生产环境典型问题实录第一期

生产环境典型问题实录第一期

列夫·托尔斯泰曰：幸福的家庭都是相似的，不幸的家庭则各有不同。这句话放在软件开发上也同样适用，闻往古，天下之美同，好的程序都是相似的，不好的程序则各有不同。好的程序要考虑健壮性、可用性、高性能、安全性、可扩展性、可维护性, 噫吁嚱，危乎高哉！我们虽无法穷举出引起软件问题的所有场景，但也能看到，一些问题在不断地重复发生。前人不暇自哀，而后人哀之；后人哀之而不鉴之，亦使后人而复哀后人也。前事不忘，后事之师，为使后人有所鉴，我们总结了一些生产环境的典型问题，目前已经有四五十条了（包括非程序性问题），希望对大家能有所借鉴。

案例一：java.net.SocketException: Connection reset

某地应用程序调用第三方公司接口经常报网络错误，报错率为90%。一般遇到SocketException这类错误，大概率是防火墙或者网络策略导致，Connection reset是tcp连接被重置，程序无法自行恢复解决，需要排查防火墙以及网络情况。现场排查后未找到具体原因，后续更改接口地址后问题不再复现。

网络问题的排查思路，公司内部可在ADC上搜索徐兴院发的贴子，内容很详实。

案例二：okhttp3 InterruptedIOException: interrupted

现场在使用okhttp的get请求时，偶发性的会报出InterruptedIOException: interrupted异常。

Caused by: java.io.InterruptedIOException: interrupted
	at okio.Timeout.throwIfReached(Timeout.kt:98) ~[okio-2.7.0.jar:na]
	at okio.OutputStreamSink.write(JvmOkio.kt:50) ~[okio-2.7.0.jar:na]
	at okio.AsyncTimeout$sink$1.write(AsyncTimeout.kt:103) ~[okio-2.7.0.jar:na]
	at okio.RealBufferedSink.flush(RealBufferedSink.kt:247) ~[okio-2.7.0.jar:na]
	at okhttp3.internal.http1.Http1ExchangeCodec.finishRequest(Http1ExchangeCodec.kt:155) ~[okhttp-4.8.1.jar:na]

