[GitHub] [incubator-ratis] ankitsinghal commented on issue #18: RATIS-523 RATIS-524 RATIS-525 RATIS-526 RATIS-527 RATIS-533 Lots of cleanup on the LogService

[GitBox <gi...@apache.org>]

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:
users@infra.apache.org


With regards,
Apache Git Services