问题现象: 使用 flink StreamingFileSink 写 hdfs 时,
有时出现 StreamingFileSink fails due to truncating HDFS file failure 异常
https://issues.apache.org/jira/browse/FLINK-18592
从 flink 1.10.1 以来一致没有被修复, 当前标记到 1.15.0 版本修复
在 github 上有 2 个 PR, 在一定程度上能解决问题, 但是还是要结合 hdfs 的配置才能更好的解决
GitHub Pull Request #13377
GitHub Pull Request #16927
系统环境:
- hadoop 3.1.1, HA 部署, 2 个 namnod, 8个 datanode, 文件副本数设置为 2
- yarn 3.1.1
- flink 1.12.2
- flink 采用 on yarn 方式部署
情景再现:
- flink job 简单的构建了从 kafka 中读取数据, 然后直接写入 hdfs, 按天和小时切分目录, 部分代码如下
private static final String DATE_FRM_DTB_DEFAULT = "yyyyMMdd/HH"; StreamingFileSink<String> hdfsSink = StreamingFileSink .forRowFormat(new Path(cfg.hdfsSink.hdfsPath), new SimpleStringEncoder<String>(UTF_8.name())) .withBucketAssigner(new DateTimeBucketAssigner<>(DATE_FRM_DTB_DEFAULT)) .withRollingPolicy( DefaultRollingPolicy.builder() .withRolloverInterval(TimeUnit.MINUTES.toMillis(6)) .withInactivityInterval(TimeUnit.MINUTES.toMillis(20)) .withMaxPartSize(512 * 1024 * 1024) .build() ) .withOutputFileConfig(new OutputFileConfig("p", STR_EMPTY)) .build(); - 某个 datanode 挂掉/重启/负载过高(datanode 上部署了 HBASE, scan 时导致 CPU 过高)时
- flink job 向 hdfs 写数据的 task 会每隔 100 秒左右 restar, 此任务所在的 yarn container 名没有发生变化, 也就是 jvm 进程一直在, 但是 task 线程一致重启
- 查看日志日志提示: StreamingFileSink fails due to truncating,
2022-02-20 15:34:33 java.io.IOException: Problem while truncating file: hdfs://xxx/warehouse/tablespace/external/hive/dwd.db/xxxx_ext/20220220/14/.p-0-2125.inprogress.9ed0a002-e996-4335-b8af-eefe09aa8580 at org.apache.flink.runtime.fs.hdfs.HadoopRecoverableFsDataOutputStream.safelyTruncateFile(HadoopRecoverableFsDataOutputStream.java:170) at org.apache.flink.runtime.fs.hdfs.HadoopRecoverableFsDataOutputStream.<init>(HadoopRecoverableFsDataOutputStream.java:88) at org.apache.flink.runtime.fs.hdfs.HadoopRecoverableWriter.recover(HadoopRecoverableWriter.java:86) at org.apache.flink.streaming.api.functions.sink.filesystem.OutputStreamBasedPartFileWriter$OutputStreamBasedBucketWriter.resumeInProgressFileFrom(OutputStreamBasedPartFileWriter.java:104) at org.apache.flink.streaming.api.functions.sink.filesystem.RowWiseBucketWriter.resumeInProgressFileFrom(RowWiseBucketWriter.java:34) at org.apache.flink.streaming.api.functions.sink.filesystem.Bucket.restoreInProgressFile(Bucket.java:141) at org.apache.flink.streaming.api.functions.sink.filesystem.Bucket.<init>(Bucket.java:126) at org.apache.flink.streaming.api.functions.sink.filesystem.Bucket.restore(Bucket.java:466) at org.apache.flink.streaming.api.functions.sink.filesystem.DefaultBucketFactoryImpl.restoreBucket(DefaultBucketFactoryImpl.java:67) at org.apache.flink.streaming.api.functions.sink.filesystem.Buckets.handleRestoredBucketState(Buckets.java:192) at org.apache.flink.streaming.api.functions.sink.filesystem.Buckets.initializeActiveBuckets(Buckets.java:179) at org.apache.flink.streaming.api.functions.sink.filesystem.Buckets.initializeState(Buckets.java:163) at org.apache.flink.streaming.api.functions.sink.filesystem.StreamingFileSinkHelper.<init>(StreamingFileSinkHelper.java:75) at org.apache.flink.streaming.api.functions.sink.filesystem.StreamingFileSink.initializeState(StreamingFileSink.java:472) at org.apache.flink.streaming.util.functions.StreamingFunctionUtils.tryRestoreFunction(StreamingFunctionUtils.java:189) at org.apache.flink.streaming.util.functions.StreamingFunctionUtils.restoreFunctionState(StreamingFunctionUtils.java:171) at org.apache.flink.streaming.api.operators.AbstractUdfStreamOperator.initializeState(AbstractUdfStreamOperator.java:96) at org.apache.flink.streaming.api.operators.StreamOperatorStateHandler.initializeOperatorState(StreamOperatorStateHandler.java:111) at org.apache.flink.streaming.api.operators.AbstractStreamOperator.initializeState(AbstractStreamOperator.java:290) at org.apache.flink.streaming.runtime.tasks.OperatorChain.initializeStateAndOpenOperators(OperatorChain.java:427) at org.apache.flink.streaming.runtime.tasks.StreamTask.lambda$beforeInvoke$2(StreamTask.java:543) at org.apache.flink.streaming.runtime.tasks.StreamTaskActionExecutor$SynchronizedStreamTaskActionExecutor.runThrowing(StreamTaskActionExecutor.java:93) at org.apache.flink.streaming.runtime.tasks.StreamTask.beforeInvoke(StreamTask.java:533) at org.apache.flink.streaming.runtime.tasks.StreamTask.invoke(StreamTask.java:573) at org.apache.flink.runtime.taskmanager.Task.doRun(Task.java:755) at org.apache.flink.runtime.taskmanager.Task.run(Task.java:570) at java.lang.Thread.run(Thread.java:748) Caused by: org.apache.hadoop.ipc.RemoteException(org.apache.hadoop.hdfs.protocol.AlreadyBeingCreatedException): Failed to TRUNCATE_FILE /warehouse/tablespace/external/hive/dwd.db/xxxx_ext/20220220/14/.p-0-2125.inprogress.9ed0a002-e996-4335-b8af-eefe09aa8580 for DFSClient_NONMAPREDUCE_620729750_1 on 172.20.37.11 because DFSClient_NONMAPREDUCE_620729750_1 is already the current lease holder. at org.apache.hadoop.hdfs.server.namenode.FSNamesystem.recoverLeaseInternal(FSNamesystem.java:2555) at org.apache.hadoop.hdfs.server.namenode.FSDirTruncateOp.truncate(FSDirTruncateOp.java:119) at org.apache.hadoop.hdfs.server.namenode.FSNamesystem.truncate(FSNamesystem.java:2117) at org.apache.hadoop.hdfs.server.namenode.NameNodeRpcServer.truncate(NameNodeRpcServer.java:1073) at org.apache.hadoop.hdfs.protocolPB.ClientNamenodeProtocolServerSideTranslatorPB.truncate(ClientNamenodeProtocolServerSideTranslatorPB.java:680) at org.apache.hadoop.hdfs.protocol.proto.ClientNamenodeProtocolProtos$ClientNamenodeProtocol$2.callBlockingMethod(ClientNamenodeProtocolProtos.java) at org.apache.hadoop.ipc.ProtobufRpcEngine$Server$ProtoBufRpcInvoker.call(ProtobufRpcEngine.java:524) at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:1025) at org.apache.hadoop.ipc.Server$RpcCall.run(Server.java:876) at org.apache.hadoop.ipc.Server$RpcCall.run(Server.java:822) 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:1730) at org.apache.hadoop.ipc.Server$Handler.run(Server.java:2682) at org.apache.hadoop.ipc.Client.getRpcResponse(Client.java:1498) at org.apache.hadoop.ipc.Client.call(Client.java:1444) at org.apache.hadoop.ipc.Client.call(Client.java:1354) at org.apache.hadoop.ipc.ProtobufRpcEngine$Invoker.invoke(ProtobufRpcEngine.java:228) at org.apache.hadoop.ipc.ProtobufRpcEngine$Invoker.invoke(ProtobufRpcEngine.java:116) at com.sun.proxy.$Proxy26.truncate(Unknown Source) at org.apache.hadoop.hdfs.protocolPB.ClientNamenodeProtocolTranslatorPB.truncate(ClientNamenodeProtocolTranslatorPB.java:379) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.apache.hadoop.io.retry.RetryInvocationHandler.invokeMethod(RetryInvocationHandler.java:422) at org.apache.hadoop.io.retry.RetryInvocationHandler$Call.invokeMethod(RetryInvocationHandler.java:165) at org.apache.hadoop.io.retry.RetryInvocationHandler$Call.invoke(RetryInvocationHandler.java:157) at org.apache.hadoop.io.retry.RetryInvocationHandler$Call.invokeOnce(RetryInvocationHandler.java:95) at org.apache.hadoop.io.retry.RetryInvocationHandler.invoke(RetryInvocationHandler.java:359) at com.sun.proxy.$Proxy27.truncate(Unknown Source) at org.apache.hadoop.hdfs.DFSClient.truncate(DFSClient.java:1574) at org.apache.hadoop.hdfs.DistributedFileSystem$18.doCall(DistributedFileSystem.java:929) at org.apache.hadoop.hdfs.DistributedFileSystem$18.doCall(DistributedFileSystem.java:926) at org.apache.hadoop.fs.FileSystemLinkResolver.resolve(FileSystemLinkResolver.java:81) at org.apache.hadoop.hdfs.DistributedFileSystem.truncate(DistributedFileSystem.java:936) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.apache.flink.runtime.fs.hdfs.HadoopRecoverableFsDataOutputStream.truncate(HadoopRecoverableFsDataOutputStream.java:209) at org.apache.flink.runtime.fs.hdfs.HadoopRecoverableFsDataOutputStream.safelyTruncateFile(HadoopRecoverableFsDataOutputStream.java:168) ... 26 more - 此时 checkpoint 无法正常完成, 提示失败
- 此时使用保存点停止 filnk 任务提示失败
flink stop -d -m test:34570 d83db9c0dadf29d19d674473b569671b - 此时使用 cancel 停止 flink 任务, 会导致数据的丢失或者重复
- 不做任何操作, 等到 1 个小时左右, 任务自动恢复正常
- 这个过程中, 数据会不断的尝试写 HDFS, 但是总是失败, 导致数据入仓延迟
原因分析
-
发生异常时, 这个task 所在的 yarn container 进程没变, 也就是说 task 只是在同一个 JVM 进程内销毁旧的线程, 重新启动新的线程来运行 task
-
新的 task 线程写 hdfs 使用的 DistributedFileSystem 对象是新创建的, 得到
lease(租约)才能对文件进行 truncate 或者 append 操作, hdfs 的 lease(租约), 其实就是写文件的锁, 保证同一时刻只能有一个程序对同一个文件进行写操作, 有关 hdfs lease 的资料可以参考 https://blog.csdn.net/androidlushangderen/article/details/52850349 -
hdfs 的
lease soft limit(HdfsConstants.LEASE_SOFTLIMIT_PERIOD) 默认为 60 秒, 到期后, 如果没有续约, 其他的 DistributedFileSystem 对象可以抢占到lease, 然后完成 truncate 操作. flink 官方源代码, flink-hadoop-fs包中org.apache.flink.runtime.fs.hdfs.HadoopRecoverableFsDataOutputStream类对 truncate 的实现private static boolean waitUntilLeaseIsRevoked(final FileSystem fs, final Path path) throws IOException { Preconditions.checkState(fs instanceof DistributedFileSystem); final DistributedFileSystem dfs = (DistributedFileSystem) fs; // 恢复租约 dfs.recoverLease(path); // 设置了 LEASE_TIMEOUT=100_000L 毫秒 超时 final Deadline deadline = Deadline.now().plus(Duration.ofMillis(LEASE_TIMEOUT)); // 判断文件是否已经关闭, 如果关闭则可以进行后面的写操作 boolean isClosed = dfs.isFileClosed(path); while (!isClosed && deadline.hasTimeLeft()) { try { Thread.sleep(500L); } catch (InterruptedException e1) { throw new IOException("Recovering the lease failed: ", e1); } isClosed = dfs.isFileClosed(path); } return isClosed; }执行
dfs.recoverLease(path)后, 接着判断dfs.isFileClosed(path)且在100秒内重复判断文件是否关闭. 100 秒大于 hdfslease softlimit过期时间 60 秒, 在hdfs 集群正常的情况下, 100 秒设置是合理的, 足够抢占到lease. -
不幸的是, 我的场景下, flink job 中的 task 每间隔 100 秒左右不断重启, 日志显示: 文件被其他人使用, 无法 truncate, 等到 1 个小时候自动恢复, 这恰巧是 hdfs 的
lease hard limit( HdfsConstants.LEASE_HARDLIMIT_PERIOD) 的默认时间 1 个小时
问题所在
- 某个 datanode 重新启动(云服务的宿主机漂移, 或者手动维护集群),
- 或者 datanode 一直处于高负载的状态(hbase 的 region server 与 datanode 部署在一起, 当有 hbase scan 操作时, datanode 负载很高), namenode 会任务 datanode 失联
- datanode 挂掉,无法恢复(我未测试此场景),
flink 写的 hdfs 文件主副本恰好在此节点, dfs.recoverLease(path) 操作需要等待主副本恢复, 等待时间就很有可能超过 100 秒,
而 flink 任务认为 recoverLease 100 秒后, 文件一定 close 了,
但实际上此时文件并未 close, 进而导致 flink job 的 task 抛出异常, 然后 restart
当 datanode 重启完成并恢复正常后, 理论上 flink job 应该恢复正常, 可实际上依然不断 restart, 持续 1 个小时(hdfs 的 lease hard limit )后恢复正常
参考 hbase 对 recoverLease 的实现 (HBase’s RecoverLeaseFSUtils)
增加了检测租约恢复超时时间到 15 分钟(如果遇到大的问题, hdfs 通常需要 10 分钟才能将节点标记为死节点), 如果采用这种方式, 将 LEASE_TIMEOUT由 100 秒增加到 15 分钟, 也只是较少 task 的 重启次数, 因为拿不到 lease 无法 truncate, 此时数据依然无法正常写入 hdfs, 依然存在数据延迟
此时在 flink web ui 上找到对应的 task 的 container id, 手动 kill 掉其对应的 jvm 进程,
yarn 会重新分配一个新的 container 来启动 flink task, flink job 恢复正常
大胆的猜测:
由于yarn container 进程没有变,
旧的 DistributedFileSystem 对象一直没有销毁, 但也不会有新的写入操作, 也就不会再有更新租约的行为,
新的 DistributedFileSystem 对象执行dfs.recoverLease(path)后, 一致无法抢占, 直到lease hard limit到期, name node 强制恢复租约, 才能正常进行后面的truncate操作
旧的 DistributedFileSystem 对象一直没有销毁, 引发了新的 DistributedFileSystem 对象无法在lease soft limit到期后抢占到lease???
保留的疑问
我自己实现了一个简单的写hdfs 文件操作, 本地执行(非 yarn 环境)
首先创建一个 DistributedFileSystem 对象然后写 hdfs, 同时 flush 完成但不关闭stream, 也不关闭DistributedFileSystem, sleep 2 分钟
然后再创建一个DistributedFileSystem 对象, 使用新的对象 获取租约,等待文件 close, 然后执行 truncate 操作, 一切正常
这跟我上面的猜测是相悖的
测试代码如下
import org.apache.hadoop.conf.Configuration;
import org.apache.hadoop.fs.FSDataOutputStream;
import org.apache.hadoop.fs.FileSystem;
import org.apache.hadoop.fs.Path;
import org.apache.hadoop.hdfs.DistributedFileSystem;
import java.io.IOException;
import java.net.URI;
import java.nio.charset.StandardCharsets;
import java.util.concurrent.TimeUnit;
public class TTT {
public static void main(String[] args) throws Exception {
// 手动创建这个文件, 给 hdfs 用户写权限
String file = "hdfs://xxx:8020/tmp/test_truncate";
Configuration conf = new Configuration();
// 创建第一个 FileSystem
DistributedFileSystem firstFS = (DistributedFileSystem) FileSystem.get(URI.create(file), conf, "hdfs");
Path path = new Path(file);
System.out.println("路径是否存在:" + firstFS.exists(path));
// 写 10 条数据
FSDataOutputStream firstHdfsOutStream = firstFS.append(path);
long l = System.currentTimeMillis();
for (int i = 0; i < 10; i++) {
byte[] strs = (i + " hello world==============>> " + l + "\n").getBytes(StandardCharsets.UTF_8);
try {
firstHdfsOutStream.write(strs);
firstHdfsOutStream.hflush();
} catch (Exception e) {
e.printStackTrace();
}
}
// 不关闭 firstHdfsOutStream
// 不关闭 firstFS
// sleep 2分钟
Thread.sleep(TimeUnit.MINUTES.toMillis(2));
// 创建第二个 FileSystem
DistributedFileSystem secondFS = (DistributedFileSystem) FileSystem.get(URI.create(file), conf, "hdfs");
// 恢复租约
waitUntilLeaseIsRevoked(secondFS, path);
// truncate 文件, truncate是异步的,
truncate(secondFS, path, 5L);
secondFS.close();
}
private static boolean waitUntilLeaseIsRevoked(final DistributedFileSystem fs, final Path path) throws IOException {
boolean b = fs.recoverLease(path);
System.out.println("dfs recoverLease ==> " + b);
boolean isClosed = fs.isFileClosed(path);
System.out.println("dfs isClosed start ==> " + isClosed);
while (!isClosed) {
try {
Thread.sleep(500L);
} catch (InterruptedException e1) {
throw new IOException("Recovering the lease failed: ", e1);
}
isClosed = fs.isFileClosed(path);
System.out.println("dfs isClosed cur ==> " + isClosed);
}
return isClosed;
}
private static boolean truncate(final DistributedFileSystem hadoopFs, final Path file, final long length)
throws IOException {
boolean truncate = hadoopFs.truncate(file, length);
System.out.println(">>>>>>>>>>>>>>>>> truncate: " + truncate);
return truncate;
}
}
手动处理方案: 应对 job 量少的场景
方案一
从日志中找到无法 truncate 的文件, 或者使用 hadoop fsck /xxx/xx -openforwrite 找到本应该关闭但未关闭的文件
手动执行销毁租约操作
hdfs debug recoverLease -path /tmp/.p-0-9.inprogress.fde66baa-5692-40b3-9b45-f8dc10b371e6 -retries 5
当返回成功后, flink job 一般也就会恢复了, 但好多时候此命令无法执行成功, 无法恢复租约
方案二
找到 问题 task 对应的 yarn container 进程, 直接 kill, yarn 会重新启动一个 containre 运行 task, flink job 问题恢复,
有时仍然提示租约未到期,
方案三
- 将无法恢复租约的文件拷贝一份到临时目录:
例如:hadoop fs -cp hdfs://xxx/warehouse/tablespace/external/hive/dwd.db/xxxx_ext/20220220/14/.p-0-2125.inprogress.9ed0a002-e996-4335-b8af-eefe09aa8580 hdfs://xxx/tmp - 将上一步拷贝出来的文件使用
hadoop fs -cp -f强制覆盖回去
例如:hadoop fs -cp -f hdfs://xxx/tmp/.p-0-2125.inprogress.9ed0a002-e996-4335-b8af-eefe09aa8580 hdfs://xxx/warehouse/tablespace/external/hive/dwd.db/xxxx_ext/20220220/14 - 此时文件已经改变, 释放锁, 恢复租约 ,flink job 一般也就会恢复了
方案四
一般到 方案三 就已经搞定了, 再不行就采取 cancel job的方案了.
- 找到 job 页面的
Checkpoints-->Overview中找到Latest Completed Checkpoint的路径,
例如:Checkpoint Detail:Path: hdfs://xxx/user/flink/1.12.2/checkpoints/ab0134ac90e9992b9583f6a9a648650e/chk-12945 - 将
Latest Completed Checkpoint的路径拷贝到临时目录, 做备份(非常重要, 否则一会 cancel job 后可能会丢失 )hadoop fs -cp -r hdfs://xxx/user/flink/1.12.2/checkpoints/ab0134ac90e9992b9583f6a9a648650e/chk-12945 hdfs://xxx/tmp/ - 直接 cancel job,
- 将无法恢复租约的文件拷贝一份到临时目录:
例如:hadoop fs -cp hdfs://xxx/warehouse/tablespace/external/hive/dwd.db/xxxx_ext/20220220/14/.p-0-2125.inprogress.9ed0a002-e996-4335-b8af-eefe09aa8580 hdfs://xxx/tmp - 删除无法恢复租约的文件
hadoop fs -rm hdfs://xxx/warehouse/tablespace/external/hive/dwd.db/xxxx_ext/20220220/14/.p-0-2125.inprogress.9ed0a002-e996-4335-b8af-eefe09aa8580 - 将第
4步中拷贝出来的文件移动到源文件目录hadoop fs -mv hdfs://xxx/tmp/.p-0-2125.inprogress.9ed0a002-e996-4335-b8af-eefe09aa8580 hdfs://xxx/warehouse/tablespace/external/hive/dwd.db/xxxx_ext/20220220/14/ - 重新启动任务并指定保存点为第
2步中备份的检查点目录flink run ..... hdfs://xxx/tmp/chk-12945 - 此时任务恢复
自动处理方案: 应对 job 量大的场景
集群比较大的时候, 任务过多, 手动处理不太现实,
方案一
可以将上述手动处理方案自动化(自行写脚本)
方案二
- hdfs 文件副本数调整到 >= 3
- 修改
org.apache.flink.runtime.fs.hdfs.HadoopRecoverableFsDataOutputStream.LEASE_TIMEOUT增加过期时间到 15 分钟, - 同时减少 hdfs 的
lease hard limit过期时间为 10 分钟, hdfs 3.2 开始,lease hard limit过期时间默认为 20 分钟, 并可以通过配置dfs.namenode.lease-hard-limit-sec修改此时间, - 重新编译 flink-hadoop-fs 包
这样最多 15 分钟,集群也就恢复正常了
833
被折叠的 条评论
为什么被折叠?
到【灌水乐园】发言
