【好好学习】SocketException: Connection reset——根因是重复认证

冷不防 2022-04-15 02:46 320阅读 0赞

**一、异常日志**

Exception in thread "main" org.apache.spark.SparkException: Job aborted due to stage failure: Task 1 in stage 73.0 failed 4 times, most recent failure: Lost task 1.3 in stage 73.0 (TID 533, HQCDDJSPTAPP144204, 3): org.apache.solr.client.solrj.impl.CloudSolrClient$RouteException: IOException occured when talking to server at: https://10.180.144.198:21116/solr/fp_exp_appl_detail_shard15_replica2
    	at org.apache.solr.client.solrj.impl.CloudSolrClient.directUpdate(CloudSolrClient.java:645)
    	at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:992)
    	at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:881)
    	at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:817)
    	at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:135)
    	at org.apache.solr.client.solrj.SolrClient.add(SolrClient.java:107)
    	at org.apache.solr.client.solrj.SolrClient.add(SolrClient.java:72)
    	at org.apache.solr.client.solrj.SolrClient.add(SolrClient.java:86)
    	at com.cpic.solr.ImportSolrProcess.writeToSolr(ImportSolrProcess.java:203)
    	at com.cpic.solr.ImportSolrProcess.ImportProcess(ImportSolrProcess.java:114)
    	at com.cpic.solr.AutoImportData$$anonfun$main$1$$anonfun$apply$mcVI$sp$3.apply(AutoImportData .scala:115)
    	at com.cpic.solr.AutoImportData$$anonfun$main$1$$anonfun$apply$mcVI$sp$3.apply(AutoImportData .scala:115)
    	at org.apache.spark.rdd.RDD$$anonfun$foreachPartition$1$$anonfun$apply$30.apply(RDD.scala:954)
    	at org.apache.spark.rdd.RDD$$anonfun$foreachPartition$1$$anonfun$apply$30.apply(RDD.scala:954)
    	at org.apache.spark.SparkContext$$anonfun$runJob$5.apply(SparkContext.scala:1892)
    	at org.apache.spark.SparkContext$$anonfun$runJob$5.apply(SparkContext.scala:1892)
    	at org.apache.spark.scheduler.ResultTask.runTask(ResultTask.scala:68)
    	at org.apache.spark.scheduler.Task.run(Task.scala:90)
    	at org.apache.spark.executor.Executor$TaskRunner.run(Executor.scala:253)
    	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    	at java.lang.Thread.run(Thread.java:745)
    Caused by: org.apache.solr.client.solrj.SolrServerException: IOException occured when talking to server at: https://10.180.144.198:21116/solr/fp_exp_appl_detail_shard15_replica2
    	at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:589)
    	at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:245)
    	at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:237)
    	at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:376)
    	at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:328)
    	at org.apache.solr.client.solrj.impl.CloudSolrClient$2.call(CloudSolrClient.java:618)
    	at org.apache.solr.client.solrj.impl.CloudSolrClient$2.call(CloudSolrClient.java:615)
    	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    	at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor$1.run(ExecutorUtil.java:212)
    	... 3 more
    Caused by: java.net.SocketException: Connection reset
    	at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:113)
    	at java.net.SocketOutputStream.write(SocketOutputStream.java:153)
    	at sun.security.ssl.OutputRecord.writeBuffer(OutputRecord.java:431)
    	at sun.security.ssl.OutputRecord.write(OutputRecord.java:417)
    	at sun.security.ssl.SSLSocketImpl.writeRecordInternal(SSLSocketImpl.java:876)
    	at sun.security.ssl.SSLSocketImpl.writeRecord(SSLSocketImpl.java:847)
    	at sun.security.ssl.AppOutputStream.write(AppOutputStream.java:123)
    	at org.apache.http.impl.io.AbstractSessionOutputBuffer.write(AbstractSessionOutputBuffer.java:181)
    	at org.apache.http.impl.io.ChunkedOutputStream.flushCacheWithAppend(ChunkedOutputStream.java:124)
    	at org.apache.http.impl.io.ChunkedOutputStream.write(ChunkedOutputStream.java:181)
    	at org.apache.http.impl.io.ChunkedOutputStream.write(ChunkedOutputStream.java:168)
    	at org.apache.http.entity.BufferedHttpEntity.writeTo(BufferedHttpEntity.java:115)
    	at org.apache.http.entity.HttpEntityWrapper.writeTo(HttpEntityWrapper.java:96)
    	at org.apache.http.impl.client.EntityEnclosingRequestWrapper$EntityWrapper.writeTo(EntityEnclosingRequestWrapper.java:112)
    	at org.apache.http.impl.entity.EntitySerializer.serialize(EntitySerializer.java:117)
    	at org.apache.http.impl.AbstractHttpClientConnection.sendRequestEntity(AbstractHttpClientConnection.java:265)
    	at org.apache.http.impl.conn.ManagedClientConnectionImpl.sendRequestEntity(ManagedClientConnectionImpl.java:216)
    	at org.apache.http.protocol.HttpRequestExecutor.doSendRequest(HttpRequestExecutor.java:237)
    	at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:122)
    	at org.apache.http.impl.client.DefaultRequestDirector.tryExecute(DefaultRequestDirector.java:686)
    	at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:488)
    	at org.apache.http.impl.client.AbstractHttpClient.doExecute(AbstractHttpClient.java:884)
    	at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82)
    	at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:107)
    	at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:55)
    	at com.huawei.solr.client.solrj.impl.InsecureHttpClient.execute(InsecureHttpClient.java:158)
    	at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:477)
    	... 11 more
    
    Driver stacktrace:
    	at org.apache.spark.scheduler.DAGScheduler.org$apache$spark$scheduler$DAGScheduler$$failJobAndIndependentStages(DAGScheduler.scala:1328)
    	at org.apache.spark.scheduler.DAGScheduler$$anonfun$abortStage$1.apply(DAGScheduler.scala:1316)
    	at org.apache.spark.scheduler.DAGScheduler$$anonfun$abortStage$1.apply(DAGScheduler.scala:1315)
    	at scala.collection.mutable.ResizableArray$class.foreach(ResizableArray.scala:59)
    	at scala.collection.mutable.ArrayBuffer.foreach(ArrayBuffer.scala:47)
    	at org.apache.spark.scheduler.DAGScheduler.abortStage(DAGScheduler.scala:1315)
    	at org.apache.spark.scheduler.DAGScheduler$$anonfun$handleTaskSetFailed$1.apply(DAGScheduler.scala:699)
    	at org.apache.spark.scheduler.DAGScheduler$$anonfun$handleTaskSetFailed$1.apply(DAGScheduler.scala:699)
    	at scala.Option.foreach(Option.scala:236)
    	at org.apache.spark.scheduler.DAGScheduler.handleTaskSetFailed(DAGScheduler.scala:699)
    	at org.apache.spark.scheduler.DAGSchedulerEventProcessLoop.doOnReceive(DAGScheduler.scala:1543)
    	at org.apache.spark.scheduler.DAGSchedulerEventProcessLoop.onReceive(DAGScheduler.scala:1505)
    	at org.apache.spark.scheduler.DAGSchedulerEventProcessLoop.onReceive(DAGScheduler.scala:1492)
    	at org.apache.spark.util.EventLoop$$anon$1.run(EventLoop.scala:72)
    	at org.apache.spark.scheduler.DAGScheduler.runJob(DAGScheduler.scala:569)
    	at org.apache.spark.SparkContext.runJob(SparkContext.scala:1866)
    	at org.apache.spark.SparkContext.runJob(SparkContext.scala:1879)
    	at org.apache.spark.SparkContext.runJob(SparkContext.scala:1892)
    	at org.apache.spark.SparkContext.runJob(SparkContext.scala:1963)
    	at org.apache.spark.rdd.RDD$$anonfun$foreachPartition$1.apply(RDD.scala:954)
    	at org.apache.spark.rdd.RDD$$anonfun$foreachPartition$1.apply(RDD.scala:952)
    	at org.apache.spark.rdd.RDDOperationScope$.withScope(RDDOperationScope.scala:147)
    	at org.apache.spark.rdd.RDDOperationScope$.withScope(RDDOperationScope.scala:108)
    	at org.apache.spark.rdd.RDD.withScope(RDD.scala:344)
    	at org.apache.spark.rdd.RDD.foreachPartition(RDD.scala:952)
    	at com.cpic.solr.AutoImportData$$anonfun$main$1.apply$mcVI$sp(AutoImportData .scala:115)
    	at scala.collection.immutable.Range.foreach$mVc$sp(Range.scala:141)
    	at com.cpic.solr.AutoImportData$.main(AutoImportData .scala:71)
    	at com.cpic.solr.AutoImportData.main(AutoImportData .scala)
    	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.spark.deploy.SparkSubmit$.org$apache$spark$deploy$SparkSubmit$$runMain(SparkSubmit.scala:764)
    	at org.apache.spark.deploy.SparkSubmit$.doRunMain$1(SparkSubmit.scala:183)
    	at org.apache.spark.deploy.SparkSubmit$.submit(SparkSubmit.scala:208)
    	at org.apache.spark.deploy.SparkSubmit$.main(SparkSubmit.scala:123)
    	at org.apache.spark.deploy.SparkSubmit.main(SparkSubmit.scala)
    Failure

