HTTP部分时候请求长时间卡死超时问题排查思路

部分业务方用户反映有些时候hue刷新页面会卡死2-5min无响应。个人也遇到过几次，在页面访问卡住的同时，通过curl url:8890 -I -L一样会卡住无法返回页面内容。

通过记录事故时间点反查linux TCP相关信息，发现在卡死的时刻，TCP connection数量骤增到2-3k (ss -s)，同时TCcpExt的ListenDrops和TcpExt.ListenOverflows会相对较高：

此时感觉是因为sysctl中关于TCP连接的部分参数没有优化导致，所以添加了如下参数并重启了hue服务，但问题依旧。

net.ipv4.tcp_tw_reuse = 1

net.ipv4.tcp_tw_recycle = 1

net.ipv4.tcp_fin_timeout = 10

net.ipv4.tcp_keepalive_time = 1200

net.ipv4.tcp_max_syn_backlog = 65535

net.ipv4.tcp_max_tw_buckets = 400000

net.ipv4.tcp_orphan_retries = 1

net.ipv4.tcp_retries2 = 5

net.core.netdev_max_backlog = 512000

net.ipv4.tcp_syn_retries = 3

net.ipv4.tcp_synack_retries = 3

net.ipv4.tcp_slow_start_after_idle = 0

vm.min_free_kbytes = 360448

vm.zone_reclaim_mode = 1

net.core.somaxconn = 65535

#net.netfilter.nf_conntrack_max = 1655350

#net.netfilter.nf_conntrack_tcp_timeout_established = 7200

#net.netfilter.nf_conntrack_tcp_timeout_time_wait = 10

kernel.shmall = 4294967296

kernel.shmmax = 68719476736

kernel.msgmax = 65536

kernel.msgmnb = 65536

此时想关注下到底是哪个进程导致了TCP连接数骤增，ss -n后发现主要为:50010端口。netstat -nlp | grep :50010后发现是DataNode服务。

此时通过dmesg发现如下报错内容：

[12522087.589828] TCP: request_sock_TCP: Possible SYN flooding on port 50010. Sending cookies.  Check SNMP counters.

[12547933.126955] TCP: request_sock_TCP: Possible SYN flooding on port 50010. Sending cookies.  Check SNMP counters.

也即TCP连接已经全被50010吃满了，导致新来的hue请求无法正常建立connection导致用户角度的卡死和超时（参考：https://help.marklogic.com/Knowledgebase/Article/View/182/0/possible-syn-flooding-messages-in-system-logs）。

同时，通过sar -n DEV 3发现下行带宽已经占了1.2GB/s, 已经达到机器对应的最大下行带宽，所以数据传输不出去也是可能的因素之一。

最终，将混部的服务拆分到独立的节点，问题解决。

hue后端的django请求HOST为domain时返回400 BAD REQUEST，ip+port则没问题排查思路

通过nginx反向代理到两台hue webserver服务后，发现wget dp-hue_nginx.company.com/hue会返回400 BAD REQUEST, 而请求服务对应的ip:portwget 192.168.1.121:8005/hue则没有问题。

继续找到问题来源，直接对某台hue webserver执行如下命令，发现上述问题可以复现，所以排除掉nginx的问题。

$ curl -I -H 'Host:dp-hue_nginx.corp.kuaishou.com' http://hue-webserver/accounts/login/?next=/

HTTP/1.1 400 BAD REQUEST




$ curl -I -H 'Host:127.0.0.1:8888' http://hue-webserver/accounts/login/?next=/

HTTP/1.1 200 OK

google得到相关post, 说设置allowed_hosts即可，检查$HUE_HOME/desktop/conf/hue.ini, 此参数默认为'*'.

再次google得到此文, 发现是个django的bug。在请求的host domain路径里不能包括下划线（underscore）。

Spark执行卡住或过慢时从YARN监控页排查思路

• 在YARN-Stages tab，检查卡住/很慢的stage对应的executor数量，如果executor数量很少，同时对应后面的shuffle read size或者records数量很大（图1），则很可能是因为没有开启spark.dynamicAllocation.enabled。开启配置如下： 

spark.dynamicAllocation.enabled               true

spark.dynamicAllocation.initialExecutors            1

spark.dynamicAllocation.minExecutors     1

spark.dynamicAllocation.maxExecutors     300

spark.shuffle.service.enabled    true

• 如果某个很慢或者卡住的stage对应的task数量为200（图2），则应该注意是spark.sql.shuffle.partitions导致的，此param默认200，可以设置为2011等大值即可。同理，如果出现tasks数量为12，则应该是由于spark.default.parallelism参数。

• 观察“Executor页面，如果Task Time(GC Time)背景飘红，说明gc时间过长。可以通过启动时添加set spark.executor.extraJavaOptions=-verbose:gc -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintGC打印gc日志，从executor列表后面的stdout里查看。从优化角度讲，spark推荐使用G1GC。如果G1GC依旧出现上述问题，则可能当前在一个executor里并发的task数过多（task本身是一个算子(lambda)，所以可能使当前的< 输入->输出 >后数据膨胀）。比如executor.memory为12G，executor.cores为4，则一共有4个task并行，每个task平均3g内存。如果减少cores数量，则可以变相提高每个task可使用的内存量。对于当前的case，从gc日志看出，heap space已经动态expand到12G，说明task的确需要消耗很多内存，所以只好调小cores数量从而降低gc time。

