[ 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)