**二、问题分析**

1.  客户称是Spark往Solr写入数据报错。
2.  异常并不是来自Solr代码，而是比较底层，java.net.SocketException: Connection reset这个异常。
3.  java.net.SocketException: （Connection reset或者Connect reset by peer: Socket write error。该异常在客户端和服务器端均有可能发生，引起该异常的原因有两个，第一个原因是如果一端的Socket被关闭（或主动关闭或者因为异常退出而引起的关闭），另一端仍发送数据，发送的第一个数据包引发该异常(Connect reset by peer)。另一个原因是一端退出，但退出时并未关闭该连接，另一端如果在从连接中读数据则抛出该异常（Connection reset）。
4.  简单说，就是在连接断开后，读和写操作引起的异常。

**三、定位过程**

1.  Socket连接已经建立，但是却被reset。hummm…
2.  查看gc日志，发现CMS GC频率和时间比较正常，排除GC带来的Stop the world的影响；
3.  用netstat -an命令可以看到所有的TCP连接信息，查看和目标机器的连接是否过多，连接是否存在多人使用误关闭的现象；
4.  查看Solr组件的日志发现大量的鉴权失败的信息。
5.  所以根本原因是客户端重用了鉴权用到的token，类似于放到一个token池去管理，可能某个线程取到了快超期的token，就会导致该线程鉴权失败。
6.  非常失败的设计，鉴定完毕。  
    ![大量鉴权失败信息][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3dlaXhpbl80MjI1NzI1MA_size_16_color_FFFFFF_t_70]

