[jira] [Created] (RATIS-509) java.lang.IllegalStateException exception in ozone log
Nilotpal Nandi created RATIS-509: Summary: java.lang.IllegalStateException exception in ozone log Key: RATIS-509 URL: https://issues.apache.org/jira/browse/RATIS-509 Project: Ratis Issue Type: Bug Reporter: Nilotpal Nandi Here is the exception seen in ozone.log --- {noformat} 2019-03-25 22:31:21,288 INFO org.apache.ratis.server.storage.RaftLogWorker: 3f7e8187-f253-4efe-a6e8-41b4c1c85f9d-RaftLogWorker: Rolling segment log-86786_86807 to index:86807 2019-03-25 22:31:21,289 INFO org.apache.ratis.server.storage.RaftLogWorker: 3f7e8187-f253-4efe-a6e8-41b4c1c85f9d-RaftLogWorker: Rolled log segment from /data/disk1/ozone/meta/ratis/891d2bbb-4c39-4714-944c-8f2d7503c052/current/log_inprogress_86786 to /data/disk1/ozone/meta/ratis/891d2bbb-4c39-4714-944c-8f2d7503c052/current/log_86786-86807 2019-03-25 22:31:21,290 INFO org.apache.ratis.server.impl.RaftServerImpl: 3f7e8187-f253-4efe-a6e8-41b4c1c85f9d: set configuration 86808: [3f7e8187-f253-4efe-a6e8-41b4c1c85f9d:172.27.21.202:9858, 48f8862a-1cc1-45a6-9a5c-d8a5ffe1b29a:172.27.38.206:9858, 9c360a3a-2671-4ad7-81ee-452f54bdcdab:172.27.87.142:9858], old=null at 86808 2019-03-25 22:31:21,389 INFO org.apache.ratis.server.storage.RaftLogWorker: 3f7e8187-f253-4efe-a6e8-41b4c1c85f9d-RaftLogWorker: created new log segment /data/disk1/ozone/meta/ratis/891d2bbb-4c39-4714-944c-8f2d7503c052/current/log_inprogress_86808 2019-03-25 22:31:22,302 INFO org.apache.ratis.grpc.server.GrpcServerProtocolService: 3f7e8187-f253-4efe-a6e8-41b4c1c85f9d: appendEntries completed 2019-03-25 22:31:22,377 ERROR org.apache.ratis.grpc.server.GrpcLogAppender: Failed onNext serverReply { requestorId: "3f7e8187-f253-4efe-a6e8-41b4c1c85f9d" replyId: "9c360a3a-2671-4ad7-81ee-452f54bdcdab" raftGroupId { id: "\211\035+\273L9G\024\224L\217-u\003\300R" } success: true } term: 2 nextIndex: 86810 followerCommit: 86807 java.lang.IllegalStateException: reply's next index is 86810, request's previous is term: 1 index: 86807 at org.apache.ratis.util.Preconditions.assertTrue(Preconditions.java:60) at org.apache.ratis.grpc.server.GrpcLogAppender.onSuccess(GrpcLogAppender.java:294) at org.apache.ratis.grpc.server.GrpcLogAppender$AppendLogResponseHandler.onNextImpl(GrpcLogAppender.java:239) at org.apache.ratis.grpc.server.GrpcLogAppender$AppendLogResponseHandler.onNext(GrpcLogAppender.java:224) at org.apache.ratis.grpc.server.GrpcLogAppender$AppendLogResponseHandler.onNext(GrpcLogAppender.java:206) at org.apache.ratis.thirdparty.io.grpc.stub.ClientCalls$StreamObserverToCallListenerAdapter.onMessage(ClientCalls.java:421) at org.apache.ratis.thirdparty.io.grpc.ForwardingClientCallListener.onMessage(ForwardingClientCallListener.java:33) at org.apache.ratis.thirdparty.io.grpc.ForwardingClientCallListener.onMessage(ForwardingClientCallListener.java:33) at org.apache.ratis.thirdparty.io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl$1MessagesAvailable.runInContext(ClientCallImpl.java:519) 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) 2019-03-25 22:31:24,207 WARN org.apache.ratis.grpc.client.GrpcClientProtocolService: 8576-UnorderedRequestStreamObserver8576: onError: org.apache.ratis.thirdparty.io.grpc.StatusRuntimeException: CANCELLED: cancelled before receiving half close {noformat} -- This message was sent by Atlassian JIRA (v7.6.3#76005)
[jira] [Created] (RATIS-483) java.util.concurrent.TimeoutException exceptions seen in datanode logs
Nilotpal Nandi created RATIS-483: Summary: java.util.concurrent.TimeoutException exceptions seen in datanode logs Key: RATIS-483 URL: https://issues.apache.org/jira/browse/RATIS-483 Project: Ratis Issue Type: Bug Reporter: Nilotpal Nandi steps taken : # created 12 datanode cluster. # started put key operation with size 100GB. Seeing following exceptions frequently in datanode logs {noformat} 2019-02-11 09:43:54,759 INFO org.apache.ratis.server.storage.RaftLogWorker: 541f579c-790a-44b0-9989-80415e119cf4-RaftLogWorker: created new log segment /data/disk1/ozone/meta/ratis/d0c1bf83-bfe5-4646-af49-d735ee312392/current/log_inprogress_3286 2019-02-11 09:44:17,443 WARN org.apache.ratis.server.impl.LogAppender: GrpcLogAppender(541f579c-790a-44b0-9989-80415e119cf4 -> 64b7e2c8-4663-42a4-a145-1bafefbccd4c): Failed get (t:1, i:3288), STATEMACHINELOGENTRY, client-3D1F07BD7204, cid=6942 in 11999532ns java.util.concurrent.TimeoutException at java.util.concurrent.CompletableFuture.timedGet(CompletableFuture.java:1771) at java.util.concurrent.CompletableFuture.get(CompletableFuture.java:1915) at org.apache.ratis.server.storage.RaftLog$EntryWithData.getEntry(RaftLog.java:433) at org.apache.ratis.util.DataQueue.pollList(DataQueue.java:133) at org.apache.ratis.server.impl.LogAppender.createRequest(LogAppender.java:171) at org.apache.ratis.grpc.server.GrpcLogAppender.appendLog(GrpcLogAppender.java:152) at org.apache.ratis.grpc.server.GrpcLogAppender.runAppenderImpl(GrpcLogAppender.java:96) at org.apache.ratis.server.impl.LogAppender.runAppender(LogAppender.java:101) at java.lang.Thread.run(Thread.java:748) 2019-02-11 09:44:18,073 INFO org.apache.ratis.server.storage.RaftLogWorker: 541f579c-790a-44b0-9989-80415e119cf4-RaftLogWorker: Rolling segment log-3286_3295 to index:3295{noformat} {noformat} 2019-02-11 09:42:58,533 INFO org.apache.ratis.server.storage.RaftLogWorker: 541f579c-790a-44b0-9989-80415e119cf4-RaftLogWorker: created new log segment /data/disk1/ozone/meta/ratis/d0c1bf83-bfe5-4646-af49-d735ee312392/current/log_inprogress_3190 2019-02-11 09:43:20,620 WARN org.apache.ratis.server.impl.LogAppender: GrpcLogAppender(541f579c-790a-44b0-9989-80415e119cf4 -> 4e4626c5-f542-410a-a117-96386cd4e3b5): Failed get (t:1, i:3192), STATEMACHINELOGENTRY, client-AA54864AC41C, cid=6742 in 999326ns java.util.concurrent.TimeoutException at java.util.concurrent.CompletableFuture.timedGet(CompletableFuture.java:1771) at java.util.concurrent.CompletableFuture.get(CompletableFuture.java:1915) at org.apache.ratis.server.storage.RaftLog$EntryWithData.getEntry(RaftLog.java:433) at org.apache.ratis.util.DataQueue.pollList(DataQueue.java:133) at org.apache.ratis.server.impl.LogAppender.createRequest(LogAppender.java:171) at org.apache.ratis.grpc.server.GrpcLogAppender.appendLog(GrpcLogAppender.java:152) at org.apache.ratis.grpc.server.GrpcLogAppender.runAppenderImpl(GrpcLogAppender.java:96) at org.apache.ratis.server.impl.LogAppender.runAppender(LogAppender.java:101) at java.lang.Thread.run(Thread.java:748) 2019-02-11 09:43:21,505 INFO org.apache.ratis.server.storage.RaftLogWorker: 541f579c-790a-44b0-9989-80415e119cf4-RaftLogWorker: Rolling segment log-3190_3199 to index:3199{noformat} {noformat} 2019-02-11 09:45:13,622 INFO org.apache.ratis.server.storage.RaftLogWorker: 6233367a-34c2-495b-ade4-6f7e11f5eb9e-RaftLogWorker: created new log segment /data/disk1/ozone/meta/ratis/390e6f99-716f-4708-8425-c1cdb4ef4cde/current/log_inprogress_3397 2019-02-11 09:45:13,637 WARN org.apache.ratis.server.impl.LogAppender: GrpcLogAppender(6233367a-34c2-495b-ade4-6f7e11f5eb9e -> 4c976a84-5271-474c-b297-ec9119617da9): Failed get (t:1, i:3397), STATEMACHINELOGENTRY, client-311AFF4454D6, cid=7135 in 74999474ns java.util.concurrent.TimeoutException at java.util.concurrent.CompletableFuture.timedGet(CompletableFuture.java:1771) at java.util.concurrent.CompletableFuture.get(CompletableFuture.java:1915) at org.apache.ratis.server.storage.RaftLog$EntryWithData.getEntry(RaftLog.java:433) at org.apache.ratis.util.DataQueue.pollList(DataQueue.java:133) at org.apache.ratis.server.impl.LogAppender.createRequest(LogAppender.java:171) at org.apache.ratis.grpc.server.GrpcLogAppender.appendLog(GrpcLogAppender.java:152) at org.apache.ratis.grpc.server.GrpcLogAppender.runAppenderImpl(GrpcLogAppender.java:96) at org.apache.ratis.server.impl.LogAppender.runAppender(LogAppender.java:101) at java.lang.Thread.run(Thread.java:748) 2019-02-11 09:45:13,637 WARN org.apache.ratis.server.impl.LogAppender: GrpcLogAppender(6233367a-34c2-495b-ade4-6f7e11f5eb9e -> e7825b0a-b777-49cb-91e9-8a0b230a44ce): Failed get (t:1, i:3397), STATEMACHINELOGENTRY, client-311AFF4454D6, cid=7135 in 74999312ns
[jira] [Commented] (RATIS-448) java.lang.IllegalStateException exception seen when log to be truncated does not exist
[ https://issues.apache.org/jira/browse/RATIS-448?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=16708583#comment-16708583 ] Nilotpal Nandi commented on RATIS-448: -- logs present at : [^nodes-ozone-logs-1543923396.tar.gz] > java.lang.IllegalStateException exception seen when log to be truncated does > not exist > -- > > Key: RATIS-448 > URL: https://issues.apache.org/jira/browse/RATIS-448 > Project: Ratis > Issue Type: Bug >Reporter: Nilotpal Nandi >Priority: Critical > Attachments: nodes-ozone-logs-1543923396.tar.gz > > > exception seen in datanode.log > - > {noformat} > java.lang.IllegalStateException: File > /data/disk1/ozone/meta/ratis/5689db14-7ca4-4198-8826-a21df55a3ae0/current/log_2466-2484 > to be truncated does not exist > at org.apache.ratis.util.Preconditions.assertTrue(Preconditions.java:60) > at > org.apache.ratis.server.storage.RaftLogWorker$TruncateLog.execute(RaftLogWorker.java:459) > at org.apache.ratis.server.storage.RaftLogWorker.run(RaftLogWorker.java:216) > at java.lang.Thread.run(Thread.java:748){noformat} > > > {noformat} > [root@ctr-e139-1542663976389-22144-01-07 current]# ls -lhart > /data/disk1/ozone/meta/ratis/5689db14-7ca4-4198-8826-a21df55a3ae0/current > total 2.7M > -rw-r--r-- 1 root root 16K Dec 4 10:15 log_0-41 > -rw-r--r-- 1 root root 9.1K Dec 4 10:15 log_42-52 > -rw-r--r-- 1 root root 12K Dec 4 10:15 log_53-62 > -rw-r--r-- 1 root root 15K Dec 4 10:15 log_63-70 > -rw-r--r-- 1 root root 16K Dec 4 10:15 log_71-91 > -rw-r--r-- 1 root root 12K Dec 4 10:15 log_92-101 > -rw-r--r-- 1 root root 15K Dec 4 10:16 log_102-109 > .. > .. > .. > .. > -rw-r--r-- 1 root root 1.9K Dec 4 10:48 log_2438-2441 > -rw-r--r-- 1 root root 187 Dec 4 10:48 raft-meta.conf > -rw-r--r-- 1 root root 14K Dec 4 10:48 log_2442-2457 > -rw-r--r-- 1 root root 15K Dec 4 10:48 log_2458-2465 > -rw-r--r-- 1 root root 49 Dec 4 10:48 raft-meta > -rw-r--r-- 1 root root 16K Dec 4 10:48 log_2466-2483 > drwxr-xr-x 2 root root 12K Dec 4 10:48 . > -rw-r--r-- 1 root root 7.9K Dec 4 10:48 log_inprogress_2485 > drwxr-xr-x 4 root root 4.0K Dec 4 10:48 .. > > > {noformat} > > -- This message was sent by Atlassian JIRA (v7.6.3#76005)
[jira] [Updated] (RATIS-448) java.lang.IllegalStateException exception seen when log to be truncated does not exist
[ https://issues.apache.org/jira/browse/RATIS-448?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ] Nilotpal Nandi updated RATIS-448: - Attachment: nodes-ozone-logs-1543923396.tar.gz > java.lang.IllegalStateException exception seen when log to be truncated does > not exist > -- > > Key: RATIS-448 > URL: https://issues.apache.org/jira/browse/RATIS-448 > Project: Ratis > Issue Type: Bug >Reporter: Nilotpal Nandi >Priority: Critical > Attachments: nodes-ozone-logs-1543923396.tar.gz > > > exception seen in datanode.log > - > {noformat} > java.lang.IllegalStateException: File > /data/disk1/ozone/meta/ratis/5689db14-7ca4-4198-8826-a21df55a3ae0/current/log_2466-2484 > to be truncated does not exist > at org.apache.ratis.util.Preconditions.assertTrue(Preconditions.java:60) > at > org.apache.ratis.server.storage.RaftLogWorker$TruncateLog.execute(RaftLogWorker.java:459) > at org.apache.ratis.server.storage.RaftLogWorker.run(RaftLogWorker.java:216) > at java.lang.Thread.run(Thread.java:748){noformat} > > > {noformat} > [root@ctr-e139-1542663976389-22144-01-07 current]# ls -lhart > /data/disk1/ozone/meta/ratis/5689db14-7ca4-4198-8826-a21df55a3ae0/current > total 2.7M > -rw-r--r-- 1 root root 16K Dec 4 10:15 log_0-41 > -rw-r--r-- 1 root root 9.1K Dec 4 10:15 log_42-52 > -rw-r--r-- 1 root root 12K Dec 4 10:15 log_53-62 > -rw-r--r-- 1 root root 15K Dec 4 10:15 log_63-70 > -rw-r--r-- 1 root root 16K Dec 4 10:15 log_71-91 > -rw-r--r-- 1 root root 12K Dec 4 10:15 log_92-101 > -rw-r--r-- 1 root root 15K Dec 4 10:16 log_102-109 > .. > .. > .. > .. > -rw-r--r-- 1 root root 1.9K Dec 4 10:48 log_2438-2441 > -rw-r--r-- 1 root root 187 Dec 4 10:48 raft-meta.conf > -rw-r--r-- 1 root root 14K Dec 4 10:48 log_2442-2457 > -rw-r--r-- 1 root root 15K Dec 4 10:48 log_2458-2465 > -rw-r--r-- 1 root root 49 Dec 4 10:48 raft-meta > -rw-r--r-- 1 root root 16K Dec 4 10:48 log_2466-2483 > drwxr-xr-x 2 root root 12K Dec 4 10:48 . > -rw-r--r-- 1 root root 7.9K Dec 4 10:48 log_inprogress_2485 > drwxr-xr-x 4 root root 4.0K Dec 4 10:48 .. > > > {noformat} > > -- This message was sent by Atlassian JIRA (v7.6.3#76005)
[jira] [Created] (RATIS-448) java.lang.IllegalStateException exception seen when log to be truncated does not exist
Nilotpal Nandi created RATIS-448: Summary: java.lang.IllegalStateException exception seen when log to be truncated does not exist Key: RATIS-448 URL: https://issues.apache.org/jira/browse/RATIS-448 Project: Ratis Issue Type: Bug Reporter: Nilotpal Nandi exception seen in datanode.log - {noformat} java.lang.IllegalStateException: File /data/disk1/ozone/meta/ratis/5689db14-7ca4-4198-8826-a21df55a3ae0/current/log_2466-2484 to be truncated does not exist at org.apache.ratis.util.Preconditions.assertTrue(Preconditions.java:60) at org.apache.ratis.server.storage.RaftLogWorker$TruncateLog.execute(RaftLogWorker.java:459) at org.apache.ratis.server.storage.RaftLogWorker.run(RaftLogWorker.java:216) at java.lang.Thread.run(Thread.java:748){noformat} {noformat} [root@ctr-e139-1542663976389-22144-01-07 current]# ls -lhart /data/disk1/ozone/meta/ratis/5689db14-7ca4-4198-8826-a21df55a3ae0/current total 2.7M -rw-r--r-- 1 root root 16K Dec 4 10:15 log_0-41 -rw-r--r-- 1 root root 9.1K Dec 4 10:15 log_42-52 -rw-r--r-- 1 root root 12K Dec 4 10:15 log_53-62 -rw-r--r-- 1 root root 15K Dec 4 10:15 log_63-70 -rw-r--r-- 1 root root 16K Dec 4 10:15 log_71-91 -rw-r--r-- 1 root root 12K Dec 4 10:15 log_92-101 -rw-r--r-- 1 root root 15K Dec 4 10:16 log_102-109 .. .. .. .. -rw-r--r-- 1 root root 1.9K Dec 4 10:48 log_2438-2441 -rw-r--r-- 1 root root 187 Dec 4 10:48 raft-meta.conf -rw-r--r-- 1 root root 14K Dec 4 10:48 log_2442-2457 -rw-r--r-- 1 root root 15K Dec 4 10:48 log_2458-2465 -rw-r--r-- 1 root root 49 Dec 4 10:48 raft-meta -rw-r--r-- 1 root root 16K Dec 4 10:48 log_2466-2483 drwxr-xr-x 2 root root 12K Dec 4 10:48 . -rw-r--r-- 1 root root 7.9K Dec 4 10:48 log_inprogress_2485 drwxr-xr-x 4 root root 4.0K Dec 4 10:48 .. {noformat} -- This message was sent by Atlassian JIRA (v7.6.3#76005)
[jira] [Commented] (RATIS-287) "URISyntaxException" warning should not print the stacktrace while ozoneFs command-line execution
[ https://issues.apache.org/jira/browse/RATIS-287?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=16572705#comment-16572705 ] Nilotpal Nandi commented on RATIS-287: -- Hi [~szetszwo] Thanks for sharing the bug details. Yes, the warning is correct. Can we stop showing the stack trace and show only the warning message ? > "URISyntaxException" warning should not print the stacktrace while ozoneFs > command-line execution > - > > Key: RATIS-287 > URL: https://issues.apache.org/jira/browse/RATIS-287 > Project: Ratis > Issue Type: Bug >Reporter: Nilotpal Nandi >Assignee: Lokesh Jain >Priority: Major > Labels: ozone > Attachments: RATIS-287.001.patch > > > > "URISyntaxException" warning shown while running ozoneFS command should not > throw the stack trace. > e.g - > {noformat} > hadoop@faf56555c4dd:~/bin$ ./ozone fs -put /etc/passwd /dir1 > 2018-07-31 07:43:52 WARN NativeCodeLoader:60 - Unable to load native-hadoop > library for your platform... using builtin-java classes where applicable > 2018-07-31 07:43:55 INFO ConfUtils:41 - raft.rpc.type = GRPC (default) > 2018-07-31 07:43:55 INFO ConfUtils:41 - raft.grpc.message.size.max = 33554432 > (custom) > 2018-07-31 07:43:55 INFO ConfUtils:41 - raft.client.rpc.retryInterval = 300 > ms (default) > 2018-07-31 07:43:55 INFO ConfUtils:41 - > raft.client.async.outstanding-requests.max = 100 (default) > 2018-07-31 07:43:55 INFO ConfUtils:41 - raft.client.async.scheduler-threads = > 3 (default) > 2018-07-31 07:43:55 INFO ConfUtils:41 - raft.grpc.flow.control.window = 1MB > (=1048576) (default) > 2018-07-31 07:43:55 INFO ConfUtils:41 - raft.grpc.message.size.max = 33554432 > (custom) > 2018-07-31 07:43:55 INFO ConfUtils:41 - raft.client.rpc.request.timeout = > 3000 ms (default) > Jul 31, 2018 7:43:56 AM > org.apache.ratis.shaded.io.grpc.internal.ProxyDetectorImpl detectProxy > WARNING: Failed to construct URI for proxy lookup, proceeding without proxy > java.net.URISyntaxException: Illegal character in hostname at index 13: > https://ozone_datanode_3.ozone_default:9858 > at java.net.URI$Parser.fail(URI.java:2848) > at java.net.URI$Parser.parseHostname(URI.java:3387) > at java.net.URI$Parser.parseServer(URI.java:3236) > at java.net.URI$Parser.parseAuthority(URI.java:3155) > at java.net.URI$Parser.parseHierarchical(URI.java:3097) > at java.net.URI$Parser.parse(URI.java:3053) > at java.net.URI.(URI.java:673) > at > org.apache.ratis.shaded.io.grpc.internal.ProxyDetectorImpl.detectProxy(ProxyDetectorImpl.java:128) > at > org.apache.ratis.shaded.io.grpc.internal.ProxyDetectorImpl.proxyFor(ProxyDetectorImpl.java:118) > at > org.apache.ratis.shaded.io.grpc.internal.InternalSubchannel.startNewTransport(InternalSubchannel.java:207) > at > org.apache.ratis.shaded.io.grpc.internal.InternalSubchannel.obtainActiveTransport(InternalSubchannel.java:188) > at > org.apache.ratis.shaded.io.grpc.internal.ManagedChannelImpl$SubchannelImpl.requestConnection(ManagedChannelImpl.java:1130) > at > org.apache.ratis.shaded.io.grpc.PickFirstBalancerFactory$PickFirstBalancer.handleResolvedAddressGroups(PickFirstBalancerFactory.java:79) > at > org.apache.ratis.shaded.io.grpc.internal.ManagedChannelImpl$NameResolverListenerImpl$1NamesResolved.run(ManagedChannelImpl.java:1032) > at > org.apache.ratis.shaded.io.grpc.internal.ChannelExecutor.drain(ChannelExecutor.java:73) > at > org.apache.ratis.shaded.io.grpc.internal.ManagedChannelImpl$LbHelperImpl.runSerialized(ManagedChannelImpl.java:1000) > at > org.apache.ratis.shaded.io.grpc.internal.ManagedChannelImpl$NameResolverListenerImpl.onAddresses(ManagedChannelImpl.java:1044) > at > org.apache.ratis.shaded.io.grpc.internal.DnsNameResolver$1.run(DnsNameResolver.java:201) > 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) > 2018-07-31 07:43:57 INFO ConfUtils:41 - raft.grpc.flow.control.window = 1MB > (=1048576) (default) > 2018-07-31 07:43:57 INFO ConfUtils:41 - raft.grpc.message.size.max = 33554432 > (custom) > 2018-07-31 07:43:57 INFO ConfUtils:41 - raft.client.rpc.request.timeout = > 3000 ms (default) > Jul 31, 2018 7:43:57 AM > org.apache.ratis.shaded.io.grpc.internal.ProxyDetectorImpl detectProxy > WARNING: Failed to construct URI for proxy lookup, proceeding without proxy > java.net.URISyntaxException: Illegal character in hostname at index 13: > https://ozone_datanode_2.ozone_default:9858 > at java.net.URI$Parser.fail(URI.java:2848) > at java.net.URI$Parser.parseHostname(URI.java:3387) > at java.net.URI$Parser.parseServer(URI.java:3236) > at
[jira] [Commented] (RATIS-287) "URISyntaxException" warning should not print the stacktrace while ozoneFs command-line execution
[ https://issues.apache.org/jira/browse/RATIS-287?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=16566682#comment-16566682 ] Nilotpal Nandi commented on RATIS-287: -- Also , ratis INFO logs should not be displayed. {noformat} hadoop@faf56555c4dd:~/bin$ ./ozone fs -put /etc/passwd /dir1 2018-07-31 07:43:52 WARN NativeCodeLoader:60 - Unable to load native-hadoop library for your platform... using builtin-java classes where applicable 2018-07-31 07:43:55 INFO ConfUtils:41 - raft.rpc.type = GRPC (default) 2018-07-31 07:43:55 INFO ConfUtils:41 - raft.grpc.message.size.max = 33554432 (custom) 2018-07-31 07:43:55 INFO ConfUtils:41 - raft.client.rpc.retryInterval = 300 ms (default) 2018-07-31 07:43:55 INFO ConfUtils:41 - raft.client.async.outstanding-requests.max = 100 (default) 2018-07-31 07:43:55 INFO ConfUtils:41 - raft.client.async.scheduler-threads = 3 (default) 2018-07-31 07:43:55 INFO ConfUtils:41 - raft.grpc.flow.control.window = 1MB (=1048576) (default) 2018-07-31 07:43:55 INFO ConfUtils:41 - raft.grpc.message.size.max = 33554432 (custom) 2018-07-31 07:43:55 INFO ConfUtils:41 - raft.client.rpc.request.timeout = 3000 ms (default){noformat} > "URISyntaxException" warning should not print the stacktrace while ozoneFs > command-line execution > - > > Key: RATIS-287 > URL: https://issues.apache.org/jira/browse/RATIS-287 > Project: Ratis > Issue Type: Bug >Reporter: Nilotpal Nandi >Priority: Major > Labels: ozone > > > "URISyntaxException" warning shown while running ozoneFS command should not > throw the stack trace. > e.g - > {noformat} > hadoop@faf56555c4dd:~/bin$ ./ozone fs -put /etc/passwd /dir1 > 2018-07-31 07:43:52 WARN NativeCodeLoader:60 - Unable to load native-hadoop > library for your platform... using builtin-java classes where applicable > 2018-07-31 07:43:55 INFO ConfUtils:41 - raft.rpc.type = GRPC (default) > 2018-07-31 07:43:55 INFO ConfUtils:41 - raft.grpc.message.size.max = 33554432 > (custom) > 2018-07-31 07:43:55 INFO ConfUtils:41 - raft.client.rpc.retryInterval = 300 > ms (default) > 2018-07-31 07:43:55 INFO ConfUtils:41 - > raft.client.async.outstanding-requests.max = 100 (default) > 2018-07-31 07:43:55 INFO ConfUtils:41 - raft.client.async.scheduler-threads = > 3 (default) > 2018-07-31 07:43:55 INFO ConfUtils:41 - raft.grpc.flow.control.window = 1MB > (=1048576) (default) > 2018-07-31 07:43:55 INFO ConfUtils:41 - raft.grpc.message.size.max = 33554432 > (custom) > 2018-07-31 07:43:55 INFO ConfUtils:41 - raft.client.rpc.request.timeout = > 3000 ms (default) > Jul 31, 2018 7:43:56 AM > org.apache.ratis.shaded.io.grpc.internal.ProxyDetectorImpl detectProxy > WARNING: Failed to construct URI for proxy lookup, proceeding without proxy > java.net.URISyntaxException: Illegal character in hostname at index 13: > https://ozone_datanode_3.ozone_default:9858 > at java.net.URI$Parser.fail(URI.java:2848) > at java.net.URI$Parser.parseHostname(URI.java:3387) > at java.net.URI$Parser.parseServer(URI.java:3236) > at java.net.URI$Parser.parseAuthority(URI.java:3155) > at java.net.URI$Parser.parseHierarchical(URI.java:3097) > at java.net.URI$Parser.parse(URI.java:3053) > at java.net.URI.(URI.java:673) > at > org.apache.ratis.shaded.io.grpc.internal.ProxyDetectorImpl.detectProxy(ProxyDetectorImpl.java:128) > at > org.apache.ratis.shaded.io.grpc.internal.ProxyDetectorImpl.proxyFor(ProxyDetectorImpl.java:118) > at > org.apache.ratis.shaded.io.grpc.internal.InternalSubchannel.startNewTransport(InternalSubchannel.java:207) > at > org.apache.ratis.shaded.io.grpc.internal.InternalSubchannel.obtainActiveTransport(InternalSubchannel.java:188) > at > org.apache.ratis.shaded.io.grpc.internal.ManagedChannelImpl$SubchannelImpl.requestConnection(ManagedChannelImpl.java:1130) > at > org.apache.ratis.shaded.io.grpc.PickFirstBalancerFactory$PickFirstBalancer.handleResolvedAddressGroups(PickFirstBalancerFactory.java:79) > at > org.apache.ratis.shaded.io.grpc.internal.ManagedChannelImpl$NameResolverListenerImpl$1NamesResolved.run(ManagedChannelImpl.java:1032) > at > org.apache.ratis.shaded.io.grpc.internal.ChannelExecutor.drain(ChannelExecutor.java:73) > at > org.apache.ratis.shaded.io.grpc.internal.ManagedChannelImpl$LbHelperImpl.runSerialized(ManagedChannelImpl.java:1000) > at > org.apache.ratis.shaded.io.grpc.internal.ManagedChannelImpl$NameResolverListenerImpl.onAddresses(ManagedChannelImpl.java:1044) > at > org.apache.ratis.shaded.io.grpc.internal.DnsNameResolver$1.run(DnsNameResolver.java:201) > at > java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) > at > java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) > at
[jira] [Commented] (RATIS-287) "URISyntaxException" warning should not print the stacktrace while ozoneFs command-line execution
[ https://issues.apache.org/jira/browse/RATIS-287?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=16563396#comment-16563396 ] Nilotpal Nandi commented on RATIS-287: -- detailed stack trace : {noformat} java.net.URISyntaxException: Illegal character in hostname at index 13: https://ozone_datanode_2.ozone_default:9858 at java.net.URI$Parser.fail(URI.java:2848) at java.net.URI$Parser.parseHostname(URI.java:3387) at java.net.URI$Parser.parseServer(URI.java:3236) at java.net.URI$Parser.parseAuthority(URI.java:3155) at java.net.URI$Parser.parseHierarchical(URI.java:3097) at java.net.URI$Parser.parse(URI.java:3053) at java.net.URI.(URI.java:673) at org.apache.ratis.shaded.io.grpc.internal.ProxyDetectorImpl.detectProxy(ProxyDetectorImpl.java:128) at org.apache.ratis.shaded.io.grpc.internal.ProxyDetectorImpl.proxyFor(ProxyDetectorImpl.java:118) at org.apache.ratis.shaded.io.grpc.internal.InternalSubchannel.startNewTransport(InternalSubchannel.java:207) at org.apache.ratis.shaded.io.grpc.internal.InternalSubchannel.obtainActiveTransport(InternalSubchannel.java:188) at org.apache.ratis.shaded.io.grpc.internal.ManagedChannelImpl$SubchannelImpl.requestConnection(ManagedChannelImpl.java:1130) at org.apache.ratis.shaded.io.grpc.PickFirstBalancerFactory$PickFirstBalancer.handleResolvedAddressGroups(PickFirstBalancerFactory.java:79) at org.apache.ratis.shaded.io.grpc.internal.ManagedChannelImpl$NameResolverListenerImpl$1NamesResolved.run(ManagedChannelImpl.java:1032) at org.apache.ratis.shaded.io.grpc.internal.ChannelExecutor.drain(ChannelExecutor.java:73) at org.apache.ratis.shaded.io.grpc.internal.DelayedClientTransport.newStream(DelayedClientTransport.java:168) at org.apache.ratis.shaded.io.grpc.internal.ClientCallImpl.start(ClientCallImpl.java:242) at org.apache.ratis.shaded.io.grpc.internal.CensusTracingModule$TracingClientInterceptor$1.start(CensusTracingModule.java:386) at org.apache.ratis.shaded.io.grpc.internal.CensusStatsModule$StatsClientInterceptor$1.start(CensusStatsModule.java:679) at org.apache.ratis.shaded.io.grpc.stub.ClientCalls.startCall(ClientCalls.java:293) at org.apache.ratis.shaded.io.grpc.stub.ClientCalls.asyncStreamingRequestCall(ClientCalls.java:283) at org.apache.ratis.shaded.io.grpc.stub.ClientCalls.asyncBidiStreamingCall(ClientCalls.java:92) at org.apache.ratis.shaded.proto.grpc.RaftClientProtocolServiceGrpc$RaftClientProtocolServiceStub.append(RaftClientProtocolServiceGrpc.java:208) at org.apache.ratis.grpc.client.RaftClientProtocolClient.appendWithTimeout(RaftClientProtocolClient.java:139) at org.apache.ratis.grpc.client.GrpcClientRpc.sendRequest(GrpcClientRpc.java:109) at org.apache.ratis.grpc.client.GrpcClientRpc.sendRequest(GrpcClientRpc.java:88) at org.apache.ratis.client.impl.RaftClientImpl.sendRequest(RaftClientImpl.java:302) at org.apache.ratis.client.impl.RaftClientImpl.sendRequestWithRetry(RaftClientImpl.java:256) at org.apache.ratis.client.impl.RaftClientImpl.send(RaftClientImpl.java:192) at org.apache.ratis.client.impl.RaftClientImpl.send(RaftClientImpl.java:173) at org.apache.ratis.client.RaftClient.send(RaftClient.java:80) at org.apache.hadoop.hdds.scm.XceiverClientRatis.sendRequest(XceiverClientRatis.java:218) at org.apache.hadoop.hdds.scm.XceiverClientRatis.sendCommand(XceiverClientRatis.java:235) at org.apache.hadoop.hdds.scm.storage.ContainerProtocolCalls.writeChunk(ContainerProtocolCalls.java:219) at org.apache.hadoop.hdds.scm.storage.ChunkOutputStream.writeChunkToContainer(ChunkOutputStream.java:220) at org.apache.hadoop.hdds.scm.storage.ChunkOutputStream.flushBufferToChunk(ChunkOutputStream.java:190) at org.apache.hadoop.hdds.scm.storage.ChunkOutputStream.write(ChunkOutputStream.java:127) at org.apache.hadoop.ozone.client.io.ChunkGroupOutputStream$ChunkOutputStreamEntry.write(ChunkGroupOutputStream.java:472) at org.apache.hadoop.ozone.client.io.ChunkGroupOutputStream.write(ChunkGroupOutputStream.java:278) at org.apache.hadoop.fs.ozone.OzoneFSOutputStream.write(OzoneFSOutputStream.java:47) at org.apache.hadoop.fs.FSDataOutputStream$PositionCache.write(FSDataOutputStream.java:57) at java.io.DataOutputStream.write(DataOutputStream.java:107) at org.apache.hadoop.io.IOUtils.copyBytes(IOUtils.java:96) at org.apache.hadoop.io.IOUtils.copyBytes(IOUtils.java:68) at org.apache.hadoop.io.IOUtils.copyBytes(IOUtils.java:129) at org.apache.hadoop.fs.shell.CommandWithDestination$TargetFileSystem.writeStreamToFile(CommandWithDestination.java:485) at org.apache.hadoop.fs.shell.CommandWithDestination.copyStreamToTarget(CommandWithDestination.java:407) at org.apache.hadoop.fs.shell.CommandWithDestination.copyFileToTarget(CommandWithDestination.java:342) at org.apache.hadoop.fs.shell.CommandWithDestination.processPath(CommandWithDestination.java:277) at
[jira] [Created] (RATIS-287) "URISyntaxException" warning should not print the stacktrace while ozoneFs command-line execution
Nilotpal Nandi created RATIS-287: Summary: "URISyntaxException" warning should not print the stacktrace while ozoneFs command-line execution Key: RATIS-287 URL: https://issues.apache.org/jira/browse/RATIS-287 Project: Ratis Issue Type: Bug Reporter: Nilotpal Nandi "URISyntaxException" warning shown while running ozoneFS command should not throw the stack trace. e.g - {noformat} hadoop@faf56555c4dd:~/bin$ ./ozone fs -put /etc/passwd /dir1 2018-07-31 07:43:52 WARN NativeCodeLoader:60 - Unable to load native-hadoop library for your platform... using builtin-java classes where applicable 2018-07-31 07:43:55 INFO ConfUtils:41 - raft.rpc.type = GRPC (default) 2018-07-31 07:43:55 INFO ConfUtils:41 - raft.grpc.message.size.max = 33554432 (custom) 2018-07-31 07:43:55 INFO ConfUtils:41 - raft.client.rpc.retryInterval = 300 ms (default) 2018-07-31 07:43:55 INFO ConfUtils:41 - raft.client.async.outstanding-requests.max = 100 (default) 2018-07-31 07:43:55 INFO ConfUtils:41 - raft.client.async.scheduler-threads = 3 (default) 2018-07-31 07:43:55 INFO ConfUtils:41 - raft.grpc.flow.control.window = 1MB (=1048576) (default) 2018-07-31 07:43:55 INFO ConfUtils:41 - raft.grpc.message.size.max = 33554432 (custom) 2018-07-31 07:43:55 INFO ConfUtils:41 - raft.client.rpc.request.timeout = 3000 ms (default) Jul 31, 2018 7:43:56 AM org.apache.ratis.shaded.io.grpc.internal.ProxyDetectorImpl detectProxy WARNING: Failed to construct URI for proxy lookup, proceeding without proxy java.net.URISyntaxException: Illegal character in hostname at index 13: https://ozone_datanode_3.ozone_default:9858 at java.net.URI$Parser.fail(URI.java:2848) at java.net.URI$Parser.parseHostname(URI.java:3387) at java.net.URI$Parser.parseServer(URI.java:3236) at java.net.URI$Parser.parseAuthority(URI.java:3155) at java.net.URI$Parser.parseHierarchical(URI.java:3097) at java.net.URI$Parser.parse(URI.java:3053) at java.net.URI.(URI.java:673) at org.apache.ratis.shaded.io.grpc.internal.ProxyDetectorImpl.detectProxy(ProxyDetectorImpl.java:128) at org.apache.ratis.shaded.io.grpc.internal.ProxyDetectorImpl.proxyFor(ProxyDetectorImpl.java:118) at org.apache.ratis.shaded.io.grpc.internal.InternalSubchannel.startNewTransport(InternalSubchannel.java:207) at org.apache.ratis.shaded.io.grpc.internal.InternalSubchannel.obtainActiveTransport(InternalSubchannel.java:188) at org.apache.ratis.shaded.io.grpc.internal.ManagedChannelImpl$SubchannelImpl.requestConnection(ManagedChannelImpl.java:1130) at org.apache.ratis.shaded.io.grpc.PickFirstBalancerFactory$PickFirstBalancer.handleResolvedAddressGroups(PickFirstBalancerFactory.java:79) at org.apache.ratis.shaded.io.grpc.internal.ManagedChannelImpl$NameResolverListenerImpl$1NamesResolved.run(ManagedChannelImpl.java:1032) at org.apache.ratis.shaded.io.grpc.internal.ChannelExecutor.drain(ChannelExecutor.java:73) at org.apache.ratis.shaded.io.grpc.internal.ManagedChannelImpl$LbHelperImpl.runSerialized(ManagedChannelImpl.java:1000) at org.apache.ratis.shaded.io.grpc.internal.ManagedChannelImpl$NameResolverListenerImpl.onAddresses(ManagedChannelImpl.java:1044) at org.apache.ratis.shaded.io.grpc.internal.DnsNameResolver$1.run(DnsNameResolver.java:201) 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) 2018-07-31 07:43:57 INFO ConfUtils:41 - raft.grpc.flow.control.window = 1MB (=1048576) (default) 2018-07-31 07:43:57 INFO ConfUtils:41 - raft.grpc.message.size.max = 33554432 (custom) 2018-07-31 07:43:57 INFO ConfUtils:41 - raft.client.rpc.request.timeout = 3000 ms (default) Jul 31, 2018 7:43:57 AM org.apache.ratis.shaded.io.grpc.internal.ProxyDetectorImpl detectProxy WARNING: Failed to construct URI for proxy lookup, proceeding without proxy java.net.URISyntaxException: Illegal character in hostname at index 13: https://ozone_datanode_2.ozone_default:9858 at java.net.URI$Parser.fail(URI.java:2848) at java.net.URI$Parser.parseHostname(URI.java:3387) at java.net.URI$Parser.parseServer(URI.java:3236) at java.net.URI$Parser.parseAuthority(URI.java:3155) at java.net.URI$Parser.parseHierarchical(URI.java:3097) at java.net.URI$Parser.parse(URI.java:3053) at java.net.URI.(URI.java:673) at org.apache.ratis.shaded.io.grpc.internal.ProxyDetectorImpl.detectProxy(ProxyDetectorImpl.java:128) at org.apache.ratis.shaded.io.grpc.internal.ProxyDetectorImpl.proxyFor(ProxyDetectorImpl.java:118) at org.apache.ratis.shaded.io.grpc.internal.InternalSubchannel.startNewTransport(InternalSubchannel.java:207) at org.apache.ratis.shaded.io.grpc.internal.InternalSubchannel.obtainActiveTransport(InternalSubchannel.java:188) at
[jira] [Created] (RATIS-259) Ratis waits infinitely with no timout when not able to connect to ozone datanode
Nilotpal Nandi created RATIS-259: Summary: Ratis waits infinitely with no timout when not able to connect to ozone datanode Key: RATIS-259 URL: https://issues.apache.org/jira/browse/RATIS-259 Project: Ratis Issue Type: Bug Reporter: Nilotpal Nandi In ozone, the pipeline type is Ratis with replication factor as 1. Ran the following command ozone command , it hung and did not complete {noformat} [root@ozone-vm bin]# ./ozone oz -getKey /nnvolume1/buckettest1/passwd ./hello1 Command Failed : {"httpCode":0,"shortMessage":"get key needs a file path to download to","resource":null,"message":"get key needs a file path to download to","requestID":null,"hostName":null} [root@ozone-vm bin]# ./ozone oz -getKey /nnvolume1/buckettest1/passwd -file . 2018-06-29 05:09:46,865 WARN util.NativeCodeLoader: Unable to load native-hadoop library for your platform... using builtin-java classes where applicable Command Failed : {"httpCode":0,"shortMessage":".exists. Download will overwrite an existing file. Aborting.","resource":null,"message":".exists. Download will overwrite an existing file. Aborting.","requestID":null,"hostName":null} [root@ozone-vm bin]# ./ozone oz -getKey /nnvolume1/buckettest1/passwd -file ./hello11 2018-06-29 05:10:27,661 WARN util.NativeCodeLoader: Unable to load native-hadoop library for your platform... using builtin-java classes where applicable 2018-06-29 05:10:28,373 INFO conf.ConfUtils: raft.rpc.type = GRPC (default) 2018-06-29 05:10:28,406 INFO conf.ConfUtils: raft.grpc.message.size.max = 33554432 (custom) 2018-06-29 05:10:28,424 INFO conf.ConfUtils: raft.client.rpc.retryInterval = 300 ms (default) 2018-06-29 05:10:28,428 INFO conf.ConfUtils: raft.client.async.outstanding-requests.max = 100 (default) 2018-06-29 05:10:28,428 INFO conf.ConfUtils: raft.client.async.scheduler-threads = 3 (default) 2018-06-29 05:10:28,595 INFO conf.ConfUtils: raft.grpc.flow.control.window = 1MB (=1048576) (default) 2018-06-29 05:10:28,595 INFO conf.ConfUtils: raft.grpc.message.size.max = 33554432 (custom) 2018-06-29 05:10:28,884 INFO conf.ConfUtils: raft.client.rpc.request.timeout = 3000 ms (default){noformat} jstack : {noformat} [root@ozone-vm logs]# jstack 4983 2018-06-29 05:31:00 Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.171-b11 mixed mode): "Attach Listener" #19 daemon prio=9 os_prio=0 tid=0x7fe9fc016000 nid=0x1804 waiting on condition [0x] java.lang.Thread.State: RUNNABLE "threadDeathWatcher-3-1" #17 daemon prio=1 os_prio=0 tid=0x7fea191e5800 nid=0x13af waiting on condition [0x7fea02905000] java.lang.Thread.State: TIMED_WAITING (sleeping) at java.lang.Thread.sleep(Native Method) at org.apache.ratis.shaded.io.netty.util.ThreadDeathWatcher$Watcher.run(ThreadDeathWatcher.java:152) at org.apache.ratis.shaded.io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:138) at java.lang.Thread.run(Thread.java:748) "grpc-default-worker-ELG-1-2" #16 daemon prio=5 os_prio=0 tid=0x7fea191d4000 nid=0x13ac runnable [0x7fea085fc000] java.lang.Thread.State: RUNNABLE at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method) at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269) at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:93) at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86) - locked <0xe0c372f0> (a org.apache.ratis.shaded.io.netty.channel.nio.SelectedSelectionKeySet) - locked <0xe0c419c8> (a java.util.Collections$UnmodifiableSet) - locked <0xe0c372a8> (a sun.nio.ch.EPollSelectorImpl) at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97) at org.apache.ratis.shaded.io.netty.channel.nio.SelectedSelectionKeySetSelector.select(SelectedSelectionKeySetSelector.java:62) at org.apache.ratis.shaded.io.netty.channel.nio.NioEventLoop.select(NioEventLoop.java:753) at org.apache.ratis.shaded.io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:409) at org.apache.ratis.shaded.io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:858) at org.apache.ratis.shaded.io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:138) at java.lang.Thread.run(Thread.java:748) "grpc-default-executor-0" #15 daemon prio=5 os_prio=0 tid=0x7fea191d0800 nid=0x13ab waiting on condition [0x7fea086fd000] java.lang.Thread.State: TIMED_WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0xe0c55a00> (a java.util.concurrent.SynchronousQueue$TransferStack) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) at