引导操作成功后，节点配置程序中的 EMR 从属引导失败

Question

我正在尝试使用 EMR w/ Spark 在 AWS 中启动一个集群。我有一个 bash 引导脚本来安装一些 python 包、下载凭据并应用一些配置。引导操作在主设备上成功，但在从设备上失败。唯一的错误提示是“i-######：启动失败。引导操作 2 失败，退出代码为非零”。紧接其前面的消息是“i-######：引导操作 1 已完成”。（在这两种情况下都指从属设备的实例 ID。主设备还报告引导操作 1 成功）。

因此，引导操作 2 中执行的最后一个命令似乎有错误，并导致引导脚本返回非零退出代码。但是，我只配置了一个 bootstrap action。非主节点是否自动运行另一个引导操作？

没有日志显示实际错误是什么。我查看了 S3 上的引导日志（无法可靠显示），并尝试在启动期间跟踪从站和主站上的 /var/log/bootstrap-actions/ 日志。

我很确定错误不在我的脚本中（每个开发人员都说......）。我能够创建一个无引导的普通 EMR 集群，然后在等待时登录并以 hadoop 用户身份运行我的引导脚本，没有错误。我还查看了最后几个命令（grep 和 echo）并验证它们不会返回非零退出，也不会导致脚本返回非零退出代码。

我认为问题一定出在一些神秘的第二次引导操作中。是这样吗？我如何确定错误？

更新我在启动期间登录到从属节点。我在 中找到了引导操作/emr/instance-controller/lib/bootstrap-actions。只有 1 个子文件夹，其中包含我的引导脚本。我然后就跑了 tail -f /emr/instance-controller/log/instance-controller.log。我验证了我的脚本已启动。经过大约 15 个状态检查周期（15 分钟）后，我明白了

2017-06-02 13:44:30,173 INFO InstanceConfigurer: Script 1 - Execution succeeded

然后我看到另一个 AWS 脚本启动，这似乎是失败的一个。

2017-06-02 13:44:30,181 INFO InstanceConfigurer: Running provision-node, with id 5aed1c54-4210-4387-944a-4fdbbce6dc8d
2017-06-02 13:44:30,188 INFO InstanceConfigurer: Script 5aed1c54-4210-4387-944a-4fdbbce6dc8d - Fetching file '/var/lib/aws/emr/provision-node'
2017-06-02 13:44:30,188 INFO InstanceConfigurer: Script 5aed1c54-4210-4387-944a-4fdbbce6dc8d - startExec '/var/lib/aws/emr/provision-node'
2017-06-02 13:44:30,189 INFO InstanceConfigurer: startExec '/var/lib/aws/emr/provision-node'
2017-06-02 13:44:30,190 INFO InstanceConfigurer: Script 5aed1c54-4210-4387-944a-4fdbbce6dc8d - Environment:
...
2017-06-02 13:44:54,201 INFO InstanceConfigurer: Output from command '/var/lib/aws/emr/provision-node':
stdout:
stderr:

2017-06-02 13:44:54,202 INFO InstanceConfigurer: Script 5aed1c54-4210-4387-944a-4fdbbce6dc8d - waitProcessCompletion ended with exit code 255 : /var/lib/aws/emr/provision-node
2017-06-02 13:44:54,202 INFO InstanceConfigurer: waitProcessCompletion ended with exit code 255 : /var/lib/aws/emr/provision-node
2017-06-02 13:44:54,203 INFO InstanceConfigurer: Script 5aed1c54-4210-4387-944a-4fdbbce6dc8d - total process run time: 24 seconds
2017-06-02 13:44:54,203 INFO InstanceConfigurer: total process run time: 24 seconds
2017-06-02 13:44:54,217 ERROR InstanceConfigurer: Script 5aed1c54-4210-4387-944a-4fdbbce6dc8d - Execution for /var/lib/aws/emr/provision-node failed with code '255'
2017-06-02 13:44:54,219 ERROR InstanceConfigurer: Startup failed with
aws157.instancecontroller.common.model.InstanceConfiguratorException: Source: PROVISION_NODE | ErrorCode: SCRIPT_EXECUTION_FAILED_CODE | Execution for /var/lib/aws/emr/provision-node failed with code '255'
    at aws157.instancecontroller.common.InstanceConfigurator.runScript(InstanceConfigurator.java:563)
    at aws157.instancecontroller.common.InstanceConfigurator.provisionNode(InstanceConfigurator.java:225)
    at aws157.instancecontroller.common.InstanceConfigurator.doDistributionConfigure(InstanceConfigurator.java:201)
    at aws157.instancecontroller.common.InstanceConfigurator.access$200(InstanceConfigurator.java:70)
    at aws157.instancecontroller.common.InstanceConfigurator$1.run(InstanceConfigurator.java:251)

我不熟悉该/var/lib/aws/emr/provision-node脚本，但其唯一内容是

#!/bin/bash
set -ex

sudo /usr/share/aws/emr/node-provisioner/bin/provision-node "$@"

