ankitsinghal commented on issue #18: RATIS-523 RATIS-524 RATIS-525 RATIS-526 
RATIS-527 RATIS-533 Lots of cleanup on the LogService
URL: https://github.com/apache/incubator-ratis/pull/18#issuecomment-488566140
 
 
   **Was getting following exception in the service**
   ` 2019-05-02 03:22:56,201 WARN  server.GrpcServerProtocolService 
(LogUtils.java:warn(136)) - worker2.logservice.ratis.org_9999: Failed 
requestVote 
worker1.logservice.ratis.org_9999->worker2.logservice.ratis.org_9999#0
    org.apache.ratis.protocol.GroupMismatchException: 
worker2.logservice.ratis.org_9999: group-87E0933ED47B not found.
        at 
org.apache.ratis.server.impl.RaftServerProxy$ImplMap.get(RaftServerProxy.java:122)
        at 
org.apache.ratis.server.impl.RaftServerProxy.getImplFuture(RaftServerProxy.java:269)
        at 
org.apache.ratis.server.impl.RaftServerProxy.getImpl(RaftServerProxy.java:278)
        at 
org.apache.ratis.server.impl.RaftServerProxy.getImpl(RaftServerProxy.java:273)
        at 
org.apache.ratis.server.impl.RaftServerProxy.requestVote(RaftServerProxy.java:442)
        at 
org.apache.ratis.grpc.server.GrpcServerProtocolService.requestVote(GrpcServerProtocolService.java:55)
        at 
org.apache.ratis.proto.grpc.RaftServerProtocolServiceGrpc$MethodHandlers.invoke(RaftServerProtocolServiceGrpc.java:319)
        at 
org.apache.ratis.thirdparty.io.grpc.stub.ServerCalls$UnaryServerCallHandler$UnaryServerCallListener.onHalfClose(ServerCalls.java:171)
        at 
org.apache.ratis.thirdparty.io.grpc.internal.ServerCallImpl$ServerStreamListenerImpl.halfClosed(ServerCallImpl.java:283)
        at 
org.apache.ratis.thirdparty.io.grpc.internal.ServerImpl$JumpToApplicationThreadServerStreamListener$1HalfClosed.runInContext(ServerImpl.java:710)
        at 
org.apache.ratis.thirdparty.io.grpc.internal.ContextRunnable.run(ContextRunnable.java:37)
        at 
org.apache.ratis.thirdparty.io.grpc.internal.SerializingExecutor.run(SerializingExecutor.java:123)
        at 
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
        at 
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
        at java.lang.Thread.run(Thread.java:748)
   
   May 02, 2019 3:22:56 AM 
org.apache.ratis.thirdparty.io.grpc.internal.ManagedChannelOrphanWrapper$ManagedChannelReference
 cleanQueue
    SEVERE: *~*~*~ Channel ManagedChannelImpl{logId=22, 
target=worker3.logservice.ratis.org:9999} was not shutdown properly!!! ~*~*~*
        Make sure to call shutdown()/shutdownNow() and wait until 
awaitTermination() returns true.
    java.lang.RuntimeException: ManagedChannel allocation site
        at 
org.apache.ratis.thirdparty.io.grpc.internal.ManagedChannelOrphanWrapper$ManagedChannelReference.<init>(ManagedChannelOrphanWrapper.java:103)
        at 
org.apache.ratis.thirdparty.io.grpc.internal.ManagedChannelOrphanWrapper.<init>(ManagedChannelOrphanWrapper.java:53)
        at 
org.apache.ratis.thirdparty.io.grpc.internal.ManagedChannelOrphanWrapper.<init>(ManagedChannelOrphanWrapper.java:44)
        at 
org.apache.ratis.thirdparty.io.grpc.internal.AbstractManagedChannelImplBuilder.build(AbstractManagedChannelImplBuilder.java:411)
        at 
org.apache.ratis.grpc.client.GrpcClientProtocolClient.<init>(GrpcClientProtocolClient.java:118)
        at 
org.apache.ratis.grpc.client.GrpcClientRpc.lambda$new$0(GrpcClientRpc.java:55)
        at 
org.apache.ratis.util.PeerProxyMap$PeerAndProxy.lambda$getProxy$0(PeerProxyMap.java:61)
        at 
org.apache.ratis.util.LifeCycle.startAndTransition(LifeCycle.java:202)
        at 
org.apache.ratis.util.PeerProxyMap$PeerAndProxy.getProxy(PeerProxyMap.java:60)
        at org.apache.ratis.util.PeerProxyMap.getProxy(PeerProxyMap.java:107)
        at 
org.apache.ratis.grpc.client.GrpcClientRpc.sendRequest(GrpcClientRpc.java:91)
        at 
org.apache.ratis.client.impl.RaftClientImpl.sendRequest(RaftClientImpl.java:401)
        at 
org.apache.ratis.client.impl.RaftClientImpl.groupRemove(RaftClientImpl.java:280)
 `
   
   **While the verification tool is saying that writes are successful.**
   `2019-05-02 03:23:46,699 INFO  server.LogStateMachine 
(VerificationTool.java:run(163)) - LogName['testlog5'] Writing message900
   2019-05-02 03:23:46,885 INFO  server.LogStateMachine 
(VerificationTool.java:run(163)) - LogName['testlog6'] Writing message900
   2019-05-02 03:23:47,304 INFO  server.LogStateMachine 
(VerificationTool.java:run(163)) - LogName['testlog2'] Writing message950
   2019-05-02 03:23:47,663 INFO  server.LogStateMachine 
(VerificationTool.java:run(168)) - 1000 log entries written to log 
LogName['testlog4'] successfully.
   2019-05-02 03:23:48,064 INFO  server.LogStateMachine 
(VerificationTool.java:run(163)) - LogName['testlog5'] Writing message950
   2019-05-02 03:23:48,365 INFO  server.LogStateMachine 
(VerificationTool.java:run(163)) - LogName['testlog6'] Writing message950
   2019-05-02 03:23:48,626 INFO  server.LogStateMachine 
(VerificationTool.java:run(168)) - 1000 log entries written to log 
LogName['testlog2'] successfully.
   2019-05-02 03:23:49,034 INFO  server.LogStateMachine 
(VerificationTool.java:run(168)) - 1000 log entries written to log 
LogName['testlog5'] successfully.
   2019-05-02 03:23:49,124 INFO  server.LogStateMachine 
(VerificationTool.java:run(168)) - 1000 log entries written to log 
LogName['testlog6'] successfully.
   `
   Not sure if it is an issue or just a normal logging, but anyways doesn't 
seem to be related to changes or JIRAs fixed under this pull request

----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
 
For queries about this service, please contact Infrastructure at:
[email protected]


With regards,
Apache Git Services

Reply via email to