You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@ratis.apache.org by "Attila Doroszlai (Jira)" <ji...@apache.org> on 2023/04/13 09:04:00 UTC
[jira] [Created] (RATIS-1831) GrpcLogAppender spinning idle between heartbeats
Attila Doroszlai created RATIS-1831:
---------------------------------------
Summary: GrpcLogAppender spinning idle between heartbeats
Key: RATIS-1831
URL: https://issues.apache.org/jira/browse/RATIS-1831
Project: Ratis
Issue Type: Bug
Components: gRPC
Affects Versions: 2.5.0, 3.0.0
Reporter: Attila Doroszlai
Assignee: Attila Doroszlai
{code:title=https://github.com/apache/ratis/blob/a9036487c5f09e8f1132be9655eb54a177573e7c/ratis-grpc/src/main/java/org/apache/ratis/grpc/server/GrpcLogAppender.java#L173-L183}
public long getWaitTimeMs() {
if (haveTooManyPendingRequests()) {
return getHeartbeatWaitTimeMs(); // Should wait for a short time
} else if (shouldSendAppendEntries() && !isSlowFollower()) {
// For normal nodes, new entries should be sent ASAP
// however for slow followers (especially when the follower is down),
// keep sending without any wait time only ends up in high CPU load
return Math.max(getMinWaitTimeMs(), 0L);
}
return Math.min(getMinWaitTimeMs(), getHeartbeatWaitTimeMs());
}
{code}
{{GrpcLogAppender}}'s main loop does not wait if there is nothing to be sent (last {{return}} in {{getWaitTimeMs}}):
{code}
2023-04-13 10:30:47,058 [s2@group-6BFAB8E011F7->s0-GrpcLogAppender-LogAppenderDaemon] TRACE server.GrpcLogAppender (GrpcLogAppender.java:getWaitTimeMs(187)) - s2@group-6BFAB8E011F7->s0-GrpcLogAppender: wait min(10, 72) -> 10
2023-04-13 10:30:47,068 [s2@group-6BFAB8E011F7->s0-GrpcLogAppender-LogAppenderDaemon] TRACE server.GrpcLogAppender (GrpcLogAppender.java:getWaitTimeMs(187)) - s2@group-6BFAB8E011F7->s0-GrpcLogAppender: wait min(0, 61) -> 0
2023-04-13 10:30:47,068 [s2@group-6BFAB8E011F7->s0-GrpcLogAppender-LogAppenderDaemon] TRACE server.GrpcLogAppender (GrpcLogAppender.java:getWaitTimeMs(187)) - s2@group-6BFAB8E011F7->s0-GrpcLogAppender: wait min(0, 61) -> 0
2023-04-13 10:30:47,068 [s2@group-6BFAB8E011F7->s0-GrpcLogAppender-LogAppenderDaemon] TRACE server.GrpcLogAppender (GrpcLogAppender.java:getWaitTimeMs(187)) - s2@group-6BFAB8E011F7->s0-GrpcLogAppender: wait min(0, 61) -> 0
2023-04-13 10:30:47,068 [s2@group-6BFAB8E011F7->s0-GrpcLogAppender-LogAppenderDaemon] TRACE server.GrpcLogAppender (GrpcLogAppender.java:getWaitTimeMs(187)) - s2@group-6BFAB8E011F7->s0-GrpcLogAppender: wait min(0, 61) -> 0
2023-04-13 10:30:47,068 [s2@group-6BFAB8E011F7->s0-GrpcLogAppender-LogAppenderDaemon] TRACE server.GrpcLogAppender (GrpcLogAppender.java:getWaitTimeMs(187)) - s2@group-6BFAB8E011F7->s0-GrpcLogAppender: wait min(0, 61) -> 0
2023-04-13 10:30:47,069 [s2@group-6BFAB8E011F7->s0-GrpcLogAppender-LogAppenderDaemon] TRACE server.GrpcLogAppender (GrpcLogAppender.java:getWaitTimeMs(187)) - s2@group-6BFAB8E011F7->s0-GrpcLogAppender: wait min(0, 61) -> 0
2023-04-13 10:30:47,069 [s2@group-6BFAB8E011F7->s0-GrpcLogAppender-LogAppenderDaemon] TRACE server.GrpcLogAppender (GrpcLogAppender.java:getWaitTimeMs(187)) - s2@group-6BFAB8E011F7->s0-GrpcLogAppender: wait min(0, 61) -> 0
2023-04-13 10:30:47,069 [s2@group-6BFAB8E011F7->s0-GrpcLogAppender-LogAppenderDaemon] TRACE server.GrpcLogAppender (GrpcLogAppender.java:getWaitTimeMs(187)) - s2@group-6BFAB8E011F7->s0-GrpcLogAppender: wait min(0, 61) -> 0
2023-04-13 10:30:47,069 [s2@group-6BFAB8E011F7->s0-GrpcLogAppender-LogAppenderDaemon] TRACE server.GrpcLogAppender (GrpcLogAppender.java:getWaitTimeMs(187)) - s2@group-6BFAB8E011F7->s0-GrpcLogAppender: wait min(0, 61) -> 0
2023-04-13 10:30:47,069 [s2@group-6BFAB8E011F7->s0-GrpcLogAppender-LogAppenderDaemon] TRACE server.GrpcLogAppender (GrpcLogAppender.java:getWaitTimeMs(187)) - s2@group-6BFAB8E011F7->s0-GrpcLogAppender: wait min(0, 61) -> 0
2023-04-13 10:30:47,069 [s2@group-6BFAB8E011F7->s0-GrpcLogAppender-LogAppenderDaemon] TRACE server.GrpcLogAppender (GrpcLogAppender.java:getWaitTimeMs(187)) - s2@group-6BFAB8E011F7->s0-GrpcLogAppender: wait min(0, 61) -> 0
2023-04-13 10:30:47,069 [s2@group-6BFAB8E011F7->s0-GrpcLogAppender-LogAppenderDaemon] TRACE server.GrpcLogAppender (GrpcLogAppender.java:getWaitTimeMs(187)) - s2@group-6BFAB8E011F7->s0-GrpcLogAppender: wait min(0, 61) -> 0
2023-04-13 10:30:47,069 [s2@group-6BFAB8E011F7->s0-GrpcLogAppender-LogAppenderDaemon] TRACE server.GrpcLogAppender (GrpcLogAppender.java:getWaitTimeMs(187)) - s2@group-6BFAB8E011F7->s0-GrpcLogAppender: wait min(0, 61) -> 0
2023-04-13 10:30:47,069 [s2@group-6BFAB8E011F7->s0-GrpcLogAppender-LogAppenderDaemon] TRACE server.GrpcLogAppender (GrpcLogAppender.java:getWaitTimeMs(187)) - s2@group-6BFAB8E011F7->s0-GrpcLogAppender: wait min(0, 61) -> 0
2023-04-13 10:30:47,069 [s2@group-6BFAB8E011F7->s0-GrpcLogAppender-LogAppenderDaemon] TRACE server.GrpcLogAppender (GrpcLogAppender.java:getWaitTimeMs(187)) - s2@group-6BFAB8E011F7->s0-GrpcLogAppender: wait min(0, 61) -> 0
2023-04-13 10:30:47,069 [s2@group-6BFAB8E011F7->s0-GrpcLogAppender-LogAppenderDaemon] TRACE server.GrpcLogAppender (GrpcLogAppender.java:getWaitTimeMs(187)) - s2@group-6BFAB8E011F7->s0-GrpcLogAppender: wait min(0, 61) -> 0
2023-04-13 10:30:47,069 [s2@group-6BFAB8E011F7->s0-GrpcLogAppender-LogAppenderDaemon] TRACE server.GrpcLogAppender (GrpcLogAppender.java:getWaitTimeMs(187)) - s2@group-6BFAB8E011F7->s0-GrpcLogAppender: wait min(0, 61) -> 0
2023-04-13 10:30:47,069 [s2@group-6BFAB8E011F7->s0-GrpcLogAppender-LogAppenderDaemon] TRACE server.GrpcLogAppender (GrpcLogAppender.java:getWaitTimeMs(187)) - s2@group-6BFAB8E011F7->s0-GrpcLogAppender: wait min(0, 61) -> 0
2023-04-13 10:30:47,069 [s2@group-6BFAB8E011F7->s0-GrpcLogAppender-LogAppenderDaemon] TRACE server.GrpcLogAppender (GrpcLogAppender.java:getWaitTimeMs(187)) - s2@group-6BFAB8E011F7->s0-GrpcLogAppender: wait min(0, 61) -> 0
2023-04-13 10:30:47,069 [s2@group-6BFAB8E011F7->s0-GrpcLogAppender-LogAppenderDaemon] TRACE server.GrpcLogAppender (GrpcLogAppender.java:getWaitTimeMs(187)) - s2@group-6BFAB8E011F7->s0-GrpcLogAppender: wait min(-1, 61) -> -1
2023-04-13 10:30:47,069 [s2@group-6BFAB8E011F7->s0-GrpcLogAppender-LogAppenderDaemon] TRACE server.GrpcLogAppender (GrpcLogAppender.java:getWaitTimeMs(187)) - s2@group-6BFAB8E011F7->s0-GrpcLogAppender: wait min(-1, 61) -> -1
2023-04-13 10:30:47,069 [s2@group-6BFAB8E011F7->s0-GrpcLogAppender-LogAppenderDaemon] TRACE server.GrpcLogAppender (GrpcLogAppender.java:getWaitTimeMs(187)) - s2@group-6BFAB8E011F7->s0-GrpcLogAppender: wait min(-1, 61) -> -1
2023-04-13 10:30:47,069 [s2@group-6BFAB8E011F7->s0-GrpcLogAppender-LogAppenderDaemon] TRACE server.GrpcLogAppender (GrpcLogAppender.java:getWaitTimeMs(187)) - s2@group-6BFAB8E011F7->s0-GrpcLogAppender: wait min(-1, 61) -> -1
2023-04-13 10:30:47,069 [s2@group-6BFAB8E011F7->s0-GrpcLogAppender-LogAppenderDaemon] TRACE server.GrpcLogAppender (GrpcLogAppender.java:getWaitTimeMs(187)) - s2@group-6BFAB8E011F7->s0-GrpcLogAppender: wait min(-1, 61) -> -1
2023-04-13 10:30:47,069 [s2@group-6BFAB8E011F7->s0-GrpcLogAppender-LogAppenderDaemon] TRACE server.GrpcLogAppender (GrpcLogAppender.java:getWaitTimeMs(187)) - s2@group-6BFAB8E011F7->s0-GrpcLogAppender: wait min(-1, 60) -> -1
2023-04-13 10:30:47,069 [s2@group-6BFAB8E011F7->s0-GrpcLogAppender-LogAppenderDaemon] TRACE server.GrpcLogAppender (GrpcLogAppender.java:getWaitTimeMs(187)) - s2@group-6BFAB8E011F7->s0-GrpcLogAppender: wait min(-1, 60) -> -1
2023-04-13 10:30:47,069 [s2@group-6BFAB8E011F7->s0-GrpcLogAppender-LogAppenderDaemon] TRACE server.GrpcLogAppender (GrpcLogAppender.java:getWaitTimeMs(187)) - s2@group-6BFAB8E011F7->s0-GrpcLogAppender: wait min(-1, 60) -> -1
2023-04-13 10:30:47,069 [s2@group-6BFAB8E011F7->s0-GrpcLogAppender-LogAppenderDaemon] TRACE server.GrpcLogAppender (GrpcLogAppender.java:getWaitTimeMs(187)) - s2@group-6BFAB8E011F7->s0-GrpcLogAppender: wait min(-1, 60) -> -1
2023-04-13 10:30:47,069 [s2@group-6BFAB8E011F7->s0-GrpcLogAppender-LogAppenderDaemon] TRACE server.GrpcLogAppender (GrpcLogAppender.java:getWaitTimeMs(187)) - s2@group-6BFAB8E011F7->s0-GrpcLogAppender: wait min(-1, 60) -> -1
2023-04-13 10:30:47,069 [s2@group-6BFAB8E011F7->s0-GrpcLogAppender-LogAppenderDaemon] TRACE server.GrpcLogAppender (GrpcLogAppender.java:getWaitTimeMs(187)) - s2@group-6BFAB8E011F7->s0-GrpcLogAppender: wait min(-1, 60) -> -1
2023-04-13 10:30:47,069 [s2@group-6BFAB8E011F7->s0-GrpcLogAppender-LogAppenderDaemon] TRACE server.GrpcLogAppender (GrpcLogAppender.java:getWaitTimeMs(187)) - s2@group-6BFAB8E011F7->s0-GrpcLogAppender: wait min(-1, 60) -> -1
2023-04-13 10:30:47,069 [s2@group-6BFAB8E011F7->s0-GrpcLogAppender-LogAppenderDaemon] TRACE server.GrpcLogAppender (GrpcLogAppender.java:getWaitTimeMs(187)) - s2@group-6BFAB8E011F7->s0-GrpcLogAppender: wait min(-1, 60) -> -1
2023-04-13 10:30:47,069 [s2@group-6BFAB8E011F7->s0-GrpcLogAppender-LogAppenderDaemon] TRACE server.GrpcLogAppender (GrpcLogAppender.java:getWaitTimeMs(187)) - s2@group-6BFAB8E011F7->s0-GrpcLogAppender: wait min(-1, 60) -> -1
2023-04-13 10:30:47,069 [s2@group-6BFAB8E011F7->s0-GrpcLogAppender-LogAppenderDaemon] TRACE server.GrpcLogAppender (GrpcLogAppender.java:getWaitTimeMs(187)) - s2@group-6BFAB8E011F7->s0-GrpcLogAppender: wait min(-1, 60) -> -1
2023-04-13 10:30:47,070 [s2@group-6BFAB8E011F7->s0-GrpcLogAppender-LogAppenderDaemon] TRACE server.GrpcLogAppender (GrpcLogAppender.java:getWaitTimeMs(187)) - s2@group-6BFAB8E011F7->s0-GrpcLogAppender: wait min(-1, 60) -> -1
2023-04-13 10:30:47,070 [s2@group-6BFAB8E011F7->s0-GrpcLogAppender-LogAppenderDaemon] TRACE server.GrpcLogAppender (GrpcLogAppender.java:getWaitTimeMs(187)) - s2@group-6BFAB8E011F7->s0-GrpcLogAppender: wait min(-1, 60) -> -1
2023-04-13 10:30:47,070 [s2@group-6BFAB8E011F7->s0-GrpcLogAppender-LogAppenderDaemon] TRACE server.GrpcLogAppender (GrpcLogAppender.java:getWaitTimeMs(187)) - s2@group-6BFAB8E011F7->s0-GrpcLogAppender: wait min(-1, 60) -> -1
2023-04-13 10:30:47,070 [s2@group-6BFAB8E011F7->s0-GrpcLogAppender-LogAppenderDaemon] TRACE server.GrpcLogAppender (GrpcLogAppender.java:getWaitTimeMs(187)) - s2@group-6BFAB8E011F7->s0-GrpcLogAppender: wait min(-1, 60) -> -1
2023-04-13 10:30:47,070 [s2@group-6BFAB8E011F7->s0-GrpcLogAppender-LogAppenderDaemon] TRACE server.GrpcLogAppender (GrpcLogAppender.java:getWaitTimeMs(187)) - s2@group-6BFAB8E011F7->s0-GrpcLogAppender: wait min(-1, 60) -> -1
2023-04-13 10:30:47,070 [s2@group-6BFAB8E011F7->s0-GrpcLogAppender-LogAppenderDaemon] TRACE server.GrpcLogAppender (GrpcLogAppender.java:getWaitTimeMs(187)) - s2@group-6BFAB8E011F7->s0-GrpcLogAppender: wait min(-1, 60) -> -1
2023-04-13 10:30:47,070 [s2@group-6BFAB8E011F7->s0-GrpcLogAppender-LogAppenderDaemon] TRACE server.GrpcLogAppender (GrpcLogAppender.java:getWaitTimeMs(187)) - s2@group-6BFAB8E011F7->s0-GrpcLogAppender: wait min(-1, 60) -> -1
2023-04-13 10:30:47,070 [s2@group-6BFAB8E011F7->s0-GrpcLogAppender-LogAppenderDaemon] TRACE server.GrpcLogAppender (GrpcLogAppender.java:getWaitTimeMs(187)) - s2@group-6BFAB8E011F7->s0-GrpcLogAppender: wait min(-1, 60) -> -1
2023-04-13 10:30:47,070 [s2@group-6BFAB8E011F7->s0-GrpcLogAppender-LogAppenderDaemon] TRACE server.GrpcLogAppender (GrpcLogAppender.java:getWaitTimeMs(187)) - s2@group-6BFAB8E011F7->s0-GrpcLogAppender: wait min(-1, 60) -> -1
2023-04-13 10:30:47,070 [s2@group-6BFAB8E011F7->s0-GrpcLogAppender-LogAppenderDaemon] TRACE server.GrpcLogAppender (GrpcLogAppender.java:getWaitTimeMs(187)) - s2@group-6BFAB8E011F7->s0-GrpcLogAppender: wait min(-1, 60) -> -1
2023-04-13 10:30:47,070 [s2@group-6BFAB8E011F7->s0-GrpcLogAppender-LogAppenderDaemon] TRACE server.GrpcLogAppender (GrpcLogAppender.java:getWaitTimeMs(187)) - s2@group-6BFAB8E011F7->s0-GrpcLogAppender: wait min(-1, 60) -> -1
2023-04-13 10:30:47,070 [s2@group-6BFAB8E011F7->s0-GrpcLogAppender-LogAppenderDaemon] TRACE server.GrpcLogAppender (GrpcLogAppender.java:getWaitTimeMs(187)) - s2@group-6BFAB8E011F7->s0-GrpcLogAppender: wait min(-1, 60) -> -1
2023-04-13 10:30:47,070 [s2@group-6BFAB8E011F7->s0-GrpcLogAppender-LogAppenderDaemon] TRACE server.GrpcLogAppender (GrpcLogAppender.java:getWaitTimeMs(187)) - s2@group-6BFAB8E011F7->s0-GrpcLogAppender: wait min(-1, 60) -> -1
2023-04-13 10:30:47,070 [s2@group-6BFAB8E011F7->s0-GrpcLogAppender-LogAppenderDaemon] TRACE server.GrpcLogAppender (GrpcLogAppender.java:getWaitTimeMs(187)) - s2@group-6BFAB8E011F7->s0-GrpcLogAppender: wait min(-1, 60) -> -1
2023-04-13 10:30:47,070 [s2@group-6BFAB8E011F7->s0-GrpcLogAppender-LogAppenderDaemon] TRACE server.GrpcLogAppender (GrpcLogAppender.java:getWaitTimeMs(187)) - s2@group-6BFAB8E011F7->s0-GrpcLogAppender: wait min(-2, 60) -> -2
{code}
--
This message was sent by Atlassian Jira
(v8.20.10#820010)