Alluxio HA 写入文件失败

Posted 2020-12-25

Alluxio HA环境,今天发生,用户无法写入文件的情况. 创建文件夹,是正常的.但是最后copyFromLocal 文件的时候,就没有任何反应.最后可以看到这个新建的文件.但是文件size是0.

alluxio fs copyFromLocal test.txt /user/mytest/prefix2

最后决定重启一下master看看结果.然后重启,然后...就没有然后了.....Master起不来了!!!!

查看master.log发现问题,刚开始,是正常的应用log file,在 inodeId 52,无法正常打开.导致master启动失败.

2018-07-25 16:39:12,897 INFO  logger.type (JournalTailer.java:processNextJournalLogFiles) - FileSystemMaster: Processing a completed log file.

.......

2018-07-25 16:39:21,461 INFO  logger.type (JournalReader.java:getNextInputStream) - Opening journal log file: hdfs://azbeta/user/alluxio/journal/FileSystemMaster/completed/log.00000000000000000007

2018-07-25 16:39:21,512 INFO  logger.type (JournalTailer.java:processNextJournalLogFiles) - FileSystemMaster: Processing a completed log file.

2018-07-25 16:39:21,520 ERROR logger.type (ServerUtils.java:run) - Uncaught exception while running Alluxio master, stopping it and exiting.

java.lang.RuntimeException: alluxio.exception.FileDoesNotExistException: inodeId 52 does not exist

at alluxio.master.file.FileSystemMaster.processJournalEntry(FileSystemMaster.java:347)

at alluxio.master.journal.JournalTailer.processNextJournalLogFiles(JournalTailer.java:123)

at alluxio.master.AbstractMaster.start(AbstractMaster.java:148)

at alluxio.master.file.FileSystemMaster.start(FileSystemMaster.java:419)

at alluxio.master.DefaultAlluxioMaster.startMasters(DefaultAlluxioMaster.java:263)

at alluxio.master.FaultTolerantAlluxioMaster.start(FaultTolerantAlluxioMaster.java:91)

at alluxio.ServerUtils.run(ServerUtils.java:38)

at alluxio.master.AlluxioMaster.main(AlluxioMaster.java:43)

Caused by: alluxio.exception.FileDoesNotExistException: inodeId 52 does not exist

at alluxio.master.file.meta.InodeTree.lockFullInodePath(InodeTree.java:351)

at alluxio.master.file.FileSystemMaster.setAttributeFromEntry(FileSystemMaster.java:3006)

at alluxio.master.file.FileSystemMaster.processJournalEntry(FileSystemMaster.java:345)

... 7 more

2018-07-25 16:39:21,522 INFO  logger.type (DefaultAlluxioMaster.java:stop) - Stopping Alluxio master @ aznballuxiosl01.envazure.com/10.24.101.103:19998

2018-07-25 16:39:21,522 ERROR logger.type (LeaderSelectorClient.java:takeLeadership) - aznballuxiosl01.envazure.com:19998 was interrupted.

java.lang.InterruptedException: sleep interrupted

at java.lang.Thread.sleep(Native Method)

at alluxio.LeaderSelectorClient.takeLeadership(LeaderSelectorClient.java:177)

at org.apache.curator.framework.recipes.leader.LeaderSelector$3.run(LeaderSelector.java:328)

at com.google.common.util.concurrent.MoreExecutors$SameThreadExecutorService.execute(MoreExecutors.java:293)

at org.apache.curator.framework.recipes.leader.LeaderSelector.doWork(LeaderSelector.java:319)

at org.apache.curator.framework.recipes.leader.LeaderSelector.doWorkLoop(LeaderSelector.java:376)

at org.apache.curator.framework.recipes.leader.LeaderSelector.access$100(LeaderSelector.java:48)

at org.apache.curator.framework.recipes.leader.LeaderSelector$2.call(LeaderSelector.java:197)

at java.util.concurrent.FutureTask.run(FutureTask.java:262)

at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)

at java.lang.Thread.run(Thread.java:745)

通过hdfs fsck /  , 也没有检查到文件损坏.

$ hdfs fsck /user/alluxio/

Connecting to namenode via https://azcbetannl02.envazure.com:50470/fsck?ugi=hdfs&path=%2Fuser%2Falluxio

FSCK started by hdfs (auth:KERBEROS_SSL) from /10.24.101.76 for path /user/alluxio at Wed Jul 25 16:38:07 CST 2018

.........Status: HEALTHY

Total size:    61438434 B (Total open files size: 275 B)

Total dirs:    7

Total files:   9

Total symlinks:                0 (Files currently being written: 1)

Total blocks (validated):      8 (avg. block size 7679804 B) (Total open file blocks (not validated): 1)

Minimally replicated blocks:   8 (100.0 %)