看看/usr/share/aws/emr/node-provisioner/bin/provision-node，我可以看到这个脚本做了很多工作来识别 $EMR_NODE_PROVISIONER_HOME 的路径，然后从那里运行以下 Java 类

java -classpath '/usr/share/aws/emr/node-provisioner/lib/*' com.amazonaws.emr.node.provisioner.Program --phase hadoop _UUID_

我通过查看提供节点脚本的源代码并独立运行它来解决这个问题。我无法实时捕获日志或故障以查看出了什么问题。当我单独运行它时，出现以下异常。但我认为这是因为我传递了垃圾数据而不是UUID（我不知道UUID来自哪里，并且在每个从站启动时都是不同的）。

2017-06-02 14:55:13,593 ERROR main: Encountered a problem while provisioning
java.net.SocketTimeoutException: Read timed out
    at java.net.SocketInputStream.socketRead0(Native Method)
    at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
    at java.net.SocketInputStream.read(SocketInputStream.java:171)
    at java.net.SocketInputStream.read(SocketInputStream.java:141)
    at java.io.BufferedInputStream.fill(BufferedInputStream.java:246)
    at java.io.BufferedInputStream.read1(BufferedInputStream.java:286)
    at java.io.BufferedInputStream.read(BufferedInputStream.java:345)
    at sun.net.www.http.HttpClient.parseHTTPHeader(HttpClient.java:735)
    at sun.net.www.http.HttpClient.parseHTTP(HttpClient.java:678)
    at sun.net.www.protocol.http.HttpURLConnection.getInputStream0(HttpURLConnection.java:1569)
    at sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1474)
    at java.net.HttpURLConnection.getResponseCode(HttpURLConnection.java:480)
    at com.google.api.client.http.javanet.NetHttpResponse.<init>(NetHttpResponse.java:37)
    at com.google.api.client.http.javanet.NetHttpRequest.execute(NetHttpRequest.java:94)
    at com.google.api.client.http.HttpRequest.execute(HttpRequest.java:972)
    at com.amazonaws.emr.node.provisioner.http.JsonHttpClient.doRequest(JsonHttpClient.java:49)
    at com.amazonaws.emr.node.provisioner.platform.EmrPlatformClient.getConfiguration(EmrPlatformClient.java:38)
    at com.amazonaws.emr.node.provisioner.platform.EmrPlatformClient.getConfiguration(EmrPlatformClient.java:31)
    at com.amazonaws.emr.node.provisioner.bigtop.config.PlatformContextProvider.provide(PlatformContextProvider.java:32)
    at com.amazonaws.emr.node.provisioner.phase.PhaseWorkflow.work(PhaseWorkflow.java:51)
    at com.amazonaws.emr.node.provisioner.phase.ProvisionHadoopPhase.perform(ProvisionHadoopPhase.java:21)
    at com.amazonaws.emr.node.provisioner.Program.main(Program.java:20)

所以我现在的问题是 com.amazonaws.emr.node.provisioner.Program 是什么以及为什么它失败（或者我如何找出原因？）？

更新2

我设法跟踪 /usr/share/aws/emr/node-provisioner/bin/provision-node 的输出直至失败，结果与我上面的独立运行相同。

java -classpath '/usr/share/aws/emr/node-provisioner/lib/*' com.amazonaws.emr.node.provisioner.Program --phase hadoop
2017-06-02 17:05:37,869 ERROR main: Encountered a problem while provisioning
java.net.SocketTimeoutException: Read timed out
    at java.net.SocketInputStream.socketRead0(Native Method)
    at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
    at java.net.SocketInputStream.read(SocketInputStream.java:171)
    at java.net.SocketInputStream.read(SocketInputStream.java:141)
    at java.io.BufferedInputStream.fill(BufferedInputStream.java:246)
    at java.io.BufferedInputStream.read1(BufferedInputStream.java:286)
    at java.io.BufferedInputStream.read(BufferedInputStream.java:345)
    at sun.net.www.http.HttpClient.parseHTTPHeader(HttpClient.java:735)
    at sun.net.www.http.HttpClient.parseHTTP(HttpClient.java:678)
    at sun.net.www.protocol.http.HttpURLConnection.getInputStream0(HttpURLConnection.java:1569)
    at sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1474)
    at java.net.HttpURLConnection.getResponseCode(HttpURLConnection.java:480)
    at com.google.api.client.http.javanet.NetHttpResponse.<init>(NetHttpResponse.java:37)
    at com.google.api.client.http.javanet.NetHttpRequest.execute(NetHttpRequest.java:94)
    at com.google.api.client.http.HttpRequest.execute(HttpRequest.java:972)
    at com.amazonaws.emr.node.provisioner.http.JsonHttpClient.doRequest(JsonHttpClient.java:49)
    at com.amazonaws.emr.node.provisioner.platform.EmrPlatformClient.getConfiguration(EmrPlatformClient.java:38)
    at com.amazonaws.emr.node.provisioner.platform.EmrPlatformClient.getConfiguration(EmrPlatformClient.java:31)
    at com.amazonaws.emr.node.provisioner.bigtop.config.PlatformContextProvider.provide(PlatformContextProvider.java:32)
    at com.amazonaws.emr.node.provisioner.phase.PhaseWorkflow.work(PhaseWorkflow.java:51)
    at com.amazonaws.emr.node.provisioner.phase.ProvisionHadoopPhase.perform(ProvisionHadoopPhase.java:21)
    at com.amazonaws.emr.node.provisioner.Program.main(Program.java:20)

