==============================================================================
LogType:syslog_attempt_1545806970486_0026_1_00_000073_0
LogLastModifiedTime:Thu Dec 27 13:01:46 +0900 2018
LogLength:22846
LogContents:
2018-12-27 13:01:44,594 [INFO] [main] |task.TezChild|: Refreshing UGI since Credentials have changed. Credentials : #Tokens=1, #SecretKeys=0
2018-12-27 13:01:44,633 [INFO] [main] |metrics.TaskCounterUpdater|: Using ResourceCalculatorProcessTree : org.apache.tez.util.TezMxBeanResourceCalculator
2018-12-27 13:01:44,634 [INFO] [main] |runtime.LogicalIOProcessorRuntimeTask|: Initializing LogicalIOProcessorRuntimeTask with TaskSpec: DAGName : INSERT OVERWRITE TABLE tb...sys(Stage-1), VertexName: Map 1, VertexParallelism: 231, TaskAttemptID:attempt_1545806970486_0026_1_00_000073_0, processorName=org.apache.hadoop.hive.ql.exec.tez.MapTezProcessor, inputSpecListSize=1, outputSpecListSize=1, inputSpecList=[{{ sourceVertexName=tb_udf, physicalEdgeCount=1, inputClassName=org.apache.tez.mapreduce.input.MRInputLegacy }}, ], outputSpecList=[{{ destinationVertexName=Reducer 2, physicalEdgeCount=418, outputClassName=org.apache.tez.runtime.library.output.OrderedPartitionedKVOutput }}, ], taskConfEntryCount=0
2018-12-27 13:01:44,635 [INFO] [main] |resources.MemoryDistributor|: InitialMemoryDistributor (isEnabled=true) invoked with: numInputs=1, numOutputs=1, JVM.maxFree=828375040, allocatorClassName=org.apache.tez.runtime.library.resources.WeightedScalingMemoryDistributor
2018-12-27 13:01:44,658 [INFO] [TezChild] |task.TezTaskRunner|: Initializing task, taskAttemptId=attempt_1545806970486_0026_1_00_000073_0
2018-12-27 13:01:44,667 [INFO] [TaskHeartbeatThread] |task.TaskReporter|: Routing events from heartbeat response to task, currentTaskAttemptId=attempt_1545806970486_0026_1_00_000073_0, eventCount=1 fromEventId=0 nextFromEventId=0
2018-12-27 13:01:44,710 [INFO] [TezChild] |log.PerfLogger|:
2018-12-27 13:01:44,715 [INFO] [TezChild] |Configuration.deprecation|: mapred.committer.job.setup.cleanup.needed is deprecated. Instead, use mapreduce.job.committer.setup.cleanup.needed
2018-12-27 13:01:44,715 [INFO] [TezChild] |Configuration.deprecation|: mapred.input.dir.recursive is deprecated. Instead, use mapreduce.input.fileinputformat.input.dir.recursive
2018-12-27 13:01:44,721 [INFO] [TezChild] |Configuration.deprecation|: mapred.task.id is deprecated. Instead, use mapreduce.task.attempt.id
2018-12-27 13:01:44,721 [INFO] [TezChild] |Configuration.deprecation|: mapred.task.partition is deprecated. Instead, use mapreduce.task.partition
2018-12-27 13:01:44,721 [INFO] [TezChild] |log.PerfLogger|:
2018-12-27 13:01:44,721 [INFO] [TezChild] |runtime.LogicalIOProcessorRuntimeTask|: Initialized processor
2018-12-27 13:01:44,721 [INFO] [TezChild] |runtime.LogicalIOProcessorRuntimeTask|: Waiting for 2 initializers to finish
2018-12-27 13:01:44,750 [INFO] [TezChild] |runtime.LogicalIOProcessorRuntimeTask|: Waiting for 1 initializers to finish
2018-12-27 13:01:44,758 [INFO] [I/O Setup 0 Initialize: {tb_udf}] |counters.Limits|: Counter limits initialized with parameters: GROUP_NAME_MAX=256, MAX_GROUPS=3000, COUNTER_NAME_MAX=64, MAX_COUNTERS=10000
2018-12-27 13:01:44,765 [INFO] [I/O Setup 0 Initialize: {tb_udf}] |input.MRInput|: tb_udf using newmapreduce API=false, split via event=true, numPhysicalInputs=1
2018-12-27 13:01:44,765 [INFO] [I/O Setup 0 Initialize: {tb_udf}] |input.MRInputLegacy|: tb_udf MRInputLegacy deferring initialization
2018-12-27 13:01:44,767 [INFO] [TezChild] |runtime.LogicalIOProcessorRuntimeTask|: All initializers finished
2018-12-27 13:01:44,770 [INFO] [TezChild] |resources.MemoryDistributor|: InitialRequests=[tb_udf:INPUT:0:org.apache.tez.mapreduce.input.MRInputLegacy], [Reducer 2:OUTPUT:283115520:org.apache.tez.runtime.library.output.OrderedPartitionedKVOutput]
2018-12-27 13:01:44,774 [INFO] [TezChild] |resources.WeightedScalingMemoryDistributor|: ScaleRatiosUsed=[PARTITIONED_UNSORTED_OUTPUT:1][UNSORTED_OUTPUT:1][UNSORTED_INPUT:1][SORTED_OUTPUT:12][SORTED_MERGED_INPUT:12][PROCESSOR:1][OTHER:1]
2018-12-27 13:01:44,777 [INFO] [TezChild] |resources.WeightedScalingMemoryDistributor|: InitialReservationFraction=0.3, AdditionalReservationFractionForIOs=0.03, finalReserveFractionUsed=0.32999999999999996
2018-12-27 13:01:44,777 [INFO] [TezChild] |resources.WeightedScalingMemoryDistributor|: Scaling Requests. NumRequests: 2, numScaledRequests: 13, TotalRequested: 283115520, TotalRequestedScaled: 2.613374030769231E8, TotalJVMHeap: 828375040, TotalAvailable: 555011276, TotalRequested/TotalJVMHeap:0.34
2018-12-27 13:01:44,777 [INFO] [TezChild] |resources.MemoryDistributor|: Allocations=[tb_udf:org.apache.tez.mapreduce.input.MRInputLegacy:INPUT:0:0], [Reducer 2:org.apache.tez.runtime.library.output.OrderedPartitionedKVOutput:OUTPUT:283115520:283115520]
2018-12-27 13:01:44,777 [INFO] [TezChild] |runtime.LogicalIOProcessorRuntimeTask|: Starting Inputs/Outputs
2018-12-27 13:01:44,778 [INFO] [I/O Setup 1 Start: {tb_udf}] |runtime.LogicalIOProcessorRuntimeTask|: Started Input with src edge: tb_udf
2018-12-27 13:01:44,778 [INFO] [TezChild] |runtime.LogicalIOProcessorRuntimeTask|: Input: tb_udf being auto started by the framework. Subsequent instances will not be auto-started
2018-12-27 13:01:44,778 [INFO] [TezChild] |runtime.LogicalIOProcessorRuntimeTask|: Num IOs determined for AutoStart: 1
2018-12-27 13:01:44,778 [INFO] [TezChild] |runtime.LogicalIOProcessorRuntimeTask|: Waiting for 1 IOs to start
2018-12-27 13:01:44,778 [INFO] [TezChild] |runtime.LogicalIOProcessorRuntimeTask|: AutoStartComplete
2018-12-27 13:01:44,788 [INFO] [TezChild] |task.TezTaskRunner|: Running task, taskAttemptId=attempt_1545806970486_0026_1_00_000073_0
2018-12-27 13:01:44,788 [INFO] [TezChild] |log.PerfLogger|:
2018-12-27 13:01:44,991 [INFO] [TezChild] |exec.Utilities|: PLAN PATH = hdfs://hortonwork0.ucak:8020/tmp/hive/hdfs/81ad51e1-49c6-476a-ae4a-4404156329a7/hive_2018-12-27_13-01-34_331_3965675722525534696-1/7a5f4a4a-9334-4c07-88f0-0385fbd5299d/map.xml
2018-12-27 13:01:45,009 [INFO] [TezChild] |log.PerfLogger|:
2018-12-27 13:01:45,009 [INFO] [TezChild] |exec.Utilities|: Deserializing MapWork via kryo
2018-12-27 13:01:45,634 [INFO] [TezChild] |log.PerfLogger|:
2018-12-27 13:01:45,635 [INFO] [TezChild] |tez.ObjectCache|: Caching key: hdfs_20181227130134_261b061d-ef40-42c2-98c4-b5941f84c11d__MAP_PLAN__
2018-12-27 13:01:45,637 [INFO] [TezChild] |log.PerfLogger|:
2018-12-27 13:01:45,651 [INFO] [TezChild] |tez.MapRecordProcessor|: The input names are: [tb_udf]
2018-12-27 13:01:45,652 [INFO] [TezChild] |input.MRInput|: Initialized MRInput: tb_udf
2018-12-27 13:01:45,722 [INFO] [TezChild] |exec.Utilities|: PLAN PATH = hdfs://hortonwork0.ucak:8020/tmp/hive/hdfs/81ad51e1-49c6-476a-ae4a-4404156329a7/hive_2018-12-27_13-01-34_331_3965675722525534696-1/7a5f4a4a-9334-4c07-88f0-0385fbd5299d/map.xml
2018-12-27 13:01:46,123 [ERROR] [TezChild] |tez.TezProcessor|: java.lang.VerifyError: Bad return type
Exception Details:
Location:
org/apache/hadoop/hdfs/DFSClient.getQuotaUsage(Ljava/lang/String;)Lorg/apache/hadoop/fs/QuotaUsage; @94: areturn
Reason:
Type 'org/apache/hadoop/fs/ContentSummary' (current frame, stack[0]) is not assignable to 'org/apache/hadoop/fs/QuotaUsage' (from method signature)
Current Frame:
bci: @94
flags: { }
locals: { 'org/apache/hadoop/hdfs/DFSClient', 'java/lang/String', 'org/apache/htrace/TraceScope', 'org/apache/hadoop/ipc/RemoteException', 'java/io/IOException', 'org/apache/hadoop/fs/ContentSummary' }
stack: { 'org/apache/hadoop/fs/ContentSummary' }
Bytecode:
0x0000000: 2ab6 00ef 2a13 0257 2bb6 00b9 4d2a b400
0x0000010: 452b b902 5802 004e 2cb6 00bb 2db0 4e2d
0x0000020: 07bd 00d4 5903 12d6 5359 0412 ed53 5905
0x0000030: 12ee 5359 0613 0259 53b6 00d7 3a04 1904
0x0000040: c102 5999 001c b200 1e13 025a b900 2002
0x0000050: 002a 2bb6 025b 3a05 2cb6 00bb 1905 b019
0x0000060: 04bf 3a06 2cb6 00bb 1906 bf
Exception Handler Table:
bci [13, 24] => handler: 30
bci [13, 24] => handler: 98
bci [30, 88] => handler: 98
bci [95, 100] => handler: 98
Stackmap Table:
full_frame(@30,{Object[#831],Object[#836],Object[#914]},{Object[#939]})
append_frame(@95,Object[#939],Object[#897])
full_frame(@98,{Object[#831],Object[#836],Object[#914]},{Object[#886]})
at org.apache.hadoop.hdfs.DistributedFileSystem.initialize(DistributedFileSystem.java:160)
at org.apache.hadoop.fs.FileSystem.createFileSystem(FileSystem.java:2669)
at org.apache.hadoop.fs.FileSystem.access$200(FileSystem.java:94)
at org.apache.hadoop.fs.FileSystem$Cache.getInternal(FileSystem.java:2703)
at org.apache.hadoop.fs.FileSystem$Cache.get(FileSystem.java:2685)
at org.apache.hadoop.fs.FileSystem.get(FileSystem.java:373)
at org.apache.hadoop.fs.Path.getFileSystem(Path.java:295)
at org.apache.hadoop.mapred.LineRecordReader.(LineRecordReader.java:108)
at org.apache.hadoop.mapred.TextInputFormat.getRecordReader(TextInputFormat.java:67)
at org.apache.hadoop.hive.ql.io.HiveInputFormat.getRecordReader(HiveInputFormat.java:255)
at org.apache.hadoop.mapred.split.TezGroupedSplitsInputFormat$TezGroupedSplitsRecordReader.initNextRecordReader(TezGroupedSplitsInputFormat.java:193)
at org.apache.hadoop.mapred.split.TezGroupedSplitsInputFormat$TezGroupedSplitsRecordReader.(TezGroupedSplitsInputFormat.java:135)
at org.apache.hadoop.mapred.split.TezGroupedSplitsInputFormat.getRecordReader(TezGroupedSplitsInputFormat.java:101)
at org.apache.tez.mapreduce.lib.MRReaderMapred.setupOldRecordReader(MRReaderMapred.java:149)
at org.apache.tez.mapreduce.lib.MRReaderMapred.setSplit(MRReaderMapred.java:80)
at org.apache.tez.mapreduce.input.MRInput.initFromEventInternal(MRInput.java:674)
at org.apache.tez.mapreduce.input.MRInput.initFromEvent(MRInput.java:633)
at org.apache.tez.mapreduce.input.MRInputLegacy.checkAndAwaitRecordReaderInitialization(MRInputLegacy.java:145)
at org.apache.tez.mapreduce.input.MRInputLegacy.init(MRInputLegacy.java:109)
at org.apache.hadoop.hive.ql.exec.tez.MapRecordProcessor.getMRInput(MapRecordProcessor.java:405)
at org.apache.hadoop.hive.ql.exec.tez.MapRecordProcessor.init(MapRecordProcessor.java:124)
at org.apache.hadoop.hive.ql.exec.tez.TezProcessor.initializeAndRunProcessor(TezProcessor.java:149)
at org.apache.hadoop.hive.ql.exec.tez.TezProcessor.run(TezProcessor.java:139)
at org.apache.tez.runtime.LogicalIOProcessorRuntimeTask.run(LogicalIOProcessorRuntimeTask.java:347)
at org.apache.tez.runtime.task.TezTaskRunner$TaskRunnerCallable$1.run(TezTaskRunner.java:194)
at org.apache.tez.runtime.task.TezTaskRunner$TaskRunnerCallable$1.run(TezTaskRunner.java:185)
at java.security.AccessController.doPrivileged(Native Method)
at javax.security.auth.Subject.doAs(Subject.java:422)
at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1698)
at org.apache.tez.runtime.task.TezTaskRunner$TaskRunnerCallable.callInternal(TezTaskRunner.java:185)
at org.apache.tez.runtime.task.TezTaskRunner$TaskRunnerCallable.callInternal(TezTaskRunner.java:181)
at org.apache.tez.common.CallableWithNdc.call(CallableWithNdc.java:36)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
2018-12-27 13:01:46,123 [INFO] [TezChild] |task.TezTaskRunner|: Encounted an error while executing task: attempt_1545806970486_0026_1_00_000073_0
java.lang.RuntimeException: java.lang.VerifyError: Bad return type
Exception Details:
Location:
org/apache/hadoop/hdfs/DFSClient.getQuotaUsage(Ljava/lang/String;)Lorg/apache/hadoop/fs/QuotaUsage; @94: areturn
Reason:
Type 'org/apache/hadoop/fs/ContentSummary' (current frame, stack[0]) is not assignable to 'org/apache/hadoop/fs/QuotaUsage' (from method signature)
Current Frame:
bci: @94
flags: { }
locals: { 'org/apache/hadoop/hdfs/DFSClient', 'java/lang/String', 'org/apache/htrace/TraceScope', 'org/apache/hadoop/ipc/RemoteException', 'java/io/IOException', 'org/apache/hadoop/fs/ContentSummary' }
stack: { 'org/apache/hadoop/fs/ContentSummary' }
Bytecode:
0x0000000: 2ab6 00ef 2a13 0257 2bb6 00b9 4d2a b400
0x0000010: 452b b902 5802 004e 2cb6 00bb 2db0 4e2d
0x0000020: 07bd 00d4 5903 12d6 5359 0412 ed53 5905
0x0000030: 12ee 5359 0613 0259 53b6 00d7 3a04 1904
0x0000040: c102 5999 001c b200 1e13 025a b900 2002
0x0000050: 002a 2bb6 025b 3a05 2cb6 00bb 1905 b019
0x0000060: 04bf 3a06 2cb6 00bb 1906 bf
Exception Handler Table:
bci [13, 24] => handler: 30
bci [13, 24] => handler: 98
bci [30, 88] => handler: 98
bci [95, 100] => handler: 98
Stackmap Table:
full_frame(@30,{Object[#831],Object[#836],Object[#914]},{Object[#939]})
append_frame(@95,Object[#939],Object[#897])
full_frame(@98,{Object[#831],Object[#836],Object[#914]},{Object[#886]})
at org.apache.hadoop.hive.ql.exec.tez.TezProcessor.initializeAndRunProcessor(TezProcessor.java:159)
at org.apache.hadoop.hive.ql.exec.tez.TezProcessor.run(TezProcessor.java:139)
at org.apache.tez.runtime.LogicalIOProcessorRuntimeTask.run(LogicalIOProcessorRuntimeTask.java:347)
at org.apache.tez.runtime.task.TezTaskRunner$TaskRunnerCallable$1.run(TezTaskRunner.java:194)
at org.apache.tez.runtime.task.TezTaskRunner$TaskRunnerCallable$1.run(TezTaskRunner.java:185)
at java.security.AccessController.doPrivileged(Native Method)
at javax.security.auth.Subject.doAs(Subject.java:422)
at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1698)
at org.apache.tez.runtime.task.TezTaskRunner$TaskRunnerCallable.callInternal(TezTaskRunner.java:185)
at org.apache.tez.runtime.task.TezTaskRunner$TaskRunnerCallable.callInternal(TezTaskRunner.java:181)
at org.apache.tez.common.CallableWithNdc.call(CallableWithNdc.java:36)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.VerifyError: Bad return type
Exception Details:
Location:
org/apache/hadoop/hdfs/DFSClient.getQuotaUsage(Ljava/lang/String;)Lorg/apache/hadoop/fs/QuotaUsage; @94: areturn
Reason:
Type 'org/apache/hadoop/fs/ContentSummary' (current frame, stack[0]) is not assignable to 'org/apache/hadoop/fs/QuotaUsage' (from method signature)
Current Frame:
bci: @94
flags: { }
locals: { 'org/apache/hadoop/hdfs/DFSClient', 'java/lang/String', 'org/apache/htrace/TraceScope', 'org/apache/hadoop/ipc/RemoteException', 'java/io/IOException', 'org/apache/hadoop/fs/ContentSummary' }
stack: { 'org/apache/hadoop/fs/ContentSummary' }
Bytecode:
0x0000000: 2ab6 00ef 2a13 0257 2bb6 00b9 4d2a b400
0x0000010: 452b b902 5802 004e 2cb6 00bb 2db0 4e2d
0x0000020: 07bd 00d4 5903 12d6 5359 0412 ed53 5905
0x0000030: 12ee 5359 0613 0259 53b6 00d7 3a04 1904
0x0000040: c102 5999 001c b200 1e13 025a b900 2002
0x0000050: 002a 2bb6 025b 3a05 2cb6 00bb 1905 b019
0x0000060: 04bf 3a06 2cb6 00bb 1906 bf
Exception Handler Table:
bci [13, 24] => handler: 30
bci [13, 24] => handler: 98
bci [30, 88] => handler: 98
bci [95, 100] => handler: 98
Stackmap Table:
full_frame(@30,{Object[#831],Object[#836],Object[#914]},{Object[#939]})
append_frame(@95,Object[#939],Object[#897])
full_frame(@98,{Object[#831],Object[#836],Object[#914]},{Object[#886]})
at org.apache.hadoop.hdfs.DistributedFileSystem.initialize(DistributedFileSystem.java:160)
at org.apache.hadoop.fs.FileSystem.createFileSystem(FileSystem.java:2669)
at org.apache.hadoop.fs.FileSystem.access$200(FileSystem.java:94)
at org.apache.hadoop.fs.FileSystem$Cache.getInternal(FileSystem.java:2703)
at org.apache.hadoop.fs.FileSystem$Cache.get(FileSystem.java:2685)
at org.apache.hadoop.fs.FileSystem.get(FileSystem.java:373)
at org.apache.hadoop.fs.Path.getFileSystem(Path.java:295)
at org.apache.hadoop.mapred.LineRecordReader.(LineRecordReader.java:108)
at org.apache.hadoop.mapred.TextInputFormat.getRecordReader(TextInputFormat.java:67)
at org.apache.hadoop.hive.ql.io.HiveInputFormat.getRecordReader(HiveInputFormat.java:255)
at org.apache.hadoop.mapred.split.TezGroupedSplitsInputFormat$TezGroupedSplitsRecordReader.initNextRecordReader(TezGroupedSplitsInputFormat.java:193)
at org.apache.hadoop.mapred.split.TezGroupedSplitsInputFormat$TezGroupedSplitsRecordReader.(TezGroupedSplitsInputFormat.java:135)
at org.apache.hadoop.mapred.split.TezGroupedSplitsInputFormat.getRecordReader(TezGroupedSplitsInputFormat.java:101)
at org.apache.tez.mapreduce.lib.MRReaderMapred.setupOldRecordReader(MRReaderMapred.java:149)
at org.apache.tez.mapreduce.lib.MRReaderMapred.setSplit(MRReaderMapred.java:80)
at org.apache.tez.mapreduce.input.MRInput.initFromEventInternal(MRInput.java:674)
at org.apache.tez.mapreduce.input.MRInput.initFromEvent(MRInput.java:633)
at org.apache.tez.mapreduce.input.MRInputLegacy.checkAndAwaitRecordReaderInitialization(MRInputLegacy.java:145)
at org.apache.tez.mapreduce.input.MRInputLegacy.init(MRInputLegacy.java:109)
at org.apache.hadoop.hive.ql.exec.tez.MapRecordProcessor.getMRInput(MapRecordProcessor.java:405)
at org.apache.hadoop.hive.ql.exec.tez.MapRecordProcessor.init(MapRecordProcessor.java:124)
at org.apache.hadoop.hive.ql.exec.tez.TezProcessor.initializeAndRunProcessor(TezProcessor.java:149)
... 14 more
2018-12-27 13:01:46,126 [INFO] [TezChild] |runtime.LogicalIOProcessorRuntimeTask|: Final Counters for attempt_1545806970486_0026_1_00_000073_0: Counters: 4 [[org.apache.tez.common.counters.TaskCounter INPUT_RECORDS_PROCESSED=0, INPUT_SPLIT_LENGTH_BYTES=94087447][TaskCounter_Map_1_INPUT_tb_udf INPUT_RECORDS_PROCESSED=0, INPUT_SPLIT_LENGTH_BYTES=94087447]]
2018-12-27 13:01:46,126 [INFO] [TezChild] |runtime.LogicalIOProcessorRuntimeTask|: Joining on EventRouter
2018-12-27 13:01:46,126 [INFO] [TezChild] |runtime.LogicalIOProcessorRuntimeTask|: Closed processor for vertex=Map 1, index=0
2018-12-27 13:01:46,126 [INFO] [TezChild] |runtime.LogicalIOProcessorRuntimeTask|: Closed input for vertex=Map 1, sourceVertex=tb_udf
2018-12-27 13:01:46,126 [WARN] [TezChild] |output.OrderedPartitionedKVOutput|: Reducer 2: Attempting to close output Reducer 2 of type OrderedPartitionedKVOutput before it was started. Generating empty events
2018-12-27 13:01:46,130 [INFO] [TezChild] |shuffle.ShuffleUtils|: Setting all 418 partitions as empty for non-started output
2018-12-27 13:01:46,131 [INFO] [TezChild] |runtime.LogicalIOProcessorRuntimeTask|: Closed input for vertex=Map 1, sourceVertex=Reducer 2
2018-12-27 13:01:46,148 [ERROR] [main] |task.TezTaskRunner|: Exception of type Error.
java.lang.NoSuchMethodError: org.apache.hadoop.fs.FileSystem.getGlobalStorageStatistics()Lorg/apache/hadoop/fs/GlobalStorageStatistics;
at org.apache.tez.runtime.metrics.TaskCounterUpdater.updateCounters(TaskCounterUpdater.java:111)
at org.apache.tez.runtime.RuntimeTask.setFrameworkCounters(RuntimeTask.java:161)
at org.apache.tez.runtime.task.TezTaskRunner.sendFailure(TezTaskRunner.java:279)
at org.apache.tez.runtime.task.TezTaskRunner.access$500(TezTaskRunner.java:55)
at org.apache.tez.runtime.task.TezTaskRunner$TaskRunnerCallable$1.run(TezTaskRunner.java:245)
at org.apache.tez.runtime.task.TezTaskRunner$TaskRunnerCallable$1.run(TezTaskRunner.java:185)
at java.security.AccessController.doPrivileged(Native Method)
at javax.security.auth.Subject.doAs(Subject.java:422)
at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1698)
at org.apache.tez.runtime.task.TezTaskRunner$TaskRunnerCallable.callInternal(TezTaskRunner.java:185)
at org.apache.tez.runtime.task.TezTaskRunner$TaskRunnerCallable.callInternal(TezTaskRunner.java:181)
at org.apache.tez.common.CallableWithNdc.call(CallableWithNdc.java:36)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
2018-12-27 13:01:46,149 [WARN] [main] |task.TezTaskRunner|: Ignoring fatal error since another error has already been reported
java.lang.NoSuchMethodError: org.apache.hadoop.fs.FileSystem.getGlobalStorageStatistics()Lorg/apache/hadoop/fs/GlobalStorageStatistics;
at org.apache.tez.runtime.metrics.TaskCounterUpdater.updateCounters(TaskCounterUpdater.java:111)
at org.apache.tez.runtime.RuntimeTask.setFrameworkCounters(RuntimeTask.java:161)
at org.apache.tez.runtime.task.TezTaskRunner.sendFailure(TezTaskRunner.java:279)
at org.apache.tez.runtime.task.TezTaskRunner.access$500(TezTaskRunner.java:55)
at org.apache.tez.runtime.task.TezTaskRunner$TaskRunnerCallable$1.run(TezTaskRunner.java:245)
at org.apache.tez.runtime.task.TezTaskRunner$TaskRunnerCallable$1.run(TezTaskRunner.java:185)
at java.security.AccessController.doPrivileged(Native Method)
at javax.security.auth.Subject.doAs(Subject.java:422)
at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1698)
at org.apache.tez.runtime.task.TezTaskRunner$TaskRunnerCallable.callInternal(TezTaskRunner.java:185)
at org.apache.tez.runtime.task.TezTaskRunner$TaskRunnerCallable.callInternal(TezTaskRunner.java:181)
at org.apache.tez.common.CallableWithNdc.call(CallableWithNdc.java:36)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
2018-12-27 13:01:46,149 [INFO] [main] |task.TezChild|: Shutdown invoked for container container_e13_1545806970486_0026_01_000051
2018-12-27 13:01:46,149 [INFO] [main] |task.TezChild|: Shutting down container container_e13_1545806970486_0026_01_000051
End of LogType:syslog_attempt_1545806970486_0026_1_00_000073_0
****************************************************************************************************************
Container: container_e13_1545806970486_0026_01_000051 on hortonwork2.ucak_45454
LogAggregationType: AGGREGATED
==============================================================================
==============================================================================
LogType:syslog_attempt_1545806970486_0026_1_00_000054_3
LogLastModifiedTime:Thu Dec 27 13:01:57 +0900 2018
LogLength:6425
LogContents:
2018-12-27 13:01:57,031 [INFO] [main] |task.TezChild|: Refreshing UGI since Credentials have changed. Credentials : #Tokens=1, #SecretKeys=0
2018-12-27 13:01:57,049 [INFO] [main] |metrics.TaskCounterUpdater|: Using ResourceCalculatorProcessTree : org.apache.tez.util.TezMxBeanResourceCalculator
2018-12-27 13:01:57,049 [INFO] [main] |runtime.LogicalIOProcessorRuntimeTask|: Initializing LogicalIOProcessorRuntimeTask with TaskSpec: DAGName : INSERT OVERWRITE TABLE tb...sys(Stage-1), VertexName: Map 1, VertexParallelism: 231, TaskAttemptID:attempt_1545806970486_0026_1_00_000054_3, processorName=org.apache.hadoop.hive.ql.exec.tez.MapTezProcessor, inputSpecListSize=1, outputSpecListSize=1, inputSpecList=[{{ sourceVertexName=tb_udf, physicalEdgeCount=1, inputClassName=org.apache.tez.mapreduce.input.MRInputLegacy }}, ], outputSpecList=[{{ destinationVertexName=Reducer 2, physicalEdgeCount=418, outputClassName=org.apache.tez.runtime.library.output.OrderedPartitionedKVOutput }}, ], taskConfEntryCount=0
2018-12-27 13:01:57,051 [INFO] [main] |resources.MemoryDistributor|: InitialMemoryDistributor (isEnabled=true) invoked with: numInputs=1, numOutputs=1, JVM.maxFree=828375040, allocatorClassName=org.apache.tez.runtime.library.resources.WeightedScalingMemoryDistributor
2018-12-27 13:01:57,056 [INFO] [TaskHeartbeatThread] |task.TaskReporter|: Received should die response from AM
2018-12-27 13:01:57,056 [INFO] [TaskHeartbeatThread] |task.TaskReporter|: Asked to die via task heartbeat
2018-12-27 13:01:57,059 [INFO] [main] |task.TezTaskRunner|: Interrupted while waiting for task to complete. Interrupting task
2018-12-27 13:01:57,059 [INFO] [main] |task.TezTaskRunner|: Shutdown requested... returning
2018-12-27 13:01:57,059 [INFO] [main] |task.TezChild|: Got a shouldDie notification via heartbeats for container container_e13_1545806970486_0026_01_000295. Shutting down
2018-12-27 13:01:57,059 [INFO] [main] |task.TezChild|: Shutdown invoked for container container_e13_1545806970486_0026_01_000295
2018-12-27 13:01:57,059 [INFO] [main] |task.TezChild|: Shutting down container container_e13_1545806970486_0026_01_000295
2018-12-27 13:01:57,059 [INFO] [TezChild] |task.TezTaskRunner|: Initializing task, taskAttemptId=attempt_1545806970486_0026_1_00_000054_3
2018-12-27 13:01:57,066 [INFO] [TezChild] |log.PerfLogger|:
2018-12-27 13:01:57,070 [INFO] [TezChild] |Configuration.deprecation|: mapred.committer.job.setup.cleanup.needed is deprecated. Instead, use mapreduce.job.committer.setup.cleanup.needed
2018-12-27 13:01:57,070 [INFO] [TezChild] |Configuration.deprecation|: mapred.input.dir.recursive is deprecated. Instead, use mapreduce.input.fileinputformat.input.dir.recursive
2018-12-27 13:01:57,075 [INFO] [TezChild] |Configuration.deprecation|: mapred.task.id is deprecated. Instead, use mapreduce.task.attempt.id
2018-12-27 13:01:57,075 [INFO] [TezChild] |Configuration.deprecation|: mapred.task.partition is deprecated. Instead, use mapreduce.task.partition
2018-12-27 13:01:57,075 [INFO] [TezChild] |log.PerfLogger|:
2018-12-27 13:01:57,075 [INFO] [TezChild] |runtime.LogicalIOProcessorRuntimeTask|: Initialized processor
2018-12-27 13:01:57,075 [INFO] [TezChild] |runtime.LogicalIOProcessorRuntimeTask|: Waiting for 2 initializers to finish
2018-12-27 13:01:57,076 [INFO] [TezChild] |task.TezTaskRunner|: Encounted an error while executing task: attempt_1545806970486_0026_1_00_000054_3
java.lang.InterruptedException
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireInterruptibly(AbstractQueuedSynchronizer.java:1220)
at java.util.concurrent.locks.ReentrantLock.lockInterruptibly(ReentrantLock.java:335)
at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:439)
at java.util.concurrent.ExecutorCompletionService.take(ExecutorCompletionService.java:193)
at org.apache.tez.runtime.LogicalIOProcessorRuntimeTask.initialize(LogicalIOProcessorRuntimeTask.java:236)
at org.apache.tez.runtime.task.TezTaskRunner$TaskRunnerCallable$1.run(TezTaskRunner.java:191)
at org.apache.tez.runtime.task.TezTaskRunner$TaskRunnerCallable$1.run(TezTaskRunner.java:185)
at java.security.AccessController.doPrivileged(Native Method)
at javax.security.auth.Subject.doAs(Subject.java:422)
at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1698)
at org.apache.tez.runtime.task.TezTaskRunner$TaskRunnerCallable.callInternal(TezTaskRunner.java:185)
at org.apache.tez.runtime.task.TezTaskRunner$TaskRunnerCallable.callInternal(TezTaskRunner.java:181)
at org.apache.tez.common.CallableWithNdc.call(CallableWithNdc.java:36)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
2018-12-27 13:01:57,078 [INFO] [TezChild] |runtime.LogicalIOProcessorRuntimeTask|: Final Counters for attempt_1545806970486_0026_1_00_000054_3: Counters: 0 []
2018-12-27 13:01:57,078 [INFO] [TezChild] |runtime.LogicalIOProcessorRuntimeTask|: Closed processor for vertex=Map 1, index=0
2018-12-27 13:01:57,078 [WARN] [TezChild] |output.OrderedPartitionedKVOutput|: Reducer 2: Attempting to close output Reducer 2 of type OrderedPartitionedKVOutput before it was started. Generating empty events
2018-12-27 13:01:57,084 [INFO] [TezChild] |shuffle.ShuffleUtils|: Setting all 418 partitions as empty for non-started output
2018-12-27 13:01:57,085 [INFO] [TezChild] |counters.Limits|: Counter limits initialized with parameters: GROUP_NAME_MAX=256, MAX_GROUPS=3000, COUNTER_NAME_MAX=64, MAX_COUNTERS=10000
2018-12-27 13:01:57,088 [INFO] [I/O Setup 0 Initialize: {tb_udf}] |input.MRInput|: tb_udf using newmapreduce API=false, split via event=true, numPhysicalInputs=1
2018-12-27 13:01:57,088 [INFO] [TezChild] |runtime.LogicalIOProcessorRuntimeTask|: Closed input for vertex=Map 1, sourceVertex=Reducer 2
2018-12-27 13:01:57,088 [INFO] [I/O Setup 0 Initialize: {tb_udf}] |input.MRInputLegacy|: tb_udf MRInputLegacy deferring initialization
End of LogType:syslog_attempt_1545806970486_0026_1_00_000054_3
****************************************************************************************************************
Container: container_e13_1545806970486_0026_01_000295 on hortonwork2.ucak_45454
LogAggregationType: AGGREGATED
==============================================================================
==============================================================================
LogType:syslog_attempt_1545806970486_0026_1_00_000049_1
LogLastModifiedTime:Thu Dec 27 13:01:50 +0900 2018
LogLength:20340
LogContents:
2018-12-27 13:01:49,387 [INFO] [main] |task.TezChild|: Refreshing UGI since Credentials have changed. Credentials : #Tokens=1, #SecretKeys=0
2018-12-27 13:01:49,457 [INFO] [main] |metrics.TaskCounterUpdater|: Using ResourceCalculatorProcessTree : org.apache.tez.util.TezMxBeanResourceCalculator
2018-12-27 13:01:49,457 [INFO] [main] |runtime.LogicalIOProcessorRuntimeTask|: Initializing LogicalIOProcessorRuntimeTask with TaskSpec: DAGName : INSERT OVERWRITE TABLE tb...sys(Stage-1), VertexName: Map 1, VertexParallelism: 231, TaskAttemptID:attempt_1545806970486_0026_1_00_000049_1, processorName=org.apache.hadoop.hive.ql.exec.tez.MapTezProcessor, inputSpecListSize=1, outputSpecListSize=1, inputSpecList=[{{ sourceVertexName=tb_udf, physicalEdgeCount=1, inputClassName=org.apache.tez.mapreduce.input.MRInputLegacy }}, ], outputSpecList=[{{ destinationVertexName=Reducer 2, physicalEdgeCount=418, outputClassName=org.apache.tez.runtime.library.output.OrderedPartitionedKVOutput }}, ], taskConfEntryCount=0
2018-12-27 13:01:49,459 [INFO] [main] |resources.MemoryDistributor|: InitialMemoryDistributor (isEnabled=true) invoked with: numInputs=1, numOutputs=1, JVM.maxFree=828375040, allocatorClassName=org.apache.tez.runtime.library.resources.WeightedScalingMemoryDistributor
2018-12-27 13:01:49,526 [INFO] [TezChild] |task.TezTaskRunner|: Initializing task, taskAttemptId=attempt_1545806970486_0026_1_00_000049_1
2018-12-27 13:01:49,534 [INFO] [TaskHeartbeatThread] |task.TaskReporter|: Routing events from heartbeat response to task, currentTaskAttemptId=attempt_1545806970486_0026_1_00_000049_1, eventCount=1 fromEventId=0 nextFromEventId=0
2018-12-27 13:01:49,585 [INFO] [TezChild] |log.PerfLogger|:
2018-12-27 13:01:49,593 [INFO] [TezChild] |Configuration.deprecation|: mapred.committer.job.setup.cleanup.needed is deprecated. Instead, use mapreduce.job.committer.setup.cleanup.needed
2018-12-27 13:01:49,594 [INFO] [TezChild] |Configuration.deprecation|: mapred.input.dir.recursive is deprecated. Instead, use mapreduce.input.fileinputformat.input.dir.recursive
2018-12-27 13:01:49,644 [INFO] [TezChild] |Configuration.deprecation|: mapred.task.id is deprecated. Instead, use mapreduce.task.attempt.id
2018-12-27 13:01:49,644 [INFO] [TezChild] |Configuration.deprecation|: mapred.task.partition is deprecated. Instead, use mapreduce.task.partition
2018-12-27 13:01:49,644 [INFO] [TezChild] |log.PerfLogger|:
2018-12-27 13:01:49,644 [INFO] [TezChild] |runtime.LogicalIOProcessorRuntimeTask|: Initialized processor
2018-12-27 13:01:49,644 [INFO] [TezChild] |runtime.LogicalIOProcessorRuntimeTask|: Waiting for 2 initializers to finish
2018-12-27 13:01:49,661 [INFO] [TezChild] |runtime.LogicalIOProcessorRuntimeTask|: Waiting for 1 initializers to finish
2018-12-27 13:01:49,723 [INFO] [I/O Setup 0 Initialize: {tb_udf}] |counters.Limits|: Counter limits initialized with parameters: GROUP_NAME_MAX=256, MAX_GROUPS=3000, COUNTER_NAME_MAX=64, MAX_COUNTERS=10000
2018-12-27 13:01:49,731 [INFO] [I/O Setup 0 Initialize: {tb_udf}] |input.MRInput|: tb_udf using newmapreduce API=false, split via event=true, numPhysicalInputs=1
2018-12-27 13:01:49,731 [INFO] [I/O Setup 0 Initialize: {tb_udf}] |input.MRInputLegacy|: tb_udf MRInputLegacy deferring initialization
2018-12-27 13:01:49,731 [INFO] [TezChild] |runtime.LogicalIOProcessorRuntimeTask|: All initializers finished
2018-12-27 13:01:49,735 [INFO] [TezChild] |resources.MemoryDistributor|: InitialRequests=[tb_udf:INPUT:0:org.apache.tez.mapreduce.input.MRInputLegacy], [Reducer 2:OUTPUT:283115520:org.apache.tez.runtime.library.output.OrderedPartitionedKVOutput]
2018-12-27 13:01:49,742 [INFO] [TezChild] |resources.WeightedScalingMemoryDistributor|: ScaleRatiosUsed=[PARTITIONED_UNSORTED_OUTPUT:1][UNSORTED_OUTPUT:1][UNSORTED_INPUT:1][SORTED_OUTPUT:12][SORTED_MERGED_INPUT:12][PROCESSOR:1][OTHER:1]
2018-12-27 13:01:49,745 [INFO] [TezChild] |resources.WeightedScalingMemoryDistributor|: InitialReservationFraction=0.3, AdditionalReservationFractionForIOs=0.03, finalReserveFractionUsed=0.32999999999999996
2018-12-27 13:01:49,745 [INFO] [TezChild] |resources.WeightedScalingMemoryDistributor|: Scaling Requests. NumRequests: 2, numScaledRequests: 13, TotalRequested: 283115520, TotalRequestedScaled: 2.613374030769231E8, TotalJVMHeap: 828375040, TotalAvailable: 555011276, TotalRequested/TotalJVMHeap:0.34
2018-12-27 13:01:49,746 [INFO] [TezChild] |resources.MemoryDistributor|: Allocations=[tb_udf:org.apache.tez.mapreduce.input.MRInputLegacy:INPUT:0:0], [Reducer 2:org.apache.tez.runtime.library.output.OrderedPartitionedKVOutput:OUTPUT:283115520:283115520]
2018-12-27 13:01:49,746 [INFO] [TezChild] |runtime.LogicalIOProcessorRuntimeTask|: Starting Inputs/Outputs
2018-12-27 13:01:49,746 [INFO] [I/O Setup 1 Start: {tb_udf}] |runtime.LogicalIOProcessorRuntimeTask|: Started Input with src edge: tb_udf
2018-12-27 13:01:49,746 [INFO] [TezChild] |runtime.LogicalIOProcessorRuntimeTask|: Input: tb_udf being auto started by the framework. Subsequent instances will not be auto-started
2018-12-27 13:01:49,747 [INFO] [TezChild] |runtime.LogicalIOProcessorRuntimeTask|: Num IOs determined for AutoStart: 1
2018-12-27 13:01:49,747 [INFO] [TezChild] |runtime.LogicalIOProcessorRuntimeTask|: Waiting for 1 IOs to start
2018-12-27 13:01:49,747 [INFO] [TezChild] |runtime.LogicalIOProcessorRuntimeTask|: AutoStartComplete
2018-12-27 13:01:49,749 [INFO] [TezChild] |task.TezTaskRunner|: Running task, taskAttemptId=attempt_1545806970486_0026_1_00_000049_1
2018-12-27 13:01:49,749 [INFO] [TezChild] |log.PerfLogger|:
2018-12-27 13:01:49,749 [INFO] [TezChild] |tez.TezProcessor|: Running task: attempt_1545806970486_0026_1_00_000049_1_10001
2018-12-27 13:01:49,940 [INFO] [TezChild] |exec.Utilities|: PLAN PATH = hdfs://hortonwork0.ucak:8020/tmp/hive/hdfs/81ad51e1-49c6-476a-ae4a-4404156329a7/hive_2018-12-27_13-01-34_331_3965675722525534696-1/7a5f4a4a-9334-4c07-88f0-0385fbd5299d/map.xml
2018-12-27 13:01:49,940 [INFO] [TezChild] |exec.Utilities|: ***************non-local mode***************
2018-12-27 13:01:49,940 [INFO] [TezChild] |exec.Utilities|: local path = hdfs://hortonwork0.ucak:8020/tmp/hive/hdfs/81ad51e1-49c6-476a-ae4a-4404156329a7/hive_2018-12-27_13-01-34_331_3965675722525534696-1/7a5f4a4a-9334-4c07-88f0-0385fbd5299d/map.xml
2018-12-27 13:01:49,942 [INFO] [TezChild] |log.PerfLogger|:
2018-12-27 13:01:49,942 [INFO] [TezChild] |exec.Utilities|: Deserializing MapWork via kryo
2018-12-27 13:01:50,129 [ERROR] [TezChild] |exec.Utilities|: Failed to load plan: hdfs://hortonwork0.ucak:8020/tmp/hive/hdfs/81ad51e1-49c6-476a-ae4a-4404156329a7/hive_2018-12-27_13-01-34_331_3965675722525534696-1/7a5f4a4a-9334-4c07-88f0-0385fbd5299d/map.xml: org.apache.hive.com.esotericsoftware.kryo.KryoException: Encountered unregistered class ID: 22
Serialization trace:
outputFileFormatClass (org.apache.hadoop.hive.ql.plan.PartitionDesc)
aliasToPartnInfo (org.apache.hadoop.hive.ql.plan.MapWork)
org.apache.hive.com.esotericsoftware.kryo.KryoException: Encountered unregistered class ID: 22
Serialization trace:
outputFileFormatClass (org.apache.hadoop.hive.ql.plan.PartitionDesc)
aliasToPartnInfo (org.apache.hadoop.hive.ql.plan.MapWork)
at org.apache.hive.com.esotericsoftware.kryo.util.DefaultClassResolver.readClass(DefaultClassResolver.java:119)
at org.apache.hive.com.esotericsoftware.kryo.Kryo.readClass(Kryo.java:656)
at org.apache.hive.com.esotericsoftware.kryo.serializers.DefaultSerializers$ClassSerializer.read(DefaultSerializers.java:238)
at org.apache.hive.com.esotericsoftware.kryo.serializers.DefaultSerializers$ClassSerializer.read(DefaultSerializers.java:226)
at org.apache.hive.com.esotericsoftware.kryo.Kryo.readObjectOrNull(Kryo.java:745)
at org.apache.hive.com.esotericsoftware.kryo.serializers.ObjectField.read(ObjectField.java:113)
at org.apache.hive.com.esotericsoftware.kryo.serializers.FieldSerializer.read(FieldSerializer.java:507)
at org.apache.hive.com.esotericsoftware.kryo.Kryo.readClassAndObject(Kryo.java:776)
at org.apache.hive.com.esotericsoftware.kryo.serializers.MapSerializer.read(MapSerializer.java:139)
at org.apache.hive.com.esotericsoftware.kryo.serializers.MapSerializer.read(MapSerializer.java:17)
at org.apache.hive.com.esotericsoftware.kryo.Kryo.readObject(Kryo.java:694)
at org.apache.hive.com.esotericsoftware.kryo.serializers.ObjectField.read(ObjectField.java:106)
at org.apache.hive.com.esotericsoftware.kryo.serializers.FieldSerializer.read(FieldSerializer.java:507)
at org.apache.hive.com.esotericsoftware.kryo.Kryo.readObject(Kryo.java:672)
at org.apache.hadoop.hive.ql.exec.Utilities.deserializeObjectByKryo(Utilities.java:1081)
at org.apache.hadoop.hive.ql.exec.Utilities.deserializePlan(Utilities.java:972)
at org.apache.hadoop.hive.ql.exec.Utilities.deserializePlan(Utilities.java:986)
at org.apache.hadoop.hive.ql.exec.Utilities.getBaseWork(Utilities.java:422)
at org.apache.hadoop.hive.ql.exec.Utilities.getMapWork(Utilities.java:301)
at org.apache.hadoop.hive.ql.exec.tez.MapRecordProcessor$1.call(MapRecordProcessor.java:108)
at org.apache.hadoop.hive.ql.exec.tez.ObjectCache.retrieve(ObjectCache.java:75)
at org.apache.hadoop.hive.ql.exec.tez.MapRecordProcessor.(MapRecordProcessor.java:105)
at org.apache.hadoop.hive.ql.exec.tez.TezProcessor.run(TezProcessor.java:132)
at org.apache.tez.runtime.LogicalIOProcessorRuntimeTask.run(LogicalIOProcessorRuntimeTask.java:347)
at org.apache.tez.runtime.task.TezTaskRunner$TaskRunnerCallable$1.run(TezTaskRunner.java:194)
at org.apache.tez.runtime.task.TezTaskRunner$TaskRunnerCallable$1.run(TezTaskRunner.java:185)
at java.security.AccessController.doPrivileged(Native Method)
at javax.security.auth.Subject.doAs(Subject.java:422)
at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1698)
at org.apache.tez.runtime.task.TezTaskRunner$TaskRunnerCallable.callInternal(TezTaskRunner.java:185)
at org.apache.tez.runtime.task.TezTaskRunner$TaskRunnerCallable.callInternal(TezTaskRunner.java:181)
at org.apache.tez.common.CallableWithNdc.call(CallableWithNdc.java:36)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
2018-12-27 13:01:50,176 [INFO] [TezChild] |task.TezTaskRunner|: Encounted an error while executing task: attempt_1545806970486_0026_1_00_000049_1
org.apache.hadoop.hive.ql.metadata.HiveException: java.lang.RuntimeException: Failed to load plan: hdfs://hortonwork0.ucak:8020/tmp/hive/hdfs/81ad51e1-49c6-476a-ae4a-4404156329a7/hive_2018-12-27_13-01-34_331_3965675722525534696-1/7a5f4a4a-9334-4c07-88f0-0385fbd5299d/map.xml: org.apache.hive.com.esotericsoftware.kryo.KryoException: Encountered unregistered class ID: 22
Serialization trace:
outputFileFormatClass (org.apache.hadoop.hive.ql.plan.PartitionDesc)
aliasToPartnInfo (org.apache.hadoop.hive.ql.plan.MapWork)
at org.apache.hadoop.hive.ql.exec.tez.ObjectCache.retrieve(ObjectCache.java:82)
at org.apache.hadoop.hive.ql.exec.tez.MapRecordProcessor.(MapRecordProcessor.java:105)
at org.apache.hadoop.hive.ql.exec.tez.TezProcessor.run(TezProcessor.java:132)
at org.apache.tez.runtime.LogicalIOProcessorRuntimeTask.run(LogicalIOProcessorRuntimeTask.java:347)
at org.apache.tez.runtime.task.TezTaskRunner$TaskRunnerCallable$1.run(TezTaskRunner.java:194)
at org.apache.tez.runtime.task.TezTaskRunner$TaskRunnerCallable$1.run(TezTaskRunner.java:185)
at java.security.AccessController.doPrivileged(Native Method)
at javax.security.auth.Subject.doAs(Subject.java:422)
at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1698)
at org.apache.tez.runtime.task.TezTaskRunner$TaskRunnerCallable.callInternal(TezTaskRunner.java:185)
at org.apache.tez.runtime.task.TezTaskRunner$TaskRunnerCallable.callInternal(TezTaskRunner.java:181)
at org.apache.tez.common.CallableWithNdc.call(CallableWithNdc.java:36)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.RuntimeException: Failed to load plan: hdfs://hortonwork0.ucak:8020/tmp/hive/hdfs/81ad51e1-49c6-476a-ae4a-4404156329a7/hive_2018-12-27_13-01-34_331_3965675722525534696-1/7a5f4a4a-9334-4c07-88f0-0385fbd5299d/map.xml: org.apache.hive.com.esotericsoftware.kryo.KryoException: Encountered unregistered class ID: 22
Serialization trace:
outputFileFormatClass (org.apache.hadoop.hive.ql.plan.PartitionDesc)
aliasToPartnInfo (org.apache.hadoop.hive.ql.plan.MapWork)
at org.apache.hadoop.hive.ql.exec.Utilities.getBaseWork(Utilities.java:462)
at org.apache.hadoop.hive.ql.exec.Utilities.getMapWork(Utilities.java:301)
at org.apache.hadoop.hive.ql.exec.tez.MapRecordProcessor$1.call(MapRecordProcessor.java:108)
at org.apache.hadoop.hive.ql.exec.tez.ObjectCache.retrieve(ObjectCache.java:75)
... 15 more
Caused by: org.apache.hive.com.esotericsoftware.kryo.KryoException: Encountered unregistered class ID: 22
Serialization trace:
outputFileFormatClass (org.apache.hadoop.hive.ql.plan.PartitionDesc)
aliasToPartnInfo (org.apache.hadoop.hive.ql.plan.MapWork)
at org.apache.hive.com.esotericsoftware.kryo.util.DefaultClassResolver.readClass(DefaultClassResolver.java:119)
at org.apache.hive.com.esotericsoftware.kryo.Kryo.readClass(Kryo.java:656)
at org.apache.hive.com.esotericsoftware.kryo.serializers.DefaultSerializers$ClassSerializer.read(DefaultSerializers.java:238)
at org.apache.hive.com.esotericsoftware.kryo.serializers.DefaultSerializers$ClassSerializer.read(DefaultSerializers.java:226)
at org.apache.hive.com.esotericsoftware.kryo.Kryo.readObjectOrNull(Kryo.java:745)
at org.apache.hive.com.esotericsoftware.kryo.serializers.ObjectField.read(ObjectField.java:113)
at org.apache.hive.com.esotericsoftware.kryo.serializers.FieldSerializer.read(FieldSerializer.java:507)
at org.apache.hive.com.esotericsoftware.kryo.Kryo.readClassAndObject(Kryo.java:776)
at org.apache.hive.com.esotericsoftware.kryo.serializers.MapSerializer.read(MapSerializer.java:139)
at org.apache.hive.com.esotericsoftware.kryo.serializers.MapSerializer.read(MapSerializer.java:17)
at org.apache.hive.com.esotericsoftware.kryo.Kryo.readObject(Kryo.java:694)
at org.apache.hive.com.esotericsoftware.kryo.serializers.ObjectField.read(ObjectField.java:106)
at org.apache.hive.com.esotericsoftware.kryo.serializers.FieldSerializer.read(FieldSerializer.java:507)
at org.apache.hive.com.esotericsoftware.kryo.Kryo.readObject(Kryo.java:672)
at org.apache.hadoop.hive.ql.exec.Utilities.deserializeObjectByKryo(Utilities.java:1081)
at org.apache.hadoop.hive.ql.exec.Utilities.deserializePlan(Utilities.java:972)
at org.apache.hadoop.hive.ql.exec.Utilities.deserializePlan(Utilities.java:986)
at org.apache.hadoop.hive.ql.exec.Utilities.getBaseWork(Utilities.java:422)
... 18 more
2018-12-27 13:01:50,180 [INFO] [TezChild] |runtime.LogicalIOProcessorRuntimeTask|: Final Counters for attempt_1545806970486_0026_1_00_000049_1: Counters: 2 [[org.apache.tez.common.counters.TaskCounter INPUT_RECORDS_PROCESSED=0][TaskCounter_Map_1_INPUT_tb_udf INPUT_RECORDS_PROCESSED=0]]
2018-12-27 13:01:50,180 [INFO] [TezChild] |runtime.LogicalIOProcessorRuntimeTask|: Joining on EventRouter
2018-12-27 13:01:50,180 [INFO] [TezChild] |runtime.LogicalIOProcessorRuntimeTask|: Closed processor for vertex=Map 1, index=0
2018-12-27 13:01:50,180 [WARN] [TezChild] |runtime.LogicalIOProcessorRuntimeTask|: Ignoring exception when closing input tb_udf(cleanup). Exception class=java.lang.NullPointerException, message=null
2018-12-27 13:01:50,180 [INFO] [TezChild] |runtime.LogicalIOProcessorRuntimeTask|: Closed input for vertex=Map 1, sourceVertex=tb_udf
2018-12-27 13:01:50,180 [WARN] [TezChild] |output.OrderedPartitionedKVOutput|: Reducer 2: Attempting to close output Reducer 2 of type OrderedPartitionedKVOutput before it was started. Generating empty events
2018-12-27 13:01:50,188 [INFO] [TezChild] |shuffle.ShuffleUtils|: Setting all 418 partitions as empty for non-started output
2018-12-27 13:01:50,190 [INFO] [TezChild] |runtime.LogicalIOProcessorRuntimeTask|: Closed input for vertex=Map 1, sourceVertex=Reducer 2
2018-12-27 13:01:50,192 [ERROR] [main] |task.TezTaskRunner|: Exception of type Error.
java.lang.NoSuchMethodError: org.apache.hadoop.fs.FileSystem.getGlobalStorageStatistics()Lorg/apache/hadoop/fs/GlobalStorageStatistics;
at org.apache.tez.runtime.metrics.TaskCounterUpdater.updateCounters(TaskCounterUpdater.java:111)
at org.apache.tez.runtime.RuntimeTask.setFrameworkCounters(RuntimeTask.java:161)
at org.apache.tez.runtime.task.TezTaskRunner.sendFailure(TezTaskRunner.java:279)
at org.apache.tez.runtime.task.TezTaskRunner.access$500(TezTaskRunner.java:55)
at org.apache.tez.runtime.task.TezTaskRunner$TaskRunnerCallable$1.run(TezTaskRunner.java:245)
at org.apache.tez.runtime.task.TezTaskRunner$TaskRunnerCallable$1.run(TezTaskRunner.java:185)
at java.security.AccessController.doPrivileged(Native Method)
at javax.security.auth.Subject.doAs(Subject.java:422)
at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1698)
at org.apache.tez.runtime.task.TezTaskRunner$TaskRunnerCallable.callInternal(TezTaskRunner.java:185)
at org.apache.tez.runtime.task.TezTaskRunner$TaskRunnerCallable.callInternal(TezTaskRunner.java:181)
at org.apache.tez.common.CallableWithNdc.call(CallableWithNdc.java:36)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
2018-12-27 13:01:50,192 [WARN] [main] |task.TezTaskRunner|: Ignoring fatal error since another error has already been reported
java.lang.NoSuchMethodError: org.apache.hadoop.fs.FileSystem.getGlobalStorageStatistics()Lorg/apache/hadoop/fs/GlobalStorageStatistics;
at org.apache.tez.runtime.metrics.TaskCounterUpdater.updateCounters(TaskCounterUpdater.java:111)
at org.apache.tez.runtime.RuntimeTask.setFrameworkCounters(RuntimeTask.java:161)
at org.apache.tez.runtime.task.TezTaskRunner.sendFailure(TezTaskRunner.java:279)
at org.apache.tez.runtime.task.TezTaskRunner.access$500(TezTaskRunner.java:55)
at org.apache.tez.runtime.task.TezTaskRunner$TaskRunnerCallable$1.run(TezTaskRunner.java:245)
at org.apache.tez.runtime.task.TezTaskRunner$TaskRunnerCallable$1.run(TezTaskRunner.java:185)
at java.security.AccessController.doPrivileged(Native Method)
at javax.security.auth.Subject.doAs(Subject.java:422)
at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1698)
at org.apache.tez.runtime.task.TezTaskRunner$TaskRunnerCallable.callInternal(TezTaskRunner.java:185)
at org.apache.tez.runtime.task.TezTaskRunner$TaskRunnerCallable.callInternal(TezTaskRunner.java:181)
at org.apache.tez.common.CallableWithNdc.call(CallableWithNdc.java:36)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
2018-12-27 13:01:50,192 [INFO] [main] |task.TezChild|: Shutdown invoked for container container_e13_1545806970486_0026_01_000127
2018-12-27 13:01:50,193 [INFO] [main] |task.TezChild|: Shutting down container container_e13_1545806970486_0026_01_000127
End of LogType:syslog_attempt_1545806970486_0026_1_00_000049_1
****************************************************************************************************************
Container: container_e13_1545806970486_0026_01_000127 on hortonwork9.ucak_45454
LogAggregationType: AGGREGATED
==============================================================================