Over-replicated blocks:        0 (0.0 %)

Under-replicated blocks:       0 (0.0 %)

Mis-replicated blocks:         0 (0.0 %)

Default replication factor:    3

Average block replication:     3.0

Corrupt blocks:                0

Missing replicas:              0 (0.0 %)

Number of data-nodes:          6

Number of racks:               1

FSCK ended at Wed Jul 25 16:38:07 CST 2018 in 4 milliseconds

The filesystem under path '/user/alluxio' is HEALTHY

经过google查询,也没有什么好的解决方案.

最后使用杀手锏. format master. 效果立杆见影. master起来了, 数据也全没啦!!! 注意:数据全没了!!

由于我们的alluxio只是一个中间临时缓存,format的影响不大.

我们看看, alluxio正常启动,日志是什么样子的:

2018-07-25 16:40:52,545 INFO  logger.type (AbstractMaster.java:start) - FileSystemMaster: Starting leader master.

2018-07-25 16:40:52,550 INFO  logger.type (JournalWriter.java:completeAllLogs) - Marking all logs as complete.

2018-07-25 16:40:52,557 INFO  logger.type (AbstractMaster.java:start) - FileSystemMaster: journal checkpoint does not exist, nothing to process.

2018-07-25 16:40:52,562 INFO  logger.type (JournalWriter.java:getCheckpointOutputStream) - Creating tmp checkpoint file: hdfs://azbeta/user/alluxio/journal/FileSystemMaster/checkpoint.data.tmp

2018-07-25 16:40:52,564 INFO  logger.type (JournalWriter.java:getCheckpointOutputStream) - Latest journal sequence number: 0 Next journal sequence number: 1

2018-07-25 16:40:52,699 INFO  logger.type (JournalWriter.java:close) - Successfully created tmp checkpoint file: hdfs://azbeta/user/alluxio/journal/FileSystemMaster/checkpoint.data.tmp

2018-07-25 16:40:52,720 INFO  logger.type (CheckpointManager.java:updateCheckpoint) - Renamed the checkpoint file from hdfs://azbeta/user/alluxio/journal/FileSystemMaster/checkpoint.data.tmp to hdfs://azbeta/user/alluxio/journal/FileSystemMaster/checkpoint.data

2018-07-25 16:40:52,720 INFO  logger.type (JournalWriter.java:deleteCompletedLogs) - Deleting all completed log files...

2018-07-25 16:40:52,722 INFO  logger.type (JournalWriter.java:deleteCompletedLogs) - Deleting completed log: hdfs://azbeta/user/alluxio/journal/FileSystemMaster/completed/log.00000000000000000000

2018-07-25 16:40:52,723 INFO  logger.type (JournalWriter.java:deleteCompletedLogs) - Finished deleting all completed log files.

2018-07-25 16:40:52,735 INFO  logger.type (MetricsSystem.java:startSinksFromConfig) - Starting sinks with config: {}.

2018-07-25 16:40:52,750 INFO  util.log (Log.java:initialized) - Logging initialized @5111ms

2018-07-25 16:40:52,917 INFO  server.Server (Server.java:doStart) - jetty-9.2.z-SNAPSHOT

2018-07-25 16:40:52,943 INFO  handler.ContextHandler (ContextHandler.java:doStart) - Started [email protected]{/metrics/json,null,AVAILABLE}

2018-07-25 16:41:04,080 INFO  handler.ContextHandler (ContextHandler.java:doStart) - Started [email protected]{/,file:/data1/alluxio-1.4.0/core/server/src/main/webapp/,AVAILABLE}{/data1/alluxio-1.4.0/core/server/src/main/webapp}

2018-07-25 16:41:04,087 INFO  server.ServerConnector (AbstractConnector.java:doStart) - Started [email protected]{HTTP/1.1}{0.0.0.0:19999}

2018-07-25 16:41:04,087 INFO  server.Server (Server.java:doStart) - Started @16448ms

2018-07-25 16:41:04,087 INFO  logger.type (WebServer.java:start) - Alluxio Master Web service started @ /0.0.0.0:19999

2018-07-25 16:41:04,088 INFO  logger.type (DefaultAlluxioMaster.java:startServing) - Alluxio master version 1.4.0 started @ aznballuxiosl01.envazure.com/10.24.101.103:19998 (gained leadership)

总结:

Alluxio HA的使用,原本是为了数据安全性和稳定性.

但是已经发生过多次,在hdfs上的journal文件夹的共享文件损坏的情况. 稳定性反倒变差了.这个需要重新考量,是否使用hdfs,提供HA的方式了.

另外,每次发生问题的时候hdfs fsck都是正常的.也就是说,不是hdfs 的"锅",而是alluxio写入hdfs的时候,没有成功,导致的文件损坏.