You are viewing a plain text version of this content. The canonical link for it is here.
Posted to hdfs-dev@hadoop.apache.org by "Dinesh Chitlangia (JIRA)" <ji...@apache.org> on 2018/10/17 22:15:00 UTC
[jira] [Resolved] (HDDS-407) ozone logs are written to
ozone.log. instead of ozone.log
[ https://issues.apache.org/jira/browse/HDDS-407?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Dinesh Chitlangia resolved HDDS-407.
------------------------------------
Resolution: Cannot Reproduce
[~nilotpalnandi] Since we have not seen an activity on this and we have also been able to replicate it, I am closing this issue. Please do not hesitate to reopen it if you are able to repro this. Thanks!
> ozone logs are written to ozone.log.<DATE> instead of ozone.log
> ---------------------------------------------------------------
>
> Key: HDDS-407
> URL: https://issues.apache.org/jira/browse/HDDS-407
> Project: Hadoop Distributed Data Store
> Issue Type: Bug
> Components: Ozone Client
> Reporter: Nilotpal Nandi
> Assignee: Dinesh Chitlangia
> Priority: Major
>
> Please refer below details
> ozone related logs are written to ozone.log.2018-09-05 instead of ozone.log. Also, please check the timestamps of the logs. The cluster was created
> {noformat}
> [root@ctr-e138-1518143905142-459606-01-000002 logs]# ls -lhart /root/hadoop_trunk/ozone-0.2.1-SNAPSHOT/logs/
> total 968K
> drwxr-xr-x 9 root root 4.0K Sep 5 10:04 ..
> -rw-r--r-- 1 root root 0 Sep 5 10:04 fairscheduler-statedump.log
> -rw-r--r-- 1 root root 17K Sep 5 10:05 hadoop-root-om-ctr-e138-1518143905142-459606-01-000002.hwx.site.out.1
> -rw-r--r-- 1 root root 16K Sep 5 10:10 hadoop-root-om-ctr-e138-1518143905142-459606-01-000002.hwx.site.out
> -rw-r--r-- 1 root root 11K Sep 5 10:10 hadoop-root-om-ctr-e138-1518143905142-459606-01-000002.hwx.site.log
> -rw-r--r-- 1 root root 17K Sep 6 05:42 hadoop-root-datanode-ctr-e138-1518143905142-459606-01-000002.hwx.site.out
> -rw-r--r-- 1 root root 2.1K Sep 6 13:20 ozone.log
> -rw-r--r-- 1 root root 67K Sep 6 13:22 hadoop-root-datanode-ctr-e138-1518143905142-459606-01-000002.hwx.site.log
> drwxr-xr-x 2 root root 4.0K Sep 6 13:31 .
> -rw-r--r-- 1 root root 811K Sep 6 13:39 ozone.log.2018-09-05
> [root@ctr-e138-1518143905142-459606-01-000002 logs]# date
> Thu Sep 6 13:39:47 UTC 2018{noformat}
>
> tail of ozone.log
> {noformat}
> [root@ctr-e138-1518143905142-459606-01-000002 logs]# tail -f ozone.log
> 2018-09-06 10:51:56,616 [IPC Server handler 13 on 9889] DEBUG (KeyManagerImpl.java:255) - Key 0file allocated in volume test-vol2 bucket test-bucket2
> 2018-09-06 10:52:18,570 [IPC Server handler 9 on 9889] DEBUG (KeyManagerImpl.java:255) - Key 0file1 allocated in volume test-vol2 bucket test-bucket2
> 2018-09-06 10:52:32,256 [IPC Server handler 12 on 9889] DEBUG (KeyManagerImpl.java:255) - Key 0file2 allocated in volume test-vol2 bucket test-bucket2
> 2018-09-06 10:53:11,008 [IPC Server handler 14 on 9889] DEBUG (KeyManagerImpl.java:255) - Key 0file2 allocated in volume test-vol2 bucket test-bucket2
> 2018-09-06 10:53:28,316 [IPC Server handler 10 on 9889] DEBUG (KeyManagerImpl.java:255) - Key 0file2 allocated in volume test-vol2 bucket test-bucket2
> 2018-09-06 10:53:39,509 [IPC Server handler 17 on 9889] DEBUG (KeyManagerImpl.java:255) - Key 0file3 allocated in volume test-vol2 bucket test-bucket2
> 2018-09-06 11:31:02,388 [IPC Server handler 19 on 9889] DEBUG (KeyManagerImpl.java:255) - Key 2GBFILE allocated in volume test-vol2 bucket test-bucket2
> 2018-09-06 11:32:44,269 [IPC Server handler 12 on 9889] DEBUG (KeyManagerImpl.java:255) - Key 2GBFILE_1 allocated in volume test-vol2 bucket test-bucket2
> 2018-09-06 13:17:33,408 [IPC Server handler 16 on 9889] DEBUG (KeyManagerImpl.java:255) - Key FILEWITHZEROS allocated in volume test-vol2 bucket test-bucket2
> 2018-09-06 13:20:13,897 [IPC Server handler 15 on 9889] DEBUG (KeyManagerImpl.java:255) - Key FILEWITHZEROS1 allocated in volume test-vol2 bucket test-bucket2{noformat}
>
> tail of ozone.log.2018-09-05:
> {noformat}
> root@ctr-e138-1518143905142-459606-01-000002 logs]# tail -50 ozone.log.2018-09-05
> 2018-09-06 13:28:57,866 [BlockDeletingService#8] DEBUG (TopNOrderedContainerDeletionChoosingPolicy.java:79) - Stop looking for next container, there is no pending deletion block contained in remaining containers.
> 2018-09-06 13:29:07,816 [Datanode State Machine Thread - 0] DEBUG (DatanodeStateMachine.java:145) - Executing cycle Number : 3266
> 2018-09-06 13:29:13,687 [Datanode ReportManager Thread - 0] DEBUG (ContainerSet.java:191) - Starting container report iteration.
> 2018-09-06 13:29:37,816 [Datanode State Machine Thread - 0] DEBUG (DatanodeStateMachine.java:145) - Executing cycle Number : 3267
> 2018-09-06 13:29:57,866 [BlockDeletingService#8] DEBUG (TopNOrderedContainerDeletionChoosingPolicy.java:79) - Stop looking for next container, there is no pending deletion block contained in remaining containers.
> 2018-09-06 13:30:07,816 [Datanode State Machine Thread - 0] DEBUG (DatanodeStateMachine.java:145) - Executing cycle Number : 3268
> 2018-09-06 13:30:19,186 [Datanode ReportManager Thread - 0] DEBUG (ContainerSet.java:191) - Starting container report iteration.
> 2018-09-06 13:30:37,816 [Datanode State Machine Thread - 0] DEBUG (DatanodeStateMachine.java:145) - Executing cycle Number : 3269
> 2018-09-06 13:30:57,866 [BlockDeletingService#8] DEBUG (TopNOrderedContainerDeletionChoosingPolicy.java:79) - Stop looking for next container, there is no pending deletion block contained in remaining containers.
> 2018-09-06 13:31:07,816 [Datanode State Machine Thread - 0] DEBUG (DatanodeStateMachine.java:145) - Executing cycle Number : 3270
> 2018-09-06 13:31:19,935 [Datanode ReportManager Thread - 0] DEBUG (ContainerSet.java:191) - Starting container report iteration.
> 2018-09-06 13:31:37,817 [Datanode State Machine Thread - 0] DEBUG (DatanodeStateMachine.java:145) - Executing cycle Number : 3271
> 2018-09-06 13:31:57,867 [BlockDeletingService#8] DEBUG (TopNOrderedContainerDeletionChoosingPolicy.java:79) - Stop looking for next container, there is no pending deletion block contained in remaining containers.
> 2018-09-06 13:32:07,817 [Datanode State Machine Thread - 0] DEBUG (DatanodeStateMachine.java:145) - Executing cycle Number : 3272
> 2018-09-06 13:32:28,898 [Datanode ReportManager Thread - 0] DEBUG (ContainerSet.java:191) - Starting container report iteration.
> 2018-09-06 13:32:37,817 [Datanode State Machine Thread - 0] DEBUG (DatanodeStateMachine.java:145) - Executing cycle Number : 3273
> 2018-09-06 13:32:57,867 [BlockDeletingService#8] DEBUG (TopNOrderedContainerDeletionChoosingPolicy.java:79) - Stop looking for next container, there is no pending deletion block contained in remaining containers.
> 2018-09-06 13:33:07,817 [Datanode State Machine Thread - 0] DEBUG (DatanodeStateMachine.java:145) - Executing cycle Number : 3274
> 2018-09-06 13:33:37,818 [Datanode State Machine Thread - 0] DEBUG (DatanodeStateMachine.java:145) - Executing cycle Number : 3275
> 2018-09-06 13:33:57,868 [BlockDeletingService#8] DEBUG (TopNOrderedContainerDeletionChoosingPolicy.java:79) - Stop looking for next container, there is no pending deletion block contained in remaining containers.
> 2018-09-06 13:34:07,818 [Datanode State Machine Thread - 0] DEBUG (DatanodeStateMachine.java:145) - Executing cycle Number : 3276
> 2018-09-06 13:34:22,773 [Datanode ReportManager Thread - 2] DEBUG (ContainerSet.java:191) - Starting container report iteration.
> 2018-09-06 13:34:37,818 [Datanode State Machine Thread - 0] DEBUG (DatanodeStateMachine.java:145) - Executing cycle Number : 3277
> 2018-09-06 13:34:57,868 [BlockDeletingService#8] DEBUG (TopNOrderedContainerDeletionChoosingPolicy.java:79) - Stop looking for next container, there is no pending deletion block contained in remaining containers.
> 2018-09-06 13:35:07,818 [Datanode State Machine Thread - 0] DEBUG (DatanodeStateMachine.java:145) - Executing cycle Number : 3278
> 2018-09-06 13:35:37,818 [Datanode State Machine Thread - 0] DEBUG (DatanodeStateMachine.java:145) - Executing cycle Number : 3279
> 2018-09-06 13:35:57,869 [BlockDeletingService#8] DEBUG (TopNOrderedContainerDeletionChoosingPolicy.java:79) - Stop looking for next container, there is no pending deletion block contained in remaining containers.
> 2018-09-06 13:36:07,820 [Datanode State Machine Thread - 0] DEBUG (DatanodeStateMachine.java:145) - Executing cycle Number : 3280
> 2018-09-06 13:36:20,425 [Datanode ReportManager Thread - 0] DEBUG (ContainerSet.java:191) - Starting container report iteration.
> 2018-09-06 13:36:37,820 [Datanode State Machine Thread - 0] DEBUG (DatanodeStateMachine.java:145) - Executing cycle Number : 3281
> 2018-09-06 13:36:57,869 [BlockDeletingService#8] DEBUG (TopNOrderedContainerDeletionChoosingPolicy.java:79) - Stop looking for next container, there is no pending deletion block contained in remaining containers.
> 2018-09-06 13:37:07,820 [Datanode State Machine Thread - 0] DEBUG (DatanodeStateMachine.java:145) - Executing cycle Number : 3282
> 2018-09-06 13:37:36,895 [Datanode ReportManager Thread - 0] DEBUG (ContainerSet.java:191) - Starting container report iteration.
> 2018-09-06 13:37:37,820 [Datanode State Machine Thread - 0] DEBUG (DatanodeStateMachine.java:145) - Executing cycle Number : 3283
> 2018-09-06 13:37:57,869 [BlockDeletingService#8] DEBUG (TopNOrderedContainerDeletionChoosingPolicy.java:79) - Stop looking for next container, there is no pending deletion block contained in remaining containers.
> 2018-09-06 13:38:07,820 [Datanode State Machine Thread - 0] DEBUG (DatanodeStateMachine.java:145) - Executing cycle Number : 3284
> 2018-09-06 13:38:37,820 [Datanode State Machine Thread - 0] DEBUG (DatanodeStateMachine.java:145) - Executing cycle Number : 3285
> 2018-09-06 13:38:57,870 [BlockDeletingService#8] DEBUG (TopNOrderedContainerDeletionChoosingPolicy.java:79) - Stop looking for next container, there is no pending deletion block contained in remaining containers.
> 2018-09-06 13:39:07,821 [Datanode State Machine Thread - 0] DEBUG (DatanodeStateMachine.java:145) - Executing cycle Number : 3286
> 2018-09-06 13:39:15,256 [Datanode ReportManager Thread - 1] DEBUG (ContainerSet.java:191) - Starting container report iteration.
> 2018-09-06 13:39:37,821 [Datanode State Machine Thread - 0] DEBUG (DatanodeStateMachine.java:145) - Executing cycle Number : 3287
> 2018-09-06 13:39:57,870 [BlockDeletingService#8] DEBUG (TopNOrderedContainerDeletionChoosingPolicy.java:79) - Stop looking for next container, there is no pending deletion block contained in remaining containers.
> 2018-09-06 13:40:07,823 [Datanode State Machine Thread - 0] DEBUG (DatanodeStateMachine.java:145) - Executing cycle Number : 3288
> 2018-09-06 13:40:29,575 [Datanode ReportManager Thread - 1] DEBUG (ContainerSet.java:191) - Starting container report iteration.
> 2018-09-06 13:40:37,823 [Datanode State Machine Thread - 0] DEBUG (DatanodeStateMachine.java:145) - Executing cycle Number : 3289
> 2018-09-06 13:40:57,871 [BlockDeletingService#8] DEBUG (TopNOrderedContainerDeletionChoosingPolicy.java:79) - Stop looking for next container, there is no pending deletion block contained in remaining containers.
> 2018-09-06 13:41:07,824 [Datanode State Machine Thread - 0] DEBUG (DatanodeStateMachine.java:145) - Executing cycle Number : 3290
> 2018-09-06 13:41:37,824 [Datanode State Machine Thread - 0] DEBUG (DatanodeStateMachine.java:145) - Executing cycle Number : 3291
> 2018-09-06 13:41:57,871 [BlockDeletingService#8] DEBUG (TopNOrderedContainerDeletionChoosingPolicy.java:79) - Stop looking for next container, there is no pending deletion block contained in remaining containers.
> 2018-09-06 13:42:00,662 [Datanode ReportManager Thread - 2] DEBUG (ContainerSet.java:191) - Starting container report iteration.{noformat}
>
> ozone manager running on the system :
> {noformat}
> [root@ctr-e138-1518143905142-459606-01-000002 logs]# ps -ef | grep ozone
> root 2011967 1 0 Sep05 ? 00:03:03 /base/tools/jdk1.8.0_112/bin/java -Dproc_om -Djava.net.preferIPv4Stack=true -Dhadoop.log.dir=/root/hadoop_trunk/ozone-0.2.1-SNAPSHOT/logs -Dhadoop.log.file=hadoop-root-om-ctr-e138-1518143905142-459606-01-000002.hwx.site.log -Dhadoop.home.dir=/root/hadoop_trunk/ozone-0.2.1-SNAPSHOT -Dhadoop.id.str=root -Dhadoop.root.logger=INFO,RFA -Dhadoop.policy.file=hadoop-policy.xml -Dhadoop.security.logger=INFO,NullAppender org.apache.hadoop.ozone.om.OzoneManager
> root 2014398 1 0 Sep05 ? 00:09:38 /base/tools/jdk1.8.0_112/bin/java -Dproc_datanode -Djava.net.preferIPv4Stack=true -Dhadoop.log.dir=/root/hadoop_trunk/ozone-0.2.1-SNAPSHOT/logs -Dhadoop.log.file=hadoop-root-datanode-ctr-e138-1518143905142-459606-01-000002.hwx.site.log -Dhadoop.home.dir=/root/hadoop_trunk/ozone-0.2.1-SNAPSHOT -Dhadoop.id.str=root -Dhadoop.root.logger=INFO,RFA -Dhadoop.policy.file=hadoop-policy.xml -Dhadoop.security.logger=INFO,NullAppender org.apache.hadoop.ozone.HddsDatanodeService
> root 2374538 2341272 0 13:43 pts/2 00:00:00 grep --color=auto ozone{noformat}
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)
---------------------------------------------------------------------
To unsubscribe, e-mail: hdfs-dev-unsubscribe@hadoop.apache.org
For additional commands, e-mail: hdfs-dev-help@hadoop.apache.org