-
Type:
Bug
-
Resolution: Fixed
-
Priority:
Major - P3
-
Affects Version/s: None
-
Component/s: None
-
None
-
Storage Engines - Server Integration
-
Fully Compatible
-
ALL
-
SESIPreview 2026-10-20, SESIroflcopter 2026-11-03
-
None
-
None
-
None
-
None
-
None
-
None
-
None
Problem
The PALI warning "LogServerManager::sendBatch per-op write deadline exceeded" (log id 12813008) always reports batchEntries:0 and batchSizeBytes:0, even when the batch being written is not empty. The same is true of the three sibling lines on the same write path: "LogServerManager::sendBatch write failed" (12813011), "AppendLog stream terminated by cancel" (11921502) and "AppendLog stream terminated with error" (11529100). In all four, the two attributes that describe the batch are always zero, while previousLSN and batchLastLSN on the same line are non-zero and advance.
Observed
On HELP-101050 (cluster InfiniteFratelli, 9.1.0-rc1023, primary shard-00-00, 2026-09-30 22:13-22:21 UTC) 12813008 was logged 483 times, every one with the same shape:
{"t":{"$date":"2026-09-30T22:13:18.235+00:00"},"s":"W","c":"DISAGG","id":12813008,
"ctx":"LSM-primary-write","msg":"LogServerManager::sendBatch per-op write deadline exceeded",
"attr":{"deadlineMs":500,"logServerAddress":"log-13...:27998","segmentId":0,
"batchEntries":0,"batchSizeBytes":0,
"previousLSN":"goo.gle/debugproto domain_id: 1 lsn: 7691454908582592534",
"batchLastLSN":"goo.gle/debugproto lsn: 7691454908582592516"}}
The batches were not empty. The log server counted 21.38 MiB (22.4 MB) received on each of the connections involved (641 of them), and each such request was a single phylog entry, i.e. one WiredTiger page image. During the incident the 0/0 was read as an empty keepalive batch, and it hid the one number that explained it: that every timed-out write was a 22 MB message.
Cause
The attributes are read from the batcher after the batch has already been extracted for sending. LogServerBatcher::extractBatch() (log_server_batcher.cpp:33-41) resets _batchEntries and _batchSize (along with _currentBatch, _lastOplogIdx, _lastPhylogIdx). The four sites read acc.entries() / acc.batchSizeBytes() after that call, so they read the reset values. batchLastLSN is not reset by extractBatch(), which is why it is the only non-zero batch attribute on these lines. In _sendBatch the correct values are already cached in locals before extractBatch() is called (log_server_manager.cpp:2313-2314), so the information exists at the moment the line is emitted; only the attributes read the wrong source.
Impact
Any investigation that uses these lines to judge how much data was in flight reads zero. In this incident it was the difference between "an empty keepalive batch timed out" and "a 22 MB write timed out".
Links: HELP-101050.