[
https://issues.apache.org/jira/browse/TEZ-2282?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14498671#comment-14498671
]
Mit Desai commented on TEZ-2282:
--------------------------------
[~hitesh], [~jeagles], [~knoguchi]. This is how the log files look like after
the patch.
{noformat}
Log Type: stderr
Log Upload Time: 16-Apr-2015 20:17:19
Log Length: 376
2015-04-16 20:17:07 Starting to run new task attempt:
attempt_1429195759237_0018_1_01_000000_0
2015-04-16 20:17:08 Completed running task attempt:
attempt_1429195759237_0018_1_01_000000_0
2015-04-16 20:17:08 Starting to run new task attempt:
attempt_1429195759237_0018_1_02_000000_0
2015-04-16 20:17:08 Completed running task attempt:
attempt_1429195759237_0018_1_02_000000_0
Log Type: stdout
Log Upload Time: 16-Apr-2015 20:17:19
Log Length: 1860
0.202: [GC [PSYoungGen: 5440K->893K(6336K)] 5440K->1517K(64640K), 0.0046680
secs] [Times: user=0.01 sys=0.00, real=0.00 secs]
0.353: [GC [PSYoungGen: 6333K->893K(11776K)] 6957K->2293K(70080K), 0.0049120
secs] [Times: user=0.01 sys=0.00, real=0.00 secs]
0.517: [GC [PSYoungGen: 11773K->885K(11776K)] 13173K->3554K(70080K), 0.0040680
secs] [Times: user=0.01 sys=0.01, real=0.01 secs]
0.690: [GC [PSYoungGen: 11765K->885K(22656K)] 14434K->4622K(80960K), 0.0034990
secs] [Times: user=0.01 sys=0.00, real=0.00 secs]
1.144: [GC [PSYoungGen: 22645K->885K(22656K)] 26382K->6884K(80960K), 0.0054460
secs] [Times: user=0.02 sys=0.00, real=0.01 secs]
1.669: [GC [PSYoungGen: 22645K->3056K(45632K)] 28644K->9986K(103936K),
0.0093110 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]
2015-04-16 20:17:07 Starting to run new task attempt:
attempt_1429195759237_0018_1_01_000000_0
2.227: [GC [PSYoungGen: 45616K->4017K(46592K)] 52546K->11854K(104896K),
0.0231380 secs] [Times: user=0.05 sys=0.00, real=0.03 secs]
2015-04-16 20:17:08 Completed running task attempt:
attempt_1429195759237_0018_1_01_000000_0
2015-04-16 20:17:08 Starting to run new task attempt:
attempt_1429195759237_0018_1_02_000000_0
2015-04-16 20:17:08 Completed running task attempt:
attempt_1429195759237_0018_1_02_000000_0
Heap
PSYoungGen total 46592K, used 46577K [0xed280000, 0xf2f80000, 0xf4440000)
eden space 42560K, 100% used [0xed280000,0xefc10000,0xefc10000)
from space 4032K, 99% used [0xefc10000,0xefffc768,0xf0000000)
to space 5056K, 0% used [0xf2a90000,0xf2a90000,0xf2f80000)
ParOldGen total 125952K, used 75420K [0xb4440000, 0xbbf40000, 0xed280000)
object space 125952K, 59% used [0xb4440000,0xb8de73f0,0xbbf40000)
PSPermGen total 16384K, used 12647K [0xb0440000, 0xb1440000, 0xb4440000)
object space 16384K, 77% used [0xb0440000,0xb1099f90,0xb1440000)
{noformat}
{noformat}
Log Type: dag_1429195759237_0018_1.dot
Log Upload Time: 16-Apr-2015 20:17:19
Log Length: 1154
digraph MRRSleepJob {
graph [ label="MRRSleepJob", fontsize=24, fontname=Helvetica];
node [fontsize=12, fontname=Helvetica];
edge [fontsize=9, fontcolor=blue, fontname=Arial];
"MRRSleepJob.reduce" [ label = "reduce[ReduceProcessor]" ];
"MRRSleepJob.reduce" -> "MRRSleepJob.reduce_MROutput" [ label = "Output
[outputClass=MROutputLegacy,\n initializer=MROutputCommitter]" ];
"MRRSleepJob.ireduce1" [ label = "ireduce1[ReduceProcessor]" ];
"MRRSleepJob.ireduce1" -> "MRRSleepJob.reduce" [ label =
"[input=OrderedPartitionedKVOutput,\n output=OrderedGroupedInputLegacy,\n
dataMovement=SCATTER_GATHER,\n schedulingType=SEQUENTIAL]" ];
"MRRSleepJob.reduce_MROutput" [ label = "reduce[MROutput]", shape = "box" ];
"MRRSleepJob.map_MRInput" [ label = "map[MRInput]", shape = "box" ];
"MRRSleepJob.map_MRInput" -> "MRRSleepJob.map" [ label = "Input
[inputClass=MRInputLegacy,\n initializer=MRInputSplitDistributor]" ];
"MRRSleepJob.map" [ label = "map[MapProcessor]" ];
"MRRSleepJob.map" -> "MRRSleepJob.ireduce1" [ label =
"[input=OrderedPartitionedKVOutput,\n output=OrderedGroupedInputLegacy,\n
dataMovement=SCATTER_GATHER,\n schedulingType=SEQUENTIAL]" ];
}
Log Type: stderr
Log Upload Time: 16-Apr-2015 20:17:19
Log Length: 118
2015-04-16 20:16:54 Running Dag: dag_1429195759237_0018_1
2015-04-16 20:17:08 Completed Dag: dag_1429195759237_0018_1
Log Type: stdout
Log Upload Time: 16-Apr-2015 20:17:19
Log Length: 1757
0.395: [GC [PSYoungGen: 16448K->2680K(19136K)] 16448K->3177K(62848K), 0.0062140
secs] [Times: user=0.01 sys=0.00, real=0.00 secs]
0.599: [GC [PSYoungGen: 19128K->2679K(35584K)] 19625K->3268K(79296K), 0.0072310
secs] [Times: user=0.01 sys=0.00, real=0.01 secs]
1.247: [GC [PSYoungGen: 35575K->2683K(35584K)] 36164K->5911K(79296K), 0.0100360
secs] [Times: user=0.03 sys=0.00, real=0.01 secs]
1.636: [GC [PSYoungGen: 35579K->2675K(68480K)] 38807K->7810K(112192K),
0.0093970 secs] [Times: user=0.03 sys=0.00, real=0.01 secs]
2.169: [GC [PSYoungGen: 68467K->2685K(68480K)] 73602K->12997K(112192K),
0.0152030 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]
2.845: [GC [PSYoungGen: 68477K->7379K(138688K)] 78789K->17695K(182400K),
0.0137060 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]
3.193: [GC [PSYoungGen: 138003K->7464K(139648K)] 148319K->18858K(183360K),
0.0176240 secs] [Times: user=0.05 sys=0.01, real=0.02 secs]
2015-04-16 20:16:54 Running Dag: dag_1429195759237_0018_1
4.163: [GC [PSYoungGen: 138088K->9654K(265344K)] 149482K->23657K(309056K),
0.0211740 secs] [Times: user=0.05 sys=0.01, real=0.03 secs]
2015-04-16 20:17:08 Completed Dag: dag_1429195759237_0018_1
Heap
PSYoungGen total 265344K, used 180717K [0xe33f0000, 0xf4540000,
0xf4540000)
eden space 255680K, 66% used [0xe33f0000,0xedafdd48,0xf2da0000)
from space 9664K, 99% used [0xf3bd0000,0xf453da98,0xf4540000)
to space 12096K, 0% used [0xf2da0000,0xf2da0000,0xf3970000)
ParOldGen total 43712K, used 14002K [0xc1140000, 0xc3bf0000, 0xe33f0000)
object space 43712K, 32% used [0xc1140000,0xc1eeca98,0xc3bf0000)
PSPermGen total 28736K, used 28708K [0xbd140000, 0xbed50000, 0xc1140000)
object space 28736K, 99% used [0xbd140000,0xbed490e8,0xbed50000)
{noformat}
> Delimit reused yarn container logs (stderr, stdout, syslog) with task attempt
> start/stop events
> -----------------------------------------------------------------------------------------------
>
> Key: TEZ-2282
> URL: https://issues.apache.org/jira/browse/TEZ-2282
> Project: Apache Tez
> Issue Type: Bug
> Reporter: Jonathan Eagles
> Assignee: Mit Desai
> Attachments: TEZ-2282.1.patch, TEZ-2282.2.patch,
> TEZ-2282.3.master.patch, TEZ-2282.3.patch, TEZ-2282.master.1.patch
>
>
> This could help with debugging in some cases where logging is task specific.
> For example GC log is going to stdout, it will be nice to see task attempt
> start/stop times
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