我猜测这可能是防火墙/安全组问题，但我使用的是 EMR 生成的默认安全组，因此我希望端口打开。我正在 VPC 的私有子网中构建此集群，因此这可能是一个问题。但是，当我构建一个没有引导的集群时，我不会遇到这种失败。我的下一个调试步骤是构建一个没有引导的普通集群并监视相同的命令。

更新 3 确认使用 Spark 的普通 EMR 部署成功，无需网络更改。/usr/share/aws/emr/node-provisioner/bin/provision-node 中没有错误。启动 java 命令后，stderr 的下一行显示平台配置参数的 JSON 转储。但是，stdout 显示来自存储库 Bigtop 的 yum 软件包安装。我在脚本或 stderr 输出（来自 set -xe）中没有看到 yum 命令，因此我认为 yum 命令必须位于该 Java 程序中。不知道为什么他们在这里成功，但没有通过引导操作。

我的私有 VPC 确实有一个带有子网路由和防火墙规则的 S3 端点，允许访问端点 plist。我的引导脚本能够使用 yum（不是来自 Bigtop 存储库）成功安装软件包、从 S3 复制文件以及从互联网上的外部 git 存储库下载代码。

Answer 1

我自己也遇到了这个问题，这就是我所发现的。引导操作 2 指的是节点配置，由于自定义引导操作 1 中的失误而失败。例如，在我的例子中，我正在安装版本 X 的 MySQL 服务器，然后在节点配置期间，执行失败，因为 yum 是尝试安装不同版本的 MySQL 服务器。看来 yum 更新冲突是问题的主要原因之一。

消息传递非常不清楚，也没有好的文档。

如果您遇到类似情况，请检查集群的所有日志。就我而言，我在以下日志文​​件中发现了有问题的消息

s3://aws-logs-<account-id>-us-west-2/elasticmapreduce/<cluster-id>/node/<instance-id>/provision-node/apps-phase/0/93d592d9-d7e8-47a8-9972-05922c5a9885/stderr.gz

Answer 2

我的引导脚本正在运行 yum 更新。当我注释掉这一点时，我能够通过配置节点脚本并最终使集群进入等待状态。其中一项更新肯定会造成某种冲突或其他问题。我不知道是哪一个。现在，我只是避免运行 yum update。

这是 yum 日志。我猜它不是 R 或 mysql 软件包之一。也许是 java、kernel、aws 或 util-linux？

Installed:
  kernel.x86_64 0:4.9.27-14.31.amzn1

Updated:
  R.x86_64 0:3.3.3-1.51.amzn1
  R-core.x86_64 0:3.3.3-1.51.amzn1
  R-core-devel.x86_64 0:3.3.3-1.51.amzn1
  R-devel.x86_64 0:3.3.3-1.51.amzn1
  R-java.x86_64 0:3.3.3-1.51.amzn1
  R-java-devel.x86_64 0:3.3.3-1.51.amzn1
  aws-amitools-ec2.noarch 0:1.5.13-0.2.amzn1
  aws-cli.noarch 0:1.11.83-1.46.amzn1
  java-1.8.0-openjdk.x86_64 1:1.8.0.131-2.b11.30.amzn1
  java-1.8.0-openjdk-devel.x86_64 1:1.8.0.131-2.b11.30.amzn1
  java-1.8.0-openjdk-headless.x86_64 1:1.8.0.131-2.b11.30.amzn1
  libRmath.x86_64 0:3.3.3-1.51.amzn1
  libRmath-devel.x86_64 0:3.3.3-1.51.amzn1
  libblkid.x86_64 0:2.23.2-33.28.amzn1
  libmount.x86_64 0:2.23.2-33.28.amzn1
  libuuid.x86_64 0:2.23.2-33.28.amzn1
  mysql-config.x86_64 0:5.5.56-1.17.amzn1
  mysql55.x86_64 0:5.5.56-1.17.amzn1
  mysql55-devel.x86_64 0:5.5.56-1.17.amzn1
  mysql55-libs.x86_64 0:5.5.56-1.17.amzn1
  ntp.x86_64 0:4.2.6p5-44.34.amzn1
  ntpdate.x86_64 0:4.2.6p5-44.34.amzn1
  python27-botocore.noarch 0:1.5.46-1.63.amzn1
  python27-jmespath.noarch 0:0.9.2-1.12.amzn1
  util-linux.x86_64 0:2.23.2-33.28.amzn1

欢迎进一步的见解。否则，继续实际运行我的代码。