[ https://issues.apache.org/jira/browse/HDDS-407?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16619921#comment-16619921 ]
Dinesh Chitlangia commented on HDDS-407: ---------------------------------------- [~nilotpalnandi] On subsequent attempts, I have still not had success with replicating this issue. Let me know if you can repro it. > 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 > Fix For: 0.3.0 > > > 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-issues-unsubscr...@hadoop.apache.org For additional commands, e-mail: hdfs-issues-h...@hadoop.apache.org