You are viewing a plain text version of this content. The canonical link for it is here.
Posted to hdfs-issues@hadoop.apache.org by "Chengbing Liu (Jira)" <ji...@apache.org> on 2022/10/26 01:44:00 UTC

[jira] [Commented] (HDFS-13791) Limit logging frequency of edit tail related statements

    [ https://issues.apache.org/jira/browse/HDFS-13791?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17624119#comment-17624119 ] 

Chengbing Liu commented on HDFS-13791:
--------------------------------------

In our production cluster with Observer NameNode enabled, we have plenty of logs printed by {{FSEditLogLoader}} and {{RedundantEditLogInputStream}}. The {{LogThrottlingHelper}} doesn't seem to work.

{noformat}
2022-10-25 09:26:50,380 INFO org.apache.hadoop.hdfs.server.namenode.FSImage: Start loading edits file ByteStringEditLog[17686250688, 17686250688], ByteStringEditLog[17686250688, 17686250688], ByteStringEditLog[17686250688, 17686250688] maxTxnsToRead = 9223372036854775807
2022-10-25 09:26:50,380 INFO org.apache.hadoop.hdfs.server.namenode.RedundantEditLogInputStream: Fast-forwarding stream 'ByteStringEditLog[17686250688, 17686250688], ByteStringEditLog[17686250688, 17686250688], ByteStringEditLog[17686250688, 17686250688]' to transaction ID 17686250688
2022-10-25 09:26:50,380 INFO org.apache.hadoop.hdfs.server.namenode.RedundantEditLogInputStream: Fast-forwarding stream 'ByteStringEditLog[17686250688, 17686250688]' to transaction ID 17686250688
2022-10-25 09:26:50,380 INFO org.apache.hadoop.hdfs.server.namenode.FSImage: Loaded 1 edits file(s) (the last named ByteStringEditLog[17686250688, 17686250688], ByteStringEditLog[17686250688, 17686250688], ByteStringEditLog[17686250688, 17686250688]) of total size 527.0, total edits 1.0, total load time 0.0 ms

2022-10-25 09:26:50,387 INFO org.apache.hadoop.hdfs.server.namenode.FSImage: Start loading edits file ByteStringEditLog[17686250689, 17686250693], ByteStringEditLog[17686250689, 17686250693], ByteStringEditLog[17686250689, 17686250693] maxTxnsToRead = 9223372036854775807
2022-10-25 09:26:50,387 INFO org.apache.hadoop.hdfs.server.namenode.RedundantEditLogInputStream: Fast-forwarding stream 'ByteStringEditLog[17686250689, 17686250693], ByteStringEditLog[17686250689, 17686250693], ByteStringEditLog[17686250689, 17686250693]' to transaction ID 17686250689
2022-10-25 09:26:50,387 INFO org.apache.hadoop.hdfs.server.namenode.RedundantEditLogInputStream: Fast-forwarding stream 'ByteStringEditLog[17686250689, 17686250693]' to transaction ID 17686250689
2022-10-25 09:26:50,387 INFO org.apache.hadoop.hdfs.server.namenode.FSImage: Loaded 1 edits file(s) (the last named ByteStringEditLog[17686250689, 17686250693], ByteStringEditLog[17686250689, 17686250693], ByteStringEditLog[17686250689, 17686250693]) of total size 890.0, total edits 5.0, total load time 1.0 ms
{noformat}

After some digging, I found the cause is that {{LogThrottlingHelper}}'s are declared as instance variables of all the enclosing classes, including {{FSImage}}, {{FSEditLogLoader}} and {{RedundantEditLogInputStream}}. Therefore the logging frequency will not be limited across different instances. For classes with only limited number of instances, such as {{FSImage}}, this is fine. For others whose instances will be created continuously, such as {{FSEditLogLoader}} and {{RedundantEditLogInputStream}}, it will result in plenty of logs.

[~xkrogen] How about making them static variables?

> Limit logging frequency of edit tail related statements
> -------------------------------------------------------
>
>                 Key: HDFS-13791
>                 URL: https://issues.apache.org/jira/browse/HDFS-13791
>             Project: Hadoop HDFS
>          Issue Type: Sub-task
>          Components: hdfs, qjm
>            Reporter: Erik Krogen
>            Assignee: Erik Krogen
>            Priority: Major
>             Fix For: HDFS-12943, 3.3.0
>
>         Attachments: HDFS-13791-HDFS-12943.000.patch, HDFS-13791-HDFS-12943.001.patch, HDFS-13791-HDFS-12943.002.patch, HDFS-13791-HDFS-12943.003.patch, HDFS-13791-HDFS-12943.004.patch, HDFS-13791-HDFS-12943.005.patch, HDFS-13791-HDFS-12943.006.patch
>
>
> There are a number of log statements that occur every time new edits are tailed by a Standby NameNode. When edits are tailing only on the order of every tens of seconds, this is fine. With the work in HDFS-13150, however, edits may be tailed every few milliseconds, which can flood the logs with tailing-related statements. We should throttle it to limit it to printing at most, say, once per 5 seconds.
> We can implement logic similar to that used in HDFS-10713. This may be slightly more tricky since the log statements are distributed across a few classes.



--
This message was sent by Atlassian Jira
(v8.20.10#820010)

---------------------------------------------------------------------
To unsubscribe, e-mail: hdfs-issues-unsubscribe@hadoop.apache.org
For additional commands, e-mail: hdfs-issues-help@hadoop.apache.org