Patch 1/2 of this patchset removed the pin's most visible symptom:
hundreds of poll passes a second. A peer that has stopped reading is
now entirely silent -- still never probed, never disconnected, nothing
logged, and no longer costing the CPU that used to give it away.
Let the ordinary probe and timeout run for such a session instead. A
non-backlogged session that does not answer its probes is dropped after
two probe intervals; a backlogged session that is not seen reading for
the same two intervals is now treated the same way, and says so through
the existing "no response to inactivity probe" message, extended to name
the bytes still queued.
What matters is not how fast a peer reads but whether the server can see
it reading. All the server sees is its own queue shrinking, and that
happens only when the socket send buffer has room -- which the peer
controls, by acknowledging data already sent and by reopening its
receive window as it reads. A peer that moves the queue within the
interval is unaffected, however slowly it consumes.
Testing. Multiple runs of the test client from patch 1/2 (also
applied), reading at different rates. At the 5 s TCP default:
rate unpatched patched
0 kB/s never t+11 s / 5.3 MB
4 kB/s t+1348 s / 0 t+27 s / 5.2 MB
20 kB/s t+278 s / 0 t+278 s / 0
(dropped at / backlog at drop)
Only the first two rows change, and they change because the queue had
not moved for two probe intervals while megabytes still stood. The
third is a control: at 20 kB/s the queue moves again well inside two
probe intervals, so it drains normally. Those drains are also why the
unpatched column is not a liveness verdict -- the test client never
answers an inactivity probe, so once it has drained it looks idle to
either build.
A client that is expected to be slow can still be left alone by
increasing the inactivity_probe duration, giving it more time to be seen
reading: at 10000 ms the 4 kB/s reader is still dropped, at t+37 s, and
at 20000 ms it survives.
Considered, measured and deemed not viable: ungating ovsdb-server's
receive by removing "if (!jsonrpc_session_get_backlog(s->js))", which
suppresses it while any backlog stands. It drops a stalled session too,
by letting the receive attempt land, but that gate also holds back
ovsdb_jsonrpc_monitor_flush_all(), which is what lets updates to a
backlogged monitor combine instead of being sent one by one; and it
changes ovsdb-server to fix a timer that lives in the FSM.
Signed-off-by: Aeliton G. Silva <[email protected]>
Assisted-by: Claude Opus 5, Claude Code
---
Notes:
v2:
- Commit message: test details measured on both builds; dropped an
incorrect claim about raft, which never gates its receive and so
already reaches the timeout today.
- Tests: the check that a reader is kept now drains every three
probe intervals. v1 drained every 4 s, inside a single interval,
so it could not have caught a reader dropped for reading slowly.
- Rebased on patch 1/2's queued-bytes reporting, so the hunks differ
from v1; the resulting reconnect_deadline__ does not.
lib/reconnect.c | 32 +++++---
python/ovs/reconnect.py | 23 ++++--
tests/reconnect.at | 166 ++++++++++++++++++++++++++++++++--------
3 files changed, 170 insertions(+), 51 deletions(-)
diff --git a/lib/reconnect.c b/lib/reconnect.c
index 87dc7715d..96957dab0 100644
--- a/lib/reconnect.c
+++ b/lib/reconnect.c
@@ -508,9 +508,11 @@ reconnect_activity(struct reconnect *fsm, long long int
now)
}
/* Tell 'fsm' how much data is currently queued for the peer and has not been
- * sent. While it is nonzero the FSM does not ask to be woken up to attempt a
- * receive: the caller evidently cannot get data to this peer, so no receive it
- * makes can settle anything. */
+ * sent. While it is nonzero the probe interval is allowed to expire on its
+ * own schedule rather than asking for a fast wake-up to attempt a receive:
+ * the caller evidently cannot get data to this peer, so no receive it makes
+ * can settle anything, and the ordinary probe and timeout should run their
+ * course. */
void
reconnect_set_queued_bytes(struct reconnect *fsm, size_t queued_bytes)
{
@@ -571,13 +573,14 @@ reconnect_deadline__(const struct reconnect *fsm, long
long int now)
if (fsm->probe_interval) {
long long int base = MAX(fsm->last_activity, fsm->state_entered);
long long int expiration = base + fsm->probe_interval;
- if (now < expiration || fsm->last_receive_attempt >= expiration) {
+ if (now < expiration || fsm->last_receive_attempt >= expiration
+ || fsm->queued_bytes) {
/* We still have time before the expiration or the time has
* already passed and there was no activity. In the first case
* we need to wait for the expiration, in the second - we're
* already past the deadline. */
return expiration;
- } else if (!fsm->queued_bytes) {
+ } else {
/* Time has already passed, but we didn't attempt to receive
* anything. We need to wake up and try to receive even if
* nothing is pending, so we can update the expiration time or
@@ -590,9 +593,10 @@ reconnect_deadline__(const struct reconnect *fsm, long
long int now)
case S_IDLE:
if (fsm->probe_interval) {
long long int expiration = fsm->state_entered +
fsm->probe_interval;
- if (now < expiration || fsm->last_receive_attempt >= expiration) {
+ if (now < expiration || fsm->last_receive_attempt >= expiration
+ || fsm->queued_bytes) {
return expiration;
- } else if (!fsm->queued_bytes) {
+ } else {
return now + 1;
}
}
@@ -662,9 +666,17 @@ reconnect_run(struct reconnect *fsm, long long int now)
return RECONNECT_PROBE;
case S_IDLE:
- VLOG_ERR("%s: no response to inactivity probe after %.3g "
- "seconds, disconnecting",
- fsm->name, (now - fsm->state_entered) / 1000.0);
+ if (fsm->queued_bytes) {
+ VLOG_ERR("%s: no response to inactivity probe after %.3g "
+ "seconds, with %"PRIuSIZE" bytes still queued for "
+ "the peer, disconnecting", fsm->name,
+ (now - fsm->state_entered) / 1000.0,
+ fsm->queued_bytes);
+ } else {
+ VLOG_ERR("%s: no response to inactivity probe after %.3g "
+ "seconds, disconnecting",
+ fsm->name, (now - fsm->state_entered) / 1000.0);
+ }
return RECONNECT_DISCONNECT;
case S_RECONNECT:
diff --git a/python/ovs/reconnect.py b/python/ovs/reconnect.py
index 38b2f7e32..ba7bfd58a 100644
--- a/python/ovs/reconnect.py
+++ b/python/ovs/reconnect.py
@@ -98,13 +98,14 @@ class Reconnect(object):
expiration = base + fsm.probe_interval
if (now < expiration or
fsm.last_receive_attempt is None or
- fsm.last_receive_attempt >= expiration):
+ fsm.last_receive_attempt >= expiration or
+ fsm.queued_bytes):
# We still have time before the expiration or the time has
# already passed and there was no activity. In the first
# case we need to wait for the expiration, in the second -
# we're already past the deadline. */
return expiration
- elif not fsm.queued_bytes:
+ else:
# Time has already passed, but we didn't attempt to receive
# anything. We need to wake up and try to receive even if
# nothing is pending, so we can update the expiration time
@@ -130,17 +131,25 @@ class Reconnect(object):
expiration = fsm.state_entered + fsm.probe_interval
if (now < expiration or
fsm.last_receive_attempt is None or
- fsm.last_receive_attempt >= expiration):
+ fsm.last_receive_attempt >= expiration or
+ fsm.queued_bytes):
return expiration
- elif not fsm.queued_bytes:
+ else:
return now + 1
return None
@staticmethod
def run(fsm, now):
- vlog.err("%s: no response to inactivity probe after %.3g "
- "seconds, disconnecting"
- % (fsm.name, (now - fsm.state_entered) / 1000.0))
+ if fsm.queued_bytes:
+ vlog.err("%s: no response to inactivity probe after %.3g "
+ "seconds, with %d bytes still queued for the peer, "
+ "disconnecting"
+ % (fsm.name, (now - fsm.state_entered) / 1000.0,
+ fsm.queued_bytes))
+ else:
+ vlog.err("%s: no response to inactivity probe after %.3g "
+ "seconds, disconnecting"
+ % (fsm.name, (now - fsm.state_entered) / 1000.0))
return DISCONNECT
class Reconnect(object):
diff --git a/tests/reconnect.at b/tests/reconnect.at
index 7433ad5c5..e65d5cc50 100644
--- a/tests/reconnect.at
+++ b/tests/reconnect.at
@@ -1368,11 +1368,10 @@ listening
dnl The guard belongs on the 1 ms retry alone. That retry is reached only once
dnl the interval has lapsed *and* no receive was attempted. ovsdb-server gates
dnl its receive on any backlog at all -- "if (!jsonrpc_session_get_backlog())"
-dnl -- so a wedged session of its own never attempts one, never leaves that
-dnl retry, and is neither probed nor dropped: the echo is not even queued for
-dnl it. Every other jsonrpc_session user calls jsonrpc_session_recv()
-dnl unconditionally, so for those the deadline is still reached with a queue
-dnl standing. Guarding the whole probe-deadline branch instead would withhold
+dnl -- so a wedged session of its own never attempts one and cannot answer the
+dnl probe, and runs on to the disconnect. Every other jsonrpc_session user
+dnl calls jsonrpc_session_recv() unconditionally, so for those an answer can
+dnl still arrive and reset the deadline. Guarding the whole probe-deadline
branch instead would withhold
dnl the probe and the disconnect from them -- a raft leader would hold a
dnl follower that stopped taking data for ever -- and no ovsdb-server check
dnl would notice.
@@ -1435,7 +1434,7 @@ run
should disconnect
])
######################################################################
-RECONNECT_CHECK([no wake-up while data is queued],
+RECONNECT_CHECK([peer with queued data is dropped],
[enable
# Connection succeeds.
@@ -1445,9 +1444,12 @@ connected
# Data is queued for the peer that we could not send.
activity 1000
-# Long past the probe interval the FSM asks for no wake-up at all, and
-# nothing happens: the connection is neither probed nor disconnected.
-advance 60000
+# Past the probe interval the connection is probed, on the ordinary
+# schedule rather than after a fast wake-up.
+timeout
+run
+
+# And a probe interval later, with nothing taken, it is given up on.
timeout
run
],
@@ -1468,15 +1470,25 @@ connected
# Data is queued for the peer that we could not send.
activity 1000
-# Long past the probe interval the FSM asks for no wake-up at all, and
-# nothing happens: the connection is neither probed nor disconnected.
-advance 60000
+# Past the probe interval the connection is probed, on the ordinary
+# schedule rather than after a fast wake-up.
+timeout
+ advance 5000 ms
+
+### t=6000 ###
+ in ACTIVE for 5000 ms (0 ms backoff)
+run
+ should send probe
+ in IDLE for 0 ms (0 ms backoff)
-### t=61000 ###
- in ACTIVE for 60000 ms (0 ms backoff)
+# And a probe interval later, with nothing taken, it is given up on.
timeout
- no timeout
+ advance 5000 ms
+
+### t=11000 ###
+ in IDLE for 5000 ms (0 ms backoff)
run
+ should disconnect
])
######################################################################
@@ -1485,7 +1497,7 @@ RECONNECT_CHECK([draining the queue restores probing],
run
connected
-# Queued: no wake-up, no probe.
+# Queued and nothing moving: probed on the ordinary schedule.
activity 1000
advance 10000
run
@@ -1508,23 +1520,26 @@ connected
connected
last connected 0 ms ago, connected 0 ms total
-# Queued: no wake-up, no probe.
+# Queued and nothing moving: probed on the ordinary schedule.
activity 1000
advance 10000
### t=11000 ###
in ACTIVE for 10000 ms (0 ms backoff)
run
+ should send probe
+ in IDLE for 0 ms (0 ms backoff)
# The queue drains, so the ordinary probe interval applies again.
activity 0
+ in ACTIVE for 0 ms (0 ms backoff)
created 1000, last activity 11000, last connected 1000
receive-attempted LLONG_MAX
timeout
advance 5000 ms
### t=16000 ###
- in ACTIVE for 15000 ms (0 ms backoff)
+ in ACTIVE for 5000 ms (0 ms backoff)
run
should send probe
in IDLE for 0 ms (0 ms backoff)
@@ -1592,7 +1607,7 @@ dnl A peer that stops reading leaves the queue standing,
so there is no
dnl activity left to report and the length has to be reported on its own.
dnl Remove the 'queued-bytes' line from the input below and the second
dnl timeout returns "advance 1 ms": the wake-up this suppresses.
-RECONNECT_CHECK([no wake-up when data is queued after the last activity],
+RECONNECT_CHECK([the probe deadline is kept when data is queued after the last
activity],
[enable
# Connection succeeds.
@@ -1608,13 +1623,11 @@ activity 0
# publishing it.
queued-bytes 182346528
-# The FSM still sleeps to the probe deadline: that is an ordinary wake-up,
-# not the 1 ms retry. Only once the deadline has lapsed with no receive
-# attempted -- the retry's own case -- does it ask for no wake-up at all,
-# because nothing a receive could do would settle anything while the caller
-# cannot get data to this peer.
+# The probe deadline is still reported, so the connection is probed on the
+# ordinary schedule rather than after the 1 ms retry.
timeout
timeout
+run
],
[### t=1000 ###
enable
@@ -1639,18 +1652,18 @@ activity 0
# publishing it.
queued-bytes 182346528
-# The FSM still sleeps to the probe deadline: that is an ordinary wake-up,
-# not the 1 ms retry. Only once the deadline has lapsed with no receive
-# attempted -- the retry's own case -- does it ask for no wake-up at all,
-# because nothing a receive could do would settle anything while the caller
-# cannot get data to this peer.
+# The probe deadline is still reported, so the connection is probed on the
+# ordinary schedule rather than after the 1 ms retry.
timeout
advance 5000 ms
### t=6000 ###
in ACTIVE for 5000 ms (0 ms backoff)
timeout
- no timeout
+ advance 0 ms
+run
+ should send probe
+ in IDLE for 0 ms (0 ms backoff)
])
dnl The same 1 ms wake-up is reachable from IDLE: a quiet connection is probed,
@@ -1658,7 +1671,7 @@ dnl and only then does the peer stop taking data. The
guard belongs in both
dnl states, not only in ACTIVE. The probe deadline itself is still
dnl reported, so a peer that is being received from is still dropped on
dnl time.
-RECONNECT_CHECK([no wake-up while data is queued in IDLE],
+RECONNECT_CHECK([the probe deadline is kept while data is queued in IDLE],
[enable
run
connected
@@ -1668,10 +1681,12 @@ timeout
receive-attempted now
run
-# Only now does the peer stop taking data.
+# Only now does the peer stop taking data. The deadline is still reported, so
+# the disconnect runs on the ordinary schedule.
queued-bytes 182346528
timeout
timeout
+run
],
[### t=1000 ###
enable
@@ -1696,7 +1711,8 @@ run
should send probe
in IDLE for 0 ms (0 ms backoff)
-# Only now does the peer stop taking data.
+# Only now does the peer stop taking data. The deadline is still reported, so
+# the disconnect runs on the ordinary schedule.
queued-bytes 182346528
timeout
advance 5000 ms
@@ -1704,5 +1720,87 @@ timeout
### t=11000 ###
in IDLE for 5000 ms (0 ms backoff)
timeout
- no timeout
+ advance 0 ms
+run
+ should disconnect
+])
+######################################################################
+dnl The property commit 633f72479 restored when it reverted disconnect-on-
+dnl backlog: a slow reader is not a dead one. All the server can see is its
+dnl own queue shrinking, and a receiver defers window updates until a
+dnl worthwhile part of its buffer is free, so a healthy slow reader moves the
+dnl queue in bursts that are far apart in time. Every burst is activity, and
+dnl activity returns the FSM to ACTIVE from IDLE, so a peer that is still
+dnl reading survives being probed however far behind it has fallen.
+RECONNECT_CHECK([a queue that keeps moving is never given up on],
+ [enable
+run
+connected
+
+# The peer is reading, just slowly: the queue shrinks once every three probe
+# intervals, so the session is probed each time -- but every shrink is
+# activity, which returns the FSM to ACTIVE, so it is never given up on.
+queued-bytes 182346528
+advance 15000
+run
+activity 182300000
+advance 15000
+run
+activity 182200000
+advance 15000
+run
+activity 182100000
+timeout
+],
+ [### t=1000 ###
+enable
+ in BACKOFF for 0 ms (0 ms backoff)
+run
+ should connect
+connected
+ in ACTIVE for 0 ms (0 ms backoff)
+ created 1000, last activity 1000, last connected 1000
+ 1 successful connections out of 1 attempts, seqno 1
+ connected
+ last connected 0 ms ago, connected 0 ms total
+
+# The peer is reading, just slowly: the queue shrinks once every three probe
+# intervals, so the session is probed each time -- but every shrink is
+# activity, which returns the FSM to ACTIVE, so it is never given up on.
+queued-bytes 182346528
+advance 15000
+
+### t=16000 ###
+ in ACTIVE for 15000 ms (0 ms backoff)
+run
+ should send probe
+ in IDLE for 0 ms (0 ms backoff)
+activity 182300000
+ in ACTIVE for 0 ms (0 ms backoff)
+ created 1000, last activity 16000, last connected 1000
+advance 15000
+
+### t=31000 ###
+ in ACTIVE for 15000 ms (0 ms backoff)
+run
+ should send probe
+ in IDLE for 0 ms (0 ms backoff)
+activity 182200000
+ in ACTIVE for 0 ms (0 ms backoff)
+ created 1000, last activity 31000, last connected 1000
+advance 15000
+
+### t=46000 ###
+ in ACTIVE for 15000 ms (0 ms backoff)
+run
+ should send probe
+ in IDLE for 0 ms (0 ms backoff)
+activity 182100000
+ in ACTIVE for 0 ms (0 ms backoff)
+ created 1000, last activity 46000, last connected 1000
+timeout
+ advance 5000 ms
+
+### t=51000 ###
+ in ACTIVE for 5000 ms (0 ms backoff)
])
--
2.43.0
--
_'Esta mensagem é direcionada apenas para os endereços constantes no
cabeçalho inicial. Se você não está listado nos endereços constantes no
cabeçalho, pedimos-lhe que desconsidere completamente o conteúdo dessa
mensagem e cuja cópia, encaminhamento e/ou execução das ações citadas estão
imediatamente anuladas e proibidas'._
* **'Apesar do Magazine Luiza tomar
todas as precauções razoáveis para assegurar que nenhum vírus esteja
presente nesse e-mail, a empresa não poderá aceitar a responsabilidade por
quaisquer perdas ou danos causados por esse e-mail ou por seus anexos'.*
_______________________________________________
dev mailing list
[email protected]
https://mail.openvswitch.org/mailman/listinfo/ovs-dev
