Alluxio HA 写入文件失败

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

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

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

1. 查看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)

2. 通过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

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

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

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

5. 我们看看, 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 o.e.j.s.ServletContextHandler@7ee0a1b3{/metrics/json,null,AVAILABLE}
2018-07-25 16:41:04,080 INFO  handler.ContextHandler (ContextHandler.java:doStart) - Started o.e.j.w.WebAppContext@4e3fbce1{/,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 ServerConnector@47fe4ff8{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的时候,没有成功,导致的文件损坏.