[jira] [Commented] (TEZ-2775) Reduce logging in runtime components
[
https://issues.apache.org/jira/browse/TEZ-2775?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=14900150#comment-14900150
]
TezQA commented on TEZ-2775:
{color:green}+1 overall{color}. Here are the results of testing the latest
attachment
http://issues.apache.org/jira/secure/attachment/12761357/TEZ-2775.5.txt
against master revision 7ed7025.
{color:green}+1 @author{color}. The patch does not contain any @author
tags.
{color:green}+1 tests included{color}. The patch appears to include 2 new
or modified test files.
{color:green}+1 javac{color}. The applied patch does not increase the
total number of javac compiler warnings.
{color:green}+1 javadoc{color}. There were no new javadoc warning messages.
{color:green}+1 findbugs{color}. The patch does not introduce any new
Findbugs (version 3.0.1) warnings.
{color:green}+1 release audit{color}. The applied patch does not increase
the total number of release audit warnings.
{color:green}+1 core tests{color}. The patch passed unit tests in .
Test results:
https://builds.apache.org/job/PreCommit-TEZ-Build/1160//testReport/
Console output: https://builds.apache.org/job/PreCommit-TEZ-Build/1160//console
This message is automatically generated.
> Reduce logging in runtime components
>
>
> Key: TEZ-2775
> URL: https://issues.apache.org/jira/browse/TEZ-2775
> Project: Apache Tez
> Issue Type: Sub-task
>Reporter: Siddharth Seth
>Assignee: Siddharth Seth
> Attachments: TEZ-2775.1.txt, TEZ-2775.3.txt, TEZ-2775.4.txt,
> TEZ-2775.5.txt
>
>
> Specifically Shuffle, which logs a lot for each event being processed and
> data being fetched.
> Also PipelinedShuffle is fairly noisy - some of the information from here
> could be consolidated.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
[jira] [Commented] (TEZ-2775) Reduce logging in runtime components
[
https://issues.apache.org/jira/browse/TEZ-2775?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=14738508#comment-14738508
]
Rajesh Balamohan commented on TEZ-2775:
---
Fetcher/FetcherOrderedGrouped - should we retain the decomp, compressed size,
type information?. That has helped in couple of scenarios when debugging.
MergeManager - Can we retain the logging in closeInMemoryFile. It has helped in
couple of debugging related to memory.
MRInput/MROutput/MultiMRInput - space needed in "newmapreduce" or is that
intentional?
PipelinedSorter:
- in flush(), indexcache empty check is due to TEZ-2440. This is completely
harmeless and can be removed. If we do not have this check, and if the task
gets killed in the middle, it can throw NPE leading to distraction when
debugging.
ShuffleInputEventHandlerImpl:
- numObsoletionEvenets - spelling?
- Moving "DME srcIdx" would help a lot in drastically reducing the task log
size. But the following code can cause confusion
{noformat}
if (numDmeEvents.get() + numObsoletionEvenets.get() >
nextToLogEventCount.get()) {
LOG.info(inputContext.getSourceVertexName() + ": "
+ "numDmeEventsSeen=" + numDmeEvents.get()
+ ", numDmeEventsSeenWithNoData=" + numDmeEventsNoData.get()
+ ", numObsoletionEventsSeen=" + numObsoletionEvenets.get());
// Log every 50 events seen.
nextToLogEventCount.addAndGet(50);
}
{noformat}
If there are only 10 or 30 events, it might only print the first time?. Would
having a method like getProgress() or something like that in
ShuffleEventHandler, where this statement can be logged to provide more
accurate number?. This can be periodically called as well as from
UnorderedKVInput.close().
ShuffleInputEventHandlerOrderedGrouped:
- Similar comments as ShuffleInputEventHandlerImpl for log statement in
handleEvent().
ShuffleManager:
- Can "Created Fetcher for host:" be retained?
- logProgress(); //can be used for mining later. Would printing it only for 50
times might make it hard to interpret?
ShuffleScheduler:
- Same as ShuffleManager for logProgress().
ShuffleUtils:logIndividualFetchComplete() - Changes can break the perf analysis
tool for different versions?
> Reduce logging in runtime components
>
>
> Key: TEZ-2775
> URL: https://issues.apache.org/jira/browse/TEZ-2775
> Project: Apache Tez
> Issue Type: Sub-task
>Reporter: Siddharth Seth
>Assignee: Siddharth Seth
> Attachments: TEZ-2775.1.txt
>
>
> Specifically Shuffle, which logs a lot for each event being processed and
> data being fetched.
> Also PipelinedShuffle is fairly noisy - some of the information from here
> could be consolidated.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
[jira] [Commented] (TEZ-2775) Reduce logging in runtime components
[ https://issues.apache.org/jira/browse/TEZ-2775?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=14739179#comment-14739179 ] Siddharth Seth commented on TEZ-2775: - bq. Fetcher/FetcherOrderedGrouped - should we retain the decomp, compressed size, type information?. That has helped in couple of scenarios when debugging. Is it sufficient if this information is available on failure ? I believe the information is already logged for a successful fetch. bq. MRInput/MROutput/MultiMRInput - space needed in "newmapreduce" or is that intentional? Intentional, but can be changed. bq. in flush(), indexcache empty check is due to TEZ-2440. This is completely harmeless and can be removed. If we do not have this check, and if the task gets killed in the middle, it can throw NPE leading to distraction when debugging. This should be documented - with the details you provided. bq. numObsoletionEvenets - spelling? Will fix. bq. If there are only 10 or 30 events, it might only print the first time?. Would having a method like getProgress() or something like that in ShuffleEventHandler, where this statement can be logged to provide more accurate number?. This can be periodically called as well as from UnorderedKVInput.close(). We don't know how many events to expect upfront. The log can be augmented to say something like - "next log after X events". In terms of a getProgress method - at what point will that get called, and how often should it log ? bq. logProgress(); //can be used for mining later. Would printing it only for 50 times might make it hard to interpret? This is always logged after all fetches complete; is that not sufficient ? In terms of mining at a later point, we may want to think of an alternate mechanism like metrics, rather than having this information in the logs. bq. ShuffleUtils:logIndividualFetchComplete() - Changes can break the perf analysis tool for different versions? It should be possible to change the perf analysis tool to handle to handle different versions of the log line ? This is far shorter than the original log line, and can actually be made shorter. On the rest of the comments, more a little later. > Reduce logging in runtime components > > > Key: TEZ-2775 > URL: https://issues.apache.org/jira/browse/TEZ-2775 > Project: Apache Tez > Issue Type: Sub-task >Reporter: Siddharth Seth >Assignee: Siddharth Seth > Attachments: TEZ-2775.1.txt > > > Specifically Shuffle, which logs a lot for each event being processed and > data being fetched. > Also PipelinedShuffle is fairly noisy - some of the information from here > could be consolidated. -- This message was sent by Atlassian JIRA (v6.3.4#6332)