**四、总结提升**

1.  一开始就应该看Solr组件的日志啊，蛛丝马迹不能放过！
2.  鉴权的设计很重要，要考虑安全性，还要兼顾性能。
3.  回顾了TCP三次握手，学习了底层的SocketException的几种异常排查思路。

**Reference**  
[https://www.jb51.net/article/34888.htm][https_www.jb51.net_article_34888.htm]  
[https://my.oschina.net/xionghui/blog/508758][https_my.oschina.net_xionghui_blog_508758]  
[https://blog.csdn.net/qiubt\_\_123/article/details/50432834][https_blog.csdn.net_qiubt_123_article_details_50432834]  
[https://blog.csdn.net/u010419967/article/details/24797645][https_blog.csdn.net_u010419967_article_details_24797645]  
[https://blog.csdn.net/u013766398/article/details/51381852][https_blog.csdn.net_u013766398_article_details_51381852]  
[https://blog.csdn.net/dengweijunkedafu/article/details/10186869][https_blog.csdn.net_dengweijunkedafu_article_details_10186869]  
[https://blog.csdn.net/Vincents\_Vincents/article/details/77502068][https_blog.csdn.net_Vincents_Vincents_article_details_77502068]

[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3dlaXhpbl80MjI1NzI1MA_size_16_color_FFFFFF_t_70]: /images/20220415/aadab69dc22f41ab846ef0468c9d8ddb.png
[https_www.jb51.net_article_34888.htm]: https://www.jb51.net/article/34888.htm
[https_my.oschina.net_xionghui_blog_508758]: https://my.oschina.net/xionghui/blog/508758
[https_blog.csdn.net_qiubt_123_article_details_50432834]: https://blog.csdn.net/qiubt__123/article/details/50432834
[https_blog.csdn.net_u010419967_article_details_24797645]: https://blog.csdn.net/u010419967/article/details/24797645
[https_blog.csdn.net_u013766398_article_details_51381852]: https://blog.csdn.net/u013766398/article/details/51381852
[https_blog.csdn.net_dengweijunkedafu_article_details_10186869]: https://blog.csdn.net/dengweijunkedafu/article/details/10186869
[https_blog.csdn.net_Vincents_Vincents_article_details_77502068]: https://blog.csdn.net/Vincents_Vincents/article/details/77502068