而使用别的http方式，如curl等调用则没有相关问题，此问题应该是okhttp内部机制导致，并发网络本身问题。
okhttp报的错是 java.io.InterruptedIOException: interrupted 看了一下对应源码，找到响应代码，是okhttp的线程被interrupt了。
[外链图片转存失败,源站可能有防盗链机制,建议将图片保存下来直接上传(img-emgd9NOX-1648197304531)(https://bed.cdpt.pro/ibed/2022/03/13/EFUbHr8Gv.png)]

所以下一步排查方向应该是分析okhttp源码，找到Thread interrupted的原因。分析了业务系统代码以及okhttp的源码，也没能定位到具体原因，但是发现系统中还使用了webflux和reactor框架。网上没有找到reactor与okhttp配合使用相关的问题，不过找到有RxJava与okhttp使用时导致interrupted的issue.
[外链图片转存失败,源站可能有防盗链机制,建议将图片保存下来直接上传(img-eyGD7N7p-1648197304536)(https://bed.cdpt.pro/ibed/2022/03/13/EFUbHrpA1.png)]

此系统本身使用springMVC即能满足业务需要，但是却用到了更复杂的webflux和reactor框架，加上团队内对于这类框架的积累较少，属于典型的过度设计。后续仍没有找到interrupted的原因，加上reactor框架在一些国产化应用中间件（东方通）上无法正常运行，项目组决定去掉webflux和reactor,改为springMVC,问题解决。

案例三：spring不当使用，触发死锁

• 发现人：王一
  项目启动时无法正常启动，导出线程信息发现有死锁。

Found one Java-level deadlock:
=============================
"arterySchedule_Worker-10":
  waiting to lock monitor 0x000000005b0166b8 (object 0x0000000081754d88, a java.util.concurrent.ConcurrentHashMap),
  which is held by "arteryScheduleStarter"
"arteryScheduleStarter":
  waiting to lock monitor 0x000000005b0164a8 (object 0x00000000817553a8, a java.util.concurrent.ConcurrentHashMap),
  which is held by "localhost-startStop-1"
"localhost-startStop-1":
  waiting to lock monitor 0x000000005b0166b8 (object 0x0000000081754d88, a java.util.concurrent.ConcurrentHashMap),
  which is held by "arteryScheduleStarter"
  
"arteryScheduleStarter":
	at org.springframework.beans.factory.support.DefaultListableBeanFactory.getBeanDefinitionNames(DefaultListableBeanFactory.java:192)
	- waiting to lock <0x00000000817553a8> (a java.util.concurrent.ConcurrentHashMap)
	at org.springframework.beans.factory.support.DefaultListableBeanFactory.getBeanNamesForType(DefaultListableBeanFactory.java:209)
	
"localhost-startStop-1":
	at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:180)
	- waiting to lock <0x0000000081754d88> (a java.util.concurrent.ConcurrentHashMap)
	at org.springframework.beans.factory.support.AbstractBeanFactory.isFactoryBean(AbstractBeanFactory.java:747)
	at org.springframework.beans.factory.support.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:422)	

死锁的特点和原因不再赘述，Spring初始化出现死锁，一定是程序内部有使用到ApplicationContext.getBean这类静态获取bean导致的。

• 为什么DefaultSingletonBeanRegistry.getSingleton要加锁？DefaultSingletonBeanRegistry.getSingleton如果不上锁就可能会出现两个线程同时进到getSingleton方法去初始化，虽然最后初始化后的bean放到singletonObjects时，后一个会覆盖前一个，但是初始化两也是不允许的情况，而且可能出现A这个bean依赖的singleton和B依赖的不是同一个。 这个不仅有死锁问题，也有性能问题，因为beanA和beanB它俩并不冲突，是不是可以把锁粒度拆小一点。这个spring官方在讨论，参见
  • https://github.com/spring-projects/spring-framework/issues/13117
  • https://github.com/spring-projects/spring-framework/issues/25667
• DefaultListableBeanFactory.getBeanDefinitionNames应该没必要加锁，我看了一下spring2.5.6和spring4.2.3的代码，4.2.3已经不加锁了。

	public String[] getBeanDefinitionNames() {
		if (this.frozenBeanDefinitionNames != null) {
			return this.frozenBeanDefinitionNames;
		}
		else {
			return StringUtils.toStringArray(this.beanDefinitionNames);
		}
	}

"qtp1865707812-282068" - Thread t@282068
   java.lang.Thread.State: BLOCKED
	at org.springframework.context.support.AbstractRefreshableApplicationContext.getBeanFactory(AbstractRefreshableApplicationContext.java:151)
	- waiting to lock <3920780> (a java.lang.Object) owned by "qtp1865707812-3209" t@3209
	at org.springframework.context.support.AbstractApplicationContext.getBean(AbstractApplicationContext.java:880)

ApplicationContext.getBean这种方法一定要慎用，由这个引起的问题，我见过的都不少。

• spring框架无法识别依赖关系，可能出现调用时获取bean为null的情况。
• 性能问题,里面都是synchonzied的方法，大量频繁调用会造成系统卡顿。
• 死锁，如本案例。
• applicationContext.getBeansOfType是O(n)复杂度，其内部是遍历应用中全部的bean,再看其是否instanceof传入的type,这个在真实项目中也出现过性能问题。

案例四：误用InputStream.available

if(inputstream.available() == 0){
    logger.error("下载的文件内容为空");
    return resultMap;
}

• 逻辑描述：如果流的avaliable为0，则代表其文件不存在。
• 问题：InputStream.avaliable并不代表真真实的输入流的字节大小，它只是表示现在可读的字节有多少。如果是FileInputStream的话，available的实验结果与文件大小是一致的，但是其方法注释上仍写的是an estimate of the number of remaining bytes that can be read，如果是网络流的话，经过验证其available值与文件大小不一致。官方文档如下：

Returns an estimate of the number of bytes that can be read (or skipped over) from this input stream without blocking by the next invocation of a method for this input stream. The next invocation might be the same thread or another thread. A single read or skip of this many bytes will not block, but may read or skip fewer bytes.

案例五 文书彩打，签章是黑的

• 发现人：郝正彬
• 现场文书彩打，签章是黑色的。排查了好久程序没找到原因，后来发现是当地温度太低，彩色打印机墨盒冻住了，把空调打开就好了。