在YARN-Jobs tab，可以看到所有stage列表，每项后面有Shuffle Read和Shuffle Write. 前者表示从上一个stage读取的shuffle数据数量，后者表示写出到下一个stage的shuffle数据数量。从这里可以可以粗略估计下当前stage所需的tasks数量。

REFERENCE: 

Apache Spark Performance Tuning – Degree of Parallelism

spark读取hive-site.xml无法识别里面spark相关参数问题

通过如下语句启动spark-sql时，如果有spark相关参数在hive-site.xml中，并不会被load到spark environment里。spark只会从hive-site.xml中读取hive相关的参数（例如metastore信息等）。

/home/hadoop/software/spark/bin/spark-sql \

--master yarn \

--deploy-mode client \

--queue queue_1 \

--conf spark.rpc.message.maxSize=2047 \

--conf spark.yarn.dist.files="/path/to/hive-site.xml"

同理，即使将spark.yarn.dist.files行的配置换成了--files /path/to/hive-site.xml或者--properties-file /path/to/hive-site.xml也没有用（--properties-file的解释为"Path to a file from which to load extra properties. If not specified, this will look for conf/spark-defaults.conf.", 读取的文件内容不应该为xml格式）。

如果需要配置spark相关的信息，需要在SPARK_HOME/conf/spark-defaults.conf中配置。

HiveOnSpark系列：metadata.HiveException: java.util.concurrent.TimeoutException

运行一个数据量很大的SparkOnHive SQL(如下), 会报TimeoutException。

ERROR : Failed to monitor Job[0] with exception 'org.apache.hadoop.hive.ql.metadata.HiveException(java.util.concurrent.TimeoutException)'

org.apache.hadoop.hive.ql.metadata.HiveException: java.util.concurrent.TimeoutException

    at org.apache.hadoop.hive.ql.exec.spark.status.impl.RemoteSparkJobStatus.getSparkJobInfo(RemoteSparkJobStatus.java:174) ~[hive-exec-2.3.2.jar:2.3.2]

    at org.apache.hadoop.hive.ql.exec.spark.status.impl.RemoteSparkJobStatus.getState(RemoteSparkJobStatus.java:81) ~[hive-exec-2.3.2.jar:2.3.2]

    at org.apache.hadoop.hive.ql.exec.spark.status.RemoteSparkJobMonitor.startMonitor(RemoteSparkJobMonitor.java:82) [hive-exec-2.3.2.jar:2.3.2]

    at org.apache.hadoop.hive.ql.exec.spark.status.impl.RemoteSparkJobRef.monitorJob(RemoteSparkJobRef.java:60) [hive-exec-2.3.2.jar:2.3.2]

    at org.apache.hadoop.hive.ql.exec.spark.SparkTask.execute(SparkTask.java:116) [hive-exec-2.3.2.jar:2.3.2]

    at org.apache.hadoop.hive.ql.exec.Task.executeTask(Task.java:199) [hive-exec-2.3.2.jar:2.3.2]

    at org.apache.hadoop.hive.ql.exec.TaskRunner.runSequential(TaskRunner.java:100) [hive-exec-2.3.2.jar:2.3.2]

    at org.apache.hadoop.hive.ql.exec.TaskRunner.run(TaskRunner.java:79) [hive-exec-2.3.2.jar:2.3.2]

Caused by: java.util.concurrent.TimeoutException

    at io.netty.util.concurrent.AbstractFuture.get(AbstractFuture.java:56) ~[netty-all-4.0.52.Final.jar:4.0.52.Final]

    at org.apache.hadoop.hive.ql.exec.spark.status.impl.RemoteSparkJobStatus.getSparkJobInfo(RemoteSparkJobStatus.java:171) ~[hive-exec-2.3.2.jar:2.3.2]

    ... 7 more

根据错误栈信息追踪源代码(入口: RemoteSparkJobStatus.java:174)，发现有个设置超时选项，regarding "Timeout for requests from Hive client to remote Spark driver". 默认是60s，应该是因为application比较复杂，导致请求时间会久一些，设置为600s即可解决。

sparkClientTimtout = hiveConf.getTimeVar(HiveConf.ConfVars.SPARK_CLIENT_FUTURE_TIMEOUT, TimeUnit.SECONDS);




SPARK_CLIENT_FUTURE_TIMEOUT("hive.spark.client.future.timeout",

      "60s", new TimeValidator(TimeUnit.SECONDS),

      "Timeout for requests from Hive client to remote Spark driver.")

Hive query（只select，不insert table/partition）时产生大量小文件问题定位思路

执行一个简单的select+filter+limit语句，因为filter中带non-partition field, 所以会启动MR（相关参考: Hive带non-parttiion-filter的query自动转化为local FetchTask问题）

在hive终端，发现在MR job执行succeed之后（yarn观察也是succeed），会一直卡在INFO: OK日志后，好像拉取结果时卡住了。

