You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@hudi.apache.org by GitBox <gi...@apache.org> on 2019/07/30 11:25:54 UTC
[GitHub] [incubator-hudi] arw357 edited a comment on issue #590: Failed to
APPEND_FILE
/HUDI_MOR/2019/03/01/.abca886a-e213-4199-b571-475919d34fe5_20190301123358.log.1
for DFSClient_NONMAPREDUCE_-263902482_1 on 172.29.0.10 because lease
recovery is in progress
arw357 edited a comment on issue #590: Failed to APPEND_FILE /HUDI_MOR/2019/03/01/.abca886a-e213-4199-b571-475919d34fe5_20190301123358.log.1 for DFSClient_NONMAPREDUCE_-263902482_1 on 172.29.0.10 because lease recovery is in progress
URL: https://github.com/apache/incubator-hudi/issues/590#issuecomment-516377266
I found something alike . I have only one datanode - it happens when the archive log is being appended. I can reproduce it.
I see that this build failed as well : https://api.travis-ci.org/v3/job/547004744/log.txt
```:08:04.613 [DataLakeSystem-akka.actor.default-dispatcher-5] INFO com.uber.hoodie.common.table.log.HoodieLogFormat$WriterBuilder - Building HoodieLogFormat Writer
11:08:04.613 [DataLakeSystem-akka.actor.default-dispatcher-5] INFO com.uber.hoodie.common.table.log.HoodieLogFormat$WriterBuilder - Computing the next log version for commits in hdfs://namenode:8020/data/lake/3ecfc2fc-8f48-46e1-8e0c-be8fc13eb596/converted/.hoodie/archived
11:08:04.621 [DataLakeSystem-akka.actor.default-dispatcher-5] INFO com.uber.hoodie.common.table.log.HoodieLogFormat$WriterBuilder - Computed the next log version for commits in hdfs://namenode:8020/data/lake/3ecfc2fc-8f48-46e1-8e0c-be8fc13eb596/converted/.hoodie/archived as 1
11:08:04.621 [DataLakeSystem-akka.actor.default-dispatcher-5] INFO com.uber.hoodie.common.table.log.HoodieLogFormat$WriterBuilder - HoodieLogFile on path hdfs://namenode:8020/data/lake/3ecfc2fc-8f48-46e1-8e0c-be8fc13eb596/converted/.hoodie/archived/.commits_.archive.1
11:08:04.630 [DataLakeSystem-akka.actor.default-dispatcher-5] INFO com.uber.hoodie.common.table.log.HoodieLogFormatWriter - HoodieLogFile {hdfs://namenode:8020/data/lake/3ecfc2fc-8f48-46e1-8e0c-be8fc13eb596/converted/.hoodie/archived/.commits_.archive.1} exists. Appending to existing file
11:08:04.652 [DataLakeSystem-akka.actor.default-dispatcher-5] INFO com.uber.hoodie.io.HoodieCommitArchiveLog - Archiving instants [[20190730104047__clean__COMPLETED], [20190730104512__clean__COMPLETED], [20190730104605__clean__COMPLETED], [20190730104628__clean__COMPLETED], [20190730104651__clean__COMPLETED], [20190730104721__clean__COMPLETED], [20190730104758__clean__COMPLETED], [20190730104821__clean__COMPLETED], [20190730104843__clean__COMPLETED], [20190730104905__clean__COMPLETED], [20190730104926__clean__COMPLETED]]
11:08:04.653 [DataLakeSystem-akka.actor.default-dispatcher-5] INFO com.uber.hoodie.io.HoodieCommitArchiveLog - Wrapper schema {"type":"record","name":"HoodieArchivedMetaEntry","namespace":"com.uber.hoodie.avro.model","fields":[{"name":"hoodieCommitMetadata","type":["null",{"type":"record","name":"HoodieCommitMetadata","fields":[{"name":"partitionToWriteStats","type":["null",{"type":"map","values":{"type":"array","items":{"type":"record","name":"HoodieWriteStat","fields":[{"name":"fileId","type":["null",{"type":"string","avro.java.string":"String"}],"default":null},{"name":"path","type":["null",{"type":"string","avro.java.string":"String"}],"default":null},{"name":"prevCommit","type":["null",{"type":"string","avro.java.string":"String"}],"default":null},{"name":"numWrites","type":["null","long"],"default":null},{"name":"numDeletes","type":["null","long"],"default":null},{"name":"numUpdateWrites","type":["null","long"],"default":null},{"name":"totalWriteBytes","type":["null","long"],"default":null},{"name":"totalWriteErrors","type":["null","long"],"default":null},{"name":"partitionPath","type":["null",{"type":"string","avro.java.string":"String"}],"default":null},{"name":"totalLogRecords","type":["null","long"],"default":null},{"name":"totalLogFiles","type":["null","long"],"default":null},{"name":"totalUpdatedRecordsCompacted","type":["null","long"],"default":null},{"name":"numInserts","type":["null","long"],"default":null},{"name":"totalLogBlocks","type":["null","long"],"default":null},{"name":"totalCorruptLogBlock","type":["null","long"],"default":null},{"name":"totalRollbackBlocks","type":["null","long"],"default":null}]}},"avro.java.string":"String"}]},{"name":"extraMetadata","type":["null",{"type":"map","values":{"type":"string","avro.java.string":"String"},"avro.java.string":"String"}]}]}],"default":"null"},{"name":"hoodieCleanMetadata","type":["null",{"type":"record","name":"HoodieCleanMetadata","fields":[{"name":"startCleanTime","type":{"type":"string","avro.java.string":"String"}},{"name":"timeTakenInMillis","type":"long"},{"name":"totalFilesDeleted","type":"int"},{"name":"earliestCommitToRetain","type":{"type":"string","avro.java.string":"String"}},{"name":"partitionMetadata","type":{"type":"map","values":{"type":"record","name":"HoodieCleanPartitionMetadata","fields":[{"name":"partitionPath","type":{"type":"string","avro.java.string":"String"}},{"name":"policy","type":{"type":"string","avro.java.string":"String"}},{"name":"deletePathPatterns","type":{"type":"array","items":{"type":"string","avro.java.string":"String"}}},{"name":"successDeleteFiles","type":{"type":"array","items":{"type":"string","avro.java.string":"String"}}},{"name":"failedDeleteFiles","type":{"type":"array","items":{"type":"string","avro.java.string":"String"}}}]},"avro.java.string":"String"}}]}],"default":"null"},{"name":"hoodieCompactionMetadata","type":["null",{"type":"record","name":"HoodieCompactionMetadata","fields":[{"name":"partitionToCompactionWriteStats","type":["null",{"type":"map","values":{"type":"array","items":{"type":"record","name":"HoodieCompactionWriteStat","fields":[{"name":"partitionPath","type":["null",{"type":"string","avro.java.string":"String"}]},{"name":"totalLogRecords","type":["null","long"]},{"name":"totalLogFiles","type":["null","long"]},{"name":"totalUpdatedRecordsCompacted","type":["null","long"]},{"name":"hoodieWriteStat","type":["null","HoodieWriteStat"]}]}},"avro.java.string":"String"}]}]}],"default":"null"},{"name":"hoodieRollbackMetadata","type":["null",{"type":"record","name":"HoodieRollbackMetadata","fields":[{"name":"startRollbackTime","type":{"type":"string","avro.java.string":"String"}},{"name":"timeTakenInMillis","type":"long"},{"name":"totalFilesDeleted","type":"int"},{"name":"commitsRollback","type":{"type":"array","items":{"type":"string","avro.java.string":"String"}}},{"name":"partitionMetadata","type":{"type":"map","values":{"type":"record","name":"HoodieRollbackPartitionMetadata","fields":[{"name":"partitionPath","type":{"type":"string","avro.java.string":"String"}},{"name":"successDeleteFiles","type":{"type":"array","items":{"type":"string","avro.java.string":"String"}}},{"name":"failedDeleteFiles","type":{"type":"array","items":{"type":"string","avro.java.string":"String"}}}]},"avro.java.string":"String"}}]}],"default":"null"},{"name":"hoodieSavePointMetadata","type":["null",{"type":"record","name":"HoodieSavepointMetadata","fields":[{"name":"savepointedBy","type":{"type":"string","avro.java.string":"String"}},{"name":"savepointedAt","type":"long"},{"name":"comments","type":{"type":"string","avro.java.string":"String"}},{"name":"partitionMetadata","type":{"type":"map","values":{"type":"record","name":"HoodieSavepointPartitionMetadata","fields":[{"name":"partitionPath","type":{"type":"string","avro.java.string":"String"}},{"name":"savepointDataFile","type":{"type":"array","items":{"type":"string","avro.java.string":"String"}}}]},"avro.java.string":"String"}}]}],"default":"null"},{"name":"commitTime","type":["null",{"type":"string","avro.java.string":"String"}]},{"name":"actionType","type":["null",{"type":"string","avro.java.string":"String"}]}]}
11:08:04.706 [DataLakeSystem-akka.actor.default-dispatcher-5] ERROR
com.uber.hoodie.exception.HoodieException: Unable to close HoodieLogFormat writer
at com.uber.hoodie.io.HoodieCommitArchiveLog.close(HoodieCommitArchiveLog.java:103)
at com.uber.hoodie.io.HoodieCommitArchiveLog.archiveIfRequired(HoodieCommitArchiveLog.java:124)
at com.uber.hoodie.HoodieWriteClient.commit(HoodieWriteClient.java:542)
at com.uber.hoodie.HoodieWriteClient.commit(HoodieWriteClient.java:489)
at com.uber.hoodie.HoodieWriteClient.commit(HoodieWriteClient.java:480)
at com.uber.hoodie.HoodieSparkSqlWriter$.write(HoodieSparkSqlWriter.scala:155)
at com.uber.hoodie.DefaultSource.createRelation(DefaultSource.scala:91)
at org.apache.spark.sql.execution.datasources.SaveIntoDataSourceCommand.run(SaveIntoDataSourceCommand.scala:45)
at org.apache.spark.sql.execution.command.ExecutedCommandExec.sideEffectResult$lzycompute(commands.scala:70)
at org.apache.spark.sql.execution.command.ExecutedCommandExec.sideEffectResult(commands.scala:68)
at org.apache.spark.sql.execution.command.ExecutedCommandExec.doExecute(commands.scala:86)
at org.apache.spark.sql.execution.SparkPlan$$anonfun$execute$1.apply(SparkPlan.scala:131)
at org.apache.spark.sql.execution.SparkPlan$$anonfun$execute$1.apply(SparkPlan.scala:127)
at org.apache.spark.sql.execution.SparkPlan$$anonfun$executeQuery$1.apply(SparkPlan.scala:155)
at org.apache.spark.rdd.RDDOperationScope$.withScope(RDDOperationScope.scala:151)
at org.apache.spark.sql.execution.SparkPlan.executeQuery(SparkPlan.scala:152)
at org.apache.spark.sql.execution.SparkPlan.execute(SparkPlan.scala:127)
at org.apache.spark.sql.execution.QueryExecution.toRdd$lzycompute(QueryExecution.scala:80)
at org.apache.spark.sql.execution.QueryExecution.toRdd(QueryExecution.scala:80)
at org.apache.spark.sql.DataFrameWriter$$anonfun$runCommand$1.apply(DataFrameWriter.scala:654)
at org.apache.spark.sql.DataFrameWriter$$anonfun$runCommand$1.apply(DataFrameWriter.scala:654)
at org.apache.spark.sql.execution.SQLExecution$.withNewExecutionId(SQLExecution.scala:77)
at org.apache.spark.sql.DataFrameWriter.runCommand(DataFrameWriter.scala:654)
at org.apache.spark.sql.DataFrameWriter.saveToV1Source(DataFrameWriter.scala:273)
at org.apache.spark.sql.DataFrameWriter.save(DataFrameWriter.scala:267)
at org.apache.spark.sql.DataFrameWriter.save(DataFrameWriter.scala:225)
....
at akka.stream.impl.fusing.Map$$anon$10.onPush(Ops.scala:52)
at akka.stream.impl.fusing.GraphInterpreter.processPush(GraphInterpreter.scala:519)
at akka.stream.impl.fusing.GraphInterpreter.execute(GraphInterpreter.scala:411)
at akka.stream.impl.fusing.GraphInterpreterShell.runBatch(ActorGraphInterpreter.scala:588)
at akka.stream.impl.fusing.GraphInterpreterShell$AsyncInput.execute(ActorGraphInterpreter.scala:472)
at akka.stream.impl.fusing.GraphInterpreterShell.processEvent(ActorGraphInterpreter.scala:563)
at akka.stream.impl.fusing.ActorGraphInterpreter.akka$stream$impl$fusing$ActorGraphInterpreter$$processEvent(ActorGraphInterpreter.scala:745)
at akka.stream.impl.fusing.ActorGraphInterpreter$$anonfun$receive$1.applyOrElse(ActorGraphInterpreter.scala:760)
at akka.actor.Actor$class.aroundReceive(Actor.scala:517)
at akka.stream.impl.fusing.ActorGraphInterpreter.aroundReceive(ActorGraphInterpreter.scala:670)
at akka.actor.ActorCell.receiveMessage(ActorCell.scala:592)
at akka.actor.ActorCell.invoke(ActorCell.scala:561)
at akka.dispatch.Mailbox.processMailbox(Mailbox.scala:258)
at akka.dispatch.Mailbox.run(Mailbox.scala:225)
at akka.dispatch.Mailbox.exec(Mailbox.scala:235)
at akka.dispatch.forkjoin.ForkJoinTask.doExec(ForkJoinTask.java:260)
at akka.dispatch.forkjoin.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:1339)
at akka.dispatch.forkjoin.ForkJoinPool.runWorker(ForkJoinPool.java:1979)
at akka.dispatch.forkjoin.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:107)
Caused by: java.io.IOException: Failed to replace a bad datanode on the existing pipeline due to no more good datanodes being available to try. (Nodes: current=[DatanodeInfoWithStorage[172.21.0.14:9866,DS-3b46b080-0c8e-4d74-a090-734caebd4a16,DISK]], original=[DatanodeInfoWithStorage[172.21.0.14:9866,DS-3b46b080-0c8e-4d74-a090-734caebd4a16,DISK]]). The current failed datanode replacement policy is DEFAULT, and a client may configure this via 'dfs.client.block.write.replace-datanode-on-failure.policy' in its configuration.
at org.apache.hadoop.hdfs.DFSOutputStream$DataStreamer.findNewDatanode(DFSOutputStream.java:1044)
at org.apache.hadoop.hdfs.DFSOutputStream$DataStreamer.addDatanode2ExistingPipeline(DFSOutputStream.java:1107)
at org.apache.hadoop.hdfs.DFSOutputStream$DataStreamer.setupPipelineForAppendOrRecovery(DFSOutputStream.java:1276)
at org.apache.hadoop.hdfs.DFSOutputStream$DataStreamer.run(DFSOutputStream.java:560)
```
Any clue ?
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
With regards,
Apache Git Services