controller: log how long each BigTable batch write took

Timed in the worker around the BulkApply call; reported on the per-batch
completion line and the exception line.  Gives a direct client-observed
latency signal to compare against Bigtable's server-side metrics.

nonfree/controller/BigTableStatusWriter.cpp

@@ -9,12 +9,18 @@
 #include "CtlUtil.hpp"
 #include "PubSubWriter.hpp"
 
+#include <algorithm>
+#include <atomic>
 #include <chrono>
+#include <cstddef>
 #include <functional>
 #include <google/cloud/bigtable/mutations.h>
 #include <google/cloud/bigtable/row.h>
 #include <google/cloud/bigtable/table.h>
+#include <google/cloud/status.h>
+#include <iterator>
 #include <opentelemetry/trace/provider.h>
+#include <thread>
 
 namespace cbt = google::cloud::bigtable;
 
@@ -38,6 +44,16 @@ static const int64_t kNodeInfoRefreshMs = 6LL * 24 * 60 * 60 * 1000;	// 6 days
 // offline), so the cache tracks the active set rather than every node ever seen.
 static const int64_t kCacheEntryTtlMs = 24LL * 60 * 60 * 1000;	// 24 hours
 static const int64_t kEvictionIntervalMs = 60LL * 60 * 1000;	// sweep at most hourly
