[
https://issues.apache.org/jira/browse/RATIS-2244?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Venkat Sambath updated RATIS-2244:
----------------------------------
Description:
When one of the Ozone OM falls back and bootstraps, the below logs from
bootstrapping and leader om are printed very frequently and rolls off 30 log
files in 15 mins. Since logs are rolled off too quick, troubleshooting cause of
bootstrap is becoming difficult.
Bootstrap OM: The below messages are printed 160k times in a minute.
{code:java}
2025-01-14 14:12:25,406 INFO
[grpc-default-executor-505]-org.apache.ratis.server.impl.SnapshotInstallationHandler:
om1546342831@group-xxxxxx: receive installSnapshot:
om1546342823->om1546342831#0-t110,notify:(t:110, i:3986910435)
2025-01-14 14:12:25,406 INFO
[grpc-default-executor-505]-org.apache.ratis.server.impl.SnapshotInstallationHandler:
om1546342831@group-xxxxxx: reply installSnapshot:
om1546342823<-om1546342831#0:FAIL-t110,IN_PROGRESS
2025-01-14 14:12:25,406 INFO
[grpc-default-executor-505]-org.apache.ratis.grpc.server.GrpcServerProtocolService:
om1546342831: Completed INSTALL_SNAPSHOT, lastRequest:
om1546342823->om1546342831#0-t110,notify:(t:110, i:3986910435)
2025-01-14 14:12:25,406 INFO
[grpc-default-executor-505]-org.apache.ratis.grpc.server.GrpcServerProtocolService:
om1546342831: Completed INSTALL_SNAPSHOT, lastReply: null
2025-01-14 14:12:25,406 INFO
[om1546342831-server-thread2313]-org.apache.ratis.server.RaftServer$Division:
om1546342831@group-xxxxxx: Failed appendEntries as snapshot (3986910435)
installation is in progress
2025-01-14 14:12:25,406 INFO
[om1546342831-server-thread2313]-org.apache.ratis.server.RaftServer$Division:
om1546342831@group-xxxxxx: inconsistency entries.
Reply:om1546342823<-om1546342831#6516120:FAIL-t110,INCONSISTENCY,nextIndex=3986809366,followerCommit=3986809365,matchIndex=-1
{code}
Leader OM: The below messages are printed 160k times in a minute.
{code:java}
65854 WARN
[grpc-default-executor-494]-org.apache.ratis.grpc.server.GrpcLogAppender:
om1546342823@group-xxxxxx->om1546342831-AppendLogResponseHandler: received
INCONSISTENCY reply with nextIndex 3986809366
23745 WARN
[grpc-default-executor-496]-org.apache.ratis.grpc.server.GrpcLogAppender:
om1546342823@group-xxxxxx->om1546342831-AppendLogResponseHandler: received
INCONSISTENCY reply with nextIndex 3986809366
69492 WARN
[grpc-default-executor-497]-org.apache.ratis.grpc.server.GrpcLogAppender:
om1546342823@group-xxxxxx->om1546342831-AppendLogResponseHandler: received
INCONSISTENCY reply with nextIndex 3986809366
{code}
Can we change these messages to debug verbosity.
was:
When one of the Ozone OM falls back and bootstrap the below logs from
bootstrapping and leader om are printed very frequently and rolls off 30 log
files in 15 mins. Since logs are rolled off too quick, troubleshooting cause of
bootstrap is becoming difficult.
Bootstrap OM: The below messages are printed 160k times in a minute.
{code:java}
2025-01-14 14:12:25,406 INFO
[grpc-default-executor-505]-org.apache.ratis.server.impl.SnapshotInstallationHandler:
om1546342831@group-xxxxxx: receive installSnapshot:
om1546342823->om1546342831#0-t110,notify:(t:110, i:3986910435)
2025-01-14 14:12:25,406 INFO
[grpc-default-executor-505]-org.apache.ratis.server.impl.SnapshotInstallationHandler:
om1546342831@group-xxxxxx: reply installSnapshot:
om1546342823<-om1546342831#0:FAIL-t110,IN_PROGRESS
2025-01-14 14:12:25,406 INFO
[grpc-default-executor-505]-org.apache.ratis.grpc.server.GrpcServerProtocolService:
om1546342831: Completed INSTALL_SNAPSHOT, lastRequest:
om1546342823->om1546342831#0-t110,notify:(t:110, i:3986910435)
2025-01-14 14:12:25,406 INFO
[grpc-default-executor-505]-org.apache.ratis.grpc.server.GrpcServerProtocolService:
om1546342831: Completed INSTALL_SNAPSHOT, lastReply: null
2025-01-14 14:12:25,406 INFO
[om1546342831-server-thread2313]-org.apache.ratis.server.RaftServer$Division:
om1546342831@group-xxxxxx: Failed appendEntries as snapshot (3986910435)
installation is in progress
2025-01-14 14:12:25,406 INFO
[om1546342831-server-thread2313]-org.apache.ratis.server.RaftServer$Division:
om1546342831@group-xxxxxx: inconsistency entries.
Reply:om1546342823<-om1546342831#6516120:FAIL-t110,INCONSISTENCY,nextIndex=3986809366,followerCommit=3986809365,matchIndex=-1
{code}
Leader OM: The below messages are printed 160k times in a minute.
{code:java}
65854 WARN
[grpc-default-executor-494]-org.apache.ratis.grpc.server.GrpcLogAppender:
om1546342823@group-xxxxxx->om1546342831-AppendLogResponseHandler: received
INCONSISTENCY reply with nextIndex 3986809366
23745 WARN
[grpc-default-executor-496]-org.apache.ratis.grpc.server.GrpcLogAppender:
om1546342823@group-xxxxxx->om1546342831-AppendLogResponseHandler: received
INCONSISTENCY reply with nextIndex 3986809366
69492 WARN
[grpc-default-executor-497]-org.apache.ratis.grpc.server.GrpcLogAppender:
om1546342823@group-xxxxxx->om1546342831-AppendLogResponseHandler: received
INCONSISTENCY reply with nextIndex 3986809366
{code}
Can we change these messages to debug verbosity.
> Log change during bootstrap
> ---------------------------
>
> Key: RATIS-2244
> URL: https://issues.apache.org/jira/browse/RATIS-2244
> Project: Ratis
> Issue Type: Improvement
> Reporter: Venkat Sambath
> Priority: Minor
>
> When one of the Ozone OM falls back and bootstraps, the below logs from
> bootstrapping and leader om are printed very frequently and rolls off 30 log
> files in 15 mins. Since logs are rolled off too quick, troubleshooting cause
> of bootstrap is becoming difficult.
> Bootstrap OM: The below messages are printed 160k times in a minute.
> {code:java}
> 2025-01-14 14:12:25,406 INFO
> [grpc-default-executor-505]-org.apache.ratis.server.impl.SnapshotInstallationHandler:
> om1546342831@group-xxxxxx: receive installSnapshot:
> om1546342823->om1546342831#0-t110,notify:(t:110, i:3986910435)
> 2025-01-14 14:12:25,406 INFO
> [grpc-default-executor-505]-org.apache.ratis.server.impl.SnapshotInstallationHandler:
> om1546342831@group-xxxxxx: reply installSnapshot:
> om1546342823<-om1546342831#0:FAIL-t110,IN_PROGRESS
> 2025-01-14 14:12:25,406 INFO
> [grpc-default-executor-505]-org.apache.ratis.grpc.server.GrpcServerProtocolService:
> om1546342831: Completed INSTALL_SNAPSHOT, lastRequest:
> om1546342823->om1546342831#0-t110,notify:(t:110, i:3986910435)
> 2025-01-14 14:12:25,406 INFO
> [grpc-default-executor-505]-org.apache.ratis.grpc.server.GrpcServerProtocolService:
> om1546342831: Completed INSTALL_SNAPSHOT, lastReply: null
> 2025-01-14 14:12:25,406 INFO
> [om1546342831-server-thread2313]-org.apache.ratis.server.RaftServer$Division:
> om1546342831@group-xxxxxx: Failed appendEntries as snapshot (3986910435)
> installation is in progress
> 2025-01-14 14:12:25,406 INFO
> [om1546342831-server-thread2313]-org.apache.ratis.server.RaftServer$Division:
> om1546342831@group-xxxxxx: inconsistency entries.
> Reply:om1546342823<-om1546342831#6516120:FAIL-t110,INCONSISTENCY,nextIndex=3986809366,followerCommit=3986809365,matchIndex=-1
> {code}
> Leader OM: The below messages are printed 160k times in a minute.
> {code:java}
> 65854 WARN
> [grpc-default-executor-494]-org.apache.ratis.grpc.server.GrpcLogAppender:
> om1546342823@group-xxxxxx->om1546342831-AppendLogResponseHandler: received
> INCONSISTENCY reply with nextIndex 3986809366
> 23745 WARN
> [grpc-default-executor-496]-org.apache.ratis.grpc.server.GrpcLogAppender:
> om1546342823@group-xxxxxx->om1546342831-AppendLogResponseHandler: received
> INCONSISTENCY reply with nextIndex 3986809366
> 69492 WARN
> [grpc-default-executor-497]-org.apache.ratis.grpc.server.GrpcLogAppender:
> om1546342823@group-xxxxxx->om1546342831-AppendLogResponseHandler: received
> INCONSISTENCY reply with nextIndex 3986809366
> {code}
> Can we change these messages to debug verbosity.
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