通过jstack打印线程栈如下，卡在了从NameNode拉取DFS文件元信息。

   java.lang.Thread.State: WAITING (on object monitor)

    at java.lang.Object.wait(Native Method)

    at java.lang.Object.wait(Object.java:502)

    at org.apache.hadoop.ipc.Client.call(Client.java:1463)

    - locked <0x00000003377bf118> (a org.apache.hadoop.ipc.Client$Call)

    at org.apache.hadoop.ipc.Client.call(Client.java:1409)

    at org.apache.hadoop.ipc.ProtobufRpcEngine$Invoker.invoke(ProtobufRpcEngine.java:230)

    at com.sun.proxy.$Proxy29.getBlockLocations(Unknown Source)

    at org.apache.hadoop.hdfs.protocolPB.ClientNamenodeProtocolTranslatorPB.getBlockLocations(ClientNamenodeProtocolTranslatorPB.java:256)

    at sun.reflect.GeneratedMethodAccessor4.invoke(Unknown Source)

    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:256)

    at org.apache.hadoop.io.retry.RetryInvocationHandler.invoke(RetryInvocationHandler.java:104)

    at com.sun.proxy.$Proxy30.getBlockLocations(Unknown Source)

    at org.apache.hadoop.hdfs.DFSClient.callGetBlockLocations(DFSClient.java:1279)

    at org.apache.hadoop.hdfs.DFSClient.getLocatedBlocks(DFSClient.java:1266)

    at org.apache.hadoop.hdfs.DFSClient.getBlockLocations(DFSClient.java:1324)

    at org.apache.hadoop.hdfs.DistributedFileSystem$2.doCall(DistributedFileSystem.java:237)

    at org.apache.hadoop.hdfs.DistributedFileSystem$2.doCall(DistributedFileSystem.java:233)

    at org.apache.hadoop.fs.FileSystemLinkResolver.resolve(FileSystemLinkResolver.java:81)

    at org.apache.hadoop.hdfs.DistributedFileSystem.getFileBlockLocations(DistributedFileSystem.java:233)

    at org.apache.hadoop.hdfs.DistributedFileSystem.getFileBlockLocations(DistributedFileSystem.java:224)

    at org.apache.hadoop.fs.FilterFileSystem.getFileBlockLocations(FilterFileSystem.java:148)

    at org.apache.hadoop.fs.viewfs.ChRootedFileSystem.getFileBlockLocations(ChRootedFileSystem.java:211)

    at org.apache.hadoop.fs.viewfs.ViewFileSystem.getFileBlockLocations(ViewFileSystem.java:330)

    at org.apache.hadoop.fs.FileSystem$4.next(FileSystem.java:1776)

    at org.apache.hadoop.fs.FileSystem$4.next(FileSystem.java:1759)

    at org.apache.hadoop.mapred.FileInputFormat.singleThreadedListStatus(FileInputFormat.java:270)

    at org.apache.hadoop.mapred.FileInputFormat.listStatus(FileInputFormat.java:229)

    at org.apache.hadoop.mapred.SequenceFileInputFormat.listStatus(SequenceFileInputFormat.java:45)

    at org.apache.hadoop.mapred.FileInputFormat.getSplits(FileInputFormat.java:315)

    at org.apache.hadoop.hive.ql.exec.FetchOperator.getNextSplits(FetchOperator.java:372)

    at org.apache.hadoop.hive.ql.exec.FetchOperator.getRecordReader(FetchOperator.java:304)

    at org.apache.hadoop.hive.ql.exec.FetchOperator.getNextRow(FetchOperator.java:459)

    at org.apache.hadoop.hive.ql.exec.FetchOperator.pushRow(FetchOperator.java:428)

    at org.apache.hadoop.hive.ql.exec.FetchTask.fetch(FetchTask.java:147)

    at org.apache.hadoop.hive.ql.Driver.getResults(Driver.java:2213)

    at org.apache.hadoop.hive.cli.CliDriver.processLocalCmd(CliDriver.java:253)

    at org.apache.hadoop.hive.cli.CliDriver.processCmd(CliDriver.java:184)

    at org.apache.hadoop.hive.cli.CliDriver.processLine(CliDriver.java:403)

    at org.apache.hadoop.hive.cli.CliDriver.executeDriver(CliDriver.java:821)

    at org.apache.hadoop.hive.cli.CliDriver.run(CliDriver.java:759)

    at org.apache.hadoop.hive.cli.CliDriver.main(CliDriver.java:686)

观察发现mr job一共启动了30k个mapper，0个reducer。相应的，会产生30k个小文件，NameNode压力会很大。

如此发现，即使开启了hive.merge.mapfiles和hive.merge.mapredfiles（相关参考：Hive的mr作业产生很多小文件或空文件的解决方案），对于这种select的query，小文件依旧很多。

解决思路有二： 

1. 在上述语句后加order by，字段随意。这样会产生一个reducer，不会去读所有的小文件元信息。 

2. 将所有这种select语句都转换为写temporary table，这样小文件会根据上述两个参数自动合并，再从这个table里select即可。