+// Bigtable's MutateRows API rejects requests containing more than 100,000
+// mutations (SetCells) total, and google-cloud-cpp sends a BulkMutation as a
+// single request -- it never splits by mutation count.  Send small batches
+// (500 rows x <=5 SetCells each, far below the limit) from a small pool of
+// worker threads.  Each worker uses the *synchronous* BulkApply on purpose:
+// the async client path makes progress only on the connection's shared
+// background event threads, which stall for tens of seconds at a time in this
+// environment, while a sync call is driven entirely by its own thread.
+static const size_t kRowsPerBatch = 500;
+static const size_t kWriterThreads = 8;
 
 BigTableStatusWriter::BigTableStatusWriter(
 	const std::string& project_id,
@@ -110,88 +126,174 @@ void BigTableStatusWriter::writePending()
 	const int64_t nowMs = OSUtils::now();
 	const std::hash<std::string> hasher;
 
-	cbt::BulkMutation bulk;
-	// Row-key hash for each mutation, aligned with bulk's indices, so a failed
-	// mutation can invalidate its cache entry (FailedMutation::original_index()).
-	std::vector<uint64_t> bulkRowHashes;
-	bulkRowHashes.reserve(toWrite.size());
+	// Build every batch on this thread first (all _lastNodeInfo reads and
+	// updates stay here, lock-free), then fan the RPCs out to worker threads.
+	// Workers only perform the RPC and record its outcome; the results --
+	// cache invalidation, re-queueing, logging -- are processed back on this
+	// thread after the workers are joined.
+	struct WriteBatch {
+		cbt::BulkMutation bulk;
+		// Row-key hash per row, aligned with the batch's indices, so a failed
+		// mutation can invalidate its cache entry
+		// (FailedMutation::original_index() is relative to this batch's request).
+		std::vector<uint64_t> rowHashes;
+		size_t entryStart = 0;	 // index into toWrite of this batch's first entry
+		size_t entryCount = 0;
+		size_t mutationCount = 0;
+		std::vector<cbt::FailedMutation> failures;
+		bool threw = false;
+		std::string error;
+		int64_t durationMs = 0;
+	};
+	std::vector<WriteBatch> batches;
+	batches.reserve((toWrite.size() + kRowsPerBatch - 1) / kRowsPerBatch);
 
-	for (const auto& entry : toWrite) {
-		std::string row_key = entry.network_id + "#" + entry.node_id;
-		const uint64_t keyHash = hasher(row_key);
+	for (size_t batchStart = 0; batchStart < toWrite.size(); batchStart += kRowsPerBatch) {
+		const size_t batchEnd = std::min(batchStart + kRowsPerBatch, toWrite.size());
 
-		// Use the member's last-seen time (epoch ms) as the explicit cell timestamp for
-		// every cell in this row.  With a server-set timestamp each SetCell lands at a
-		// fresh server clock value, so re-applying the same mutation creates a *new* cell
-		// version instead of overwriting -- non-idempotent, and google-cloud-cpp won't
-		// retry such writes.  A deterministic timestamp makes a re-applied update an exact
-		// overwrite (idempotent + safely retriable).  Bigtable cell timestamps are
-		// millisecond-granular, so last_seen (already ms) aligns exactly; it's also
-		// monotonic per member, so a later check-in always reads as the newest version.
-		const std::chrono::milliseconds cellTs(entry.last_seen);
+		WriteBatch batch;
+		batch.entryStart = batchStart;
+		batch.entryCount = batchEnd - batchStart;
+		batch.rowHashes.reserve(batch.entryCount);
 
-		cbt::SingleRowMutation m(row_key);
+		for (size_t i = batchStart; i < batchEnd; ++i) {
+			const auto& entry = toWrite[i];
 
-		// node_info (os/arch/version) changes rarely.  Write it only when our
-		// last-written value for this row differs, or hasn't been refreshed in a
-		// while -- no read RPC, the controller is the sole writer of node_info.
-		const uint64_t valueHash = hasher(entry.os + "|" + entry.arch + "|" + entry.version);
-		auto it = _lastNodeInfo.find(keyHash);
-		const bool writeNodeInfo = (it == _lastNodeInfo.end()) || (it->second.valueHash != valueHash)
-			|| ((nowMs - it->second.lastWrittenMs) > kNodeInfoRefreshMs);
+			std::string row_key = entry.network_id + "#" + entry.node_id;
+			const uint64_t keyHash = hasher(row_key);
 
-		if (writeNodeInfo) {
-			m.emplace_back(cbt::SetCell(nodeInfoColumnFamily, osColumn, cellTs, entry.os));
-			m.emplace_back(cbt::SetCell(nodeInfoColumnFamily, archColumn, cellTs, entry.arch));
-			m.emplace_back(cbt::SetCell(nodeInfoColumnFamily, versionColumn, cellTs, entry.version));
-			_lastNodeInfo[keyHash] = NodeInfoState { valueHash, nowMs, nowMs };
-		}
-		else {
-			it->second.lastSeenMs = nowMs;
+			// Use the member's last-seen time (epoch ms) as the explicit cell timestamp for
+			// every cell in this row.  With a server-set timestamp each SetCell lands at a
+			// fresh server clock value, so re-applying the same mutation creates a *new* cell
+			// version instead of overwriting -- non-idempotent, and google-cloud-cpp won't
+			// retry such writes.  A deterministic timestamp makes a re-applied update an exact
+			// overwrite (idempotent + safely retriable).  Bigtable cell timestamps are
+			// millisecond-granular, so last_seen (already ms) aligns exactly; it's also
+			// monotonic per member, so a later check-in always reads as the newest version.
+			// It also makes duplicate rows racing across parallel batches order-independent.
+			const std::chrono::milliseconds cellTs(entry.last_seen);
+
+			cbt::SingleRowMutation m(row_key);
+			size_t rowMutations = 0;
+
+			// node_info (os/arch/version) changes rarely.  Write it only when our
+			// last-written value for this row differs, or hasn't been refreshed in a
+			// while -- no read RPC, the controller is the sole writer of node_info.
+			const uint64_t valueHash = hasher(entry.os + "|" + entry.arch + "|" + entry.version);
+			auto it = _lastNodeInfo.find(keyHash);
+			const bool writeNodeInfo = (it == _lastNodeInfo.end()) || (it->second.valueHash != valueHash)
+				|| ((nowMs - it->second.lastWrittenMs) > kNodeInfoRefreshMs);
+
+			if (writeNodeInfo) {
+				m.emplace_back(cbt::SetCell(nodeInfoColumnFamily, osColumn, cellTs, entry.os));
+				m.emplace_back(cbt::SetCell(nodeInfoColumnFamily, archColumn, cellTs, entry.arch));
+				m.emplace_back(cbt::SetCell(nodeInfoColumnFamily, versionColumn, cellTs, entry.version));
+				rowMutations += 3;
+				_lastNodeInfo[keyHash] = NodeInfoState { valueHash, nowMs, nowMs };
+			}
+			else {
+				it->second.lastSeenMs = nowMs;
+			}
+
+			// check_in (ip + last_seen) changes every cycle, so it's always written.
+			char buf[64] = { 0 };
+			std::string addressStr = entry.address.toString(buf);
+			if (entry.address.ss_family == AF_INET) {
+				m.emplace_back(cbt::SetCell(checkInColumnFamily, ipv4Column, cellTs, std::move(addressStr)));
+				rowMutations++;
+			}
+			else if (entry.address.ss_family == AF_INET6) {
+				m.emplace_back(cbt::SetCell(checkInColumnFamily, ipv6Column, cellTs, std::move(addressStr)));
+				rowMutations++;
+			}
+			m.emplace_back(cbt::SetCell(checkInColumnFamily, lastSeenColumn, cellTs, entry.last_seen));
+			rowMutations++;
+
+			batch.bulk.emplace_back(m);
+			batch.rowHashes.push_back(keyHash);
+			batch.mutationCount += rowMutations;
 		}
 
-		// check_in (ip + last_seen) changes every cycle, so it's always written.
-		char buf[64] = { 0 };
-		std::string addressStr = entry.address.toString(buf);
-		if (entry.address.ss_family == AF_INET) {
-			m.emplace_back(cbt::SetCell(checkInColumnFamily, ipv4Column, cellTs, std::move(addressStr)));
-		}
-		else if (entry.address.ss_family == AF_INET6) {
-			m.emplace_back(cbt::SetCell(checkInColumnFamily, ipv6Column, cellTs, std::move(addressStr)));
-		}
-		m.emplace_back(cbt::SetCell(checkInColumnFamily, lastSeenColumn, cellTs, entry.last_seen));
-
-		bulk.emplace_back(m);
-		bulkRowHashes.push_back(keyHash);
+		batches.push_back(std::move(batch));
 	}
 
-	ZTC_LOG("Applying %zu mutations to BigTable\n", bulk.size());
+	ZTC_LOG("Applying %zu rows to BigTable in %zu batches of up to %zu\n", toWrite.size(), batches.size(), kRowsPerBatch);
 
-	try {
-		std::vector<cbt::FailedMutation> failures = _table->BulkApply(std::move(bulk));
-		ZTC_LOG("BigTable write completed with %zu failures\n", failures.size());
-		for (auto const& r : failures) {
+	std::atomic<size_t> nextBatch { 0 };
+	std::vector<std::thread> workers;
+	workers.reserve(std::min(kWriterThreads, batches.size()));
+	for (size_t t = 0; t < std::min(kWriterThreads, batches.size()); ++t) {
+		workers.emplace_back([this, &batches, &nextBatch]() {
+			for (size_t i = nextBatch.fetch_add(1); i < batches.size(); i = nextBatch.fetch_add(1)) {
+				WriteBatch& b = batches[i];
+				const auto start = std::chrono::steady_clock::now();
+				try {
+					b.failures = _table->BulkApply(std::move(b.bulk));
+				}
+				catch (const std::exception& e) {
+					b.threw = true;
+					b.error = e.what();
+				}
+				b.durationMs =
+					std::chrono::duration_cast<std::chrono::milliseconds>(std::chrono::steady_clock::now() - start)
+						.count();
+			}
+		});
+	}
+	for (auto& w : workers) {
+		w.join();
+	}
+
+	// Failed entries are re-queued for the next cycle rather than dropped: the
+	// deterministic cell timestamps make replays idempotent and
+	// requeuePendingStatus caps the backlog.  This covers transient
+	// per-mutation failures (expired auth tokens, UNAVAILABLE, ...) that the
+	// client does not retry internally.
+	std::vector<PendingStatusEntry> toRequeue;
+	size_t totalFailures = 0;
+	for (WriteBatch& batch : batches) {
+		if (batch.threw) {
+			// The batch's outcome is unknown, so clear the rows it covered to force a
+			// node_info rewrite next cycle rather than trusting an optimistic update,
+			// and re-queue all of its entries.
+			ZTC_LOG("Exception writing to BigTable after %lld ms: %s\n", (long long)batch.durationMs, batch.error.c_str());
+			span->SetAttribute("error", batch.error);
+			span->SetStatus(opentelemetry::trace::StatusCode::kError, batch.error);
+			for (uint64_t keyHash : batch.rowHashes) {
+				_lastNodeInfo.erase(keyHash);
+			}
+			toRequeue.insert(
+				toRequeue.end(), std::make_move_iterator(toWrite.begin() + static_cast<std::ptrdiff_t>(batch.entryStart)),
+				std::make_move_iterator(
+					toWrite.begin() + static_cast<std::ptrdiff_t>(batch.entryStart + batch.entryCount)));
+			continue;
+		}
+		ZTC_LOG(
+			"BigTable batch of %zu rows (%zu mutations) completed with %zu failures in %lld ms\n",
+			batch.rowHashes.size(), batch.mutationCount, batch.failures.size(), (long long)batch.durationMs);
+		totalFailures += batch.failures.size();
+		for (auto const& r : batch.failures) {
 			std::cerr << ::ZeroTier::controllerLogId() << " Error writing to BigTable: " << r.status() << "\n";
+			const int idx = r.original_index();
+			if (idx < 0 || static_cast<size_t>(idx) >= batch.rowHashes.size()) {
+				continue;
+			}
 			// Drop the cache entry for any failed row so its node_info is rewritten
 			// next cycle rather than being assumed durably written.
-			const int idx = r.original_index();
-			if (idx >= 0 && static_cast<size_t>(idx) < bulkRowHashes.size()) {
-				_lastNodeInfo.erase(bulkRowHashes[idx]);
+			_lastNodeInfo.erase(batch.rowHashes[idx]);
+			// Re-queue the failed entry unless the server called it malformed --
+			// batches are far below the request limits, so INVALID_ARGUMENT here
+			// means the row itself is unprocessable and would just loop forever.
+			if (r.status().code() != google::cloud::StatusCode::kInvalidArgument) {
+				toRequeue.push_back(std::move(toWrite[batch.entryStart + static_cast<size_t>(idx)]));
 			}
 		}
 	}
-	catch (const std::exception& e) {
-		ZTC_LOG("Exception writing to BigTable: %s\n", e.what());
-		span->SetAttribute("error", e.what());
-		span->SetStatus(opentelemetry::trace::StatusCode::kError, e.what());
-		// The batch's outcome is unknown, so clear the rows it covered to force a
-		// node_info rewrite next cycle rather than trusting an optimistic update.
-		for (uint64_t keyHash : bulkRowHashes) {
-			_lastNodeInfo.erase(keyHash);
-		}
-		// Don't drop the batch — re-queue it for the next cycle.
-		requeuePendingStatus(_pending, _lock, std::move(toWrite), "BigTableStatusWriter");
-		return;
+
+	ZTC_LOG("BigTable write completed with %zu failures\n", totalFailures);
+	if (! toRequeue.empty()) {
+		ZTC_LOG("BigTableStatusWriter: re-queueing %zu entries for retry next cycle\n", toRequeue.size());
+		requeuePendingStatus(_pending, _lock, std::move(toRequeue), "BigTableStatusWriter");
 	}
 
 	// Periodically evict rows we haven't seen lately so the cache tracks the

nonfree/controller/CentralDB.hpp

@@ -7,7 +7,7 @@
 #ifndef ZT_CONTROLLER_CENTRAL_DB_HPP
 #define ZT_CONTROLLER_CENTRAL_DB_HPP
 
-#define ZT_CENTRAL_CONTROLLER_COMMIT_THREADS 4
+#define ZT_CENTRAL_CONTROLLER_COMMIT_THREADS 8
 
 // Max times a change is re-queued after a failed DB write before it is dropped.
 // Stopgap durability: the PubSub message was already acked at enqueue time, so a

nonfree/controller/EmbeddedNetworkController.cpp

@@ -51,7 +51,10 @@ using json = nlohmann::json;
 // Cap on the request queue for controller-initiated re-requests (pushes), which fan
 // out to every online member on a network change. Beyond this they're dropped (the
 // member picks up the change on its next poll) to bound memory under churn.
-#define ZT_CONTROLLER_MAX_QUEUED_REREQUESTS 16384
+// Hard safety backstop on the request-queue depth. Per-member de-dup (see request()) keeps the
+// real depth ~= the online-member count; this only bounds pathological overflow. ~1.3 KB/entry,
+// so 2097152 ~= 2.6 GB worst case (well within the pod memory limit).
+#define ZT_CONTROLLER_MAX_QUEUED_REREQUESTS 2097152
 
 namespace ZeroTier {
 
@@ -740,25 +743,48 @@ void EmbeddedNetworkController::request(
 		}
 		ms.lastRequestTime = now;
 	}
-	else {
-		// Controller-initiated re-request (push). These fan out to every online member
-		// on a network change, so cap the backlog and drop on overflow rather than
-		// growing the queue without bound — the member will still pick up the change on
-		// its next periodic poll. Member-initiated requests (requestPacketId != 0) are
-		// always queued; they're already rate-limited per member above.
-		if (_queue.size() >= ZT_CONTROLLER_MAX_QUEUED_REREQUESTS) {
-			return;
+
+	// Hard backstop on total depth (see the constant). Both a controller-initiated re-request
+	// (a network-change fan-out to every online member) and a member-initiated reconnect herd
+	// can enqueue faster than the worker threads drain; over the backstop we drop (the member
+	// re-requests on its next poll; a controller push re-applies later).
+	if (_queue.size() >= ZT_CONTROLLER_MAX_QUEUED_REREQUESTS) {
+		return;
+	}
+
+	// De-dup: keep at most one pending request per (network, member) in the queue. Member
+	// requests were previously only per-member rate-limited (1s), so a reconnect herd across
+	// ~24k members each re-requesting ~1x/sec while the backlog drained stacked ~20+ duplicate
+	// _RQEntry per member -- ~500k entries (~600 MB) and an OOM. De-duping bounds the real depth
+	// to roughly the online-member count; nothing is lost because the queued request reads fresh
+	// config when a worker processes it, and the key is cleared on dequeue so a change arriving
+	// mid-process still re-queues.
+	const _MemberStatusKey rqKey(nwid, identity.address().toInt());
+	{
+		std::lock_guard<std::mutex> l(_pendingRequests_l);
+		if (! _pendingRequests.insert(rqKey).second) {
+			return;	  // a request for this member is already queued
 		}
 	}
 
-	_RQEntry* qe = new _RQEntry;
-	qe->nwid = nwid;
-	qe->requestPacketId = requestPacketId;
-	qe->fromAddr = fromAddr;
-	qe->identity = identity;
-	qe->metaData = metaData;
-	qe->type = _RQEntry::RQENTRY_TYPE_REQUEST;
-	_queue.post(qe);
+	// The member is now marked pending, and that mark is only cleared when a worker dequeues the
+	// entry. If we fail to enqueue after this point (allocation/copy/post throwing), erase the
+	// mark so the member isn't permanently deduped away and starved until the process restarts.
+	try {
+		std::unique_ptr<_RQEntry> qe(new _RQEntry);
+		qe->nwid = nwid;
+		qe->requestPacketId = requestPacketId;
+		qe->fromAddr = fromAddr;
+		qe->identity = identity;
+		qe->metaData = metaData;
+		qe->type = _RQEntry::RQENTRY_TYPE_REQUEST;
+		_queue.post(qe.get());
+		qe.release();	 // ownership handed to _queue; the worker deletes it
+	}
+	catch (...) {
+		std::lock_guard<std::mutex> l(_pendingRequests_l);
+		_pendingRequests.erase(rqKey);
+	}
 }
 
 std::string EmbeddedNetworkController::networkUpdateFromPostData(uint64_t networkID, const std::string& body)
@@ -2490,7 +2516,12 @@ void EmbeddedNetworkController::_startThreads()
 	if (! _threads.empty()) {
 		return;
 	}
+#ifdef ZT1_CENTRAL_CONTROLLER
+    // Ensure central controllers have at least 8 threads running to process network config requests
+    const long hwc = std::max((long)std::thread::hardware_concurrency(), (long)8);
+#else
 	const long hwc = std::max((long)std::thread::hardware_concurrency(), (long)1);
+#endif
 	for (long t = 0; t < hwc; ++t) {
 		_threads.emplace_back([this, t]() {
 			Metrics::network_config_request_threads++;
@@ -2507,6 +2538,13 @@ void EmbeddedNetworkController::_startThreads()
 				else if (timedWaitResult == BlockingQueue<_RQEntry*>::OK) {
 					idleIterations = 0;
 					if (qe) {
+						// Clear the de-dup mark now that this entry is dequeued, so a fresh request
+						// for the same member (e.g. a config change arriving while we process it) can
+						// queue again instead of being deduped away.
+						{
+							std::lock_guard<std::mutex> l(_pendingRequests_l);
+							_pendingRequests.erase(_MemberStatusKey(qe->nwid, qe->identity.address().toInt()));
+						}
 						try {
 							_request(qe->nwid, qe->fromAddr, qe->requestPacketId, qe->identity, qe->metaData);
 							processedCount++;

nonfree/controller/EmbeddedNetworkController.hpp

@@ -26,6 +26,7 @@
 #include <string>
 #include <thread>
 #include <unordered_map>
+#include <unordered_set>
 #include <vector>
 
 namespace ZeroTier {
@@ -157,6 +158,12 @@ class EmbeddedNetworkController
 	std::unordered_map<_MemberStatusKey, _MemberStatus, _MemberStatusHash> _memberStatus;
 	std::mutex _memberStatus_l;
 
+	// At-most-one queued config request per (network, member): a reconnect herd (or a member
+	// re-requesting while an earlier request is still queued) would otherwise stack duplicate
+	// _RQEntry (each ~1 KB). Inserted in request(), erased when a worker dequeues the entry.
+	std::unordered_set<_MemberStatusKey, _MemberStatusHash> _pendingRequests;
+	std::mutex _pendingRequests_l;
+
 	std::set<std::pair<int64_t, _MemberStatusKey> > _expiringSoon;
 	std::mutex _expiringSoon_l;
 

scripts/bootstrap-deps.sh

@@ -79,6 +79,7 @@ else
             -DWITH_BENCHMARK=OFF -DWITH_EXAMPLES=OFF -DWITH_FUNC_TESTS=OFF \
             -DUSE_THIRDPARTY_LIBRARIES=OFF \
             -DWITH_ABSEIL=ON \
+            -DWITH_API_ONLY=OFF \
             -DWITH_OTLP_GRPC=ON -DWITH_OTLP_HTTP=ON -DWITH_PROMETHEUS=OFF
     else
         # Header-only API only (default): quick, no SDK/exporters, no abseil/protobuf/grpc.