commons-logging源码学习

commons-logging是一个流行的logging统一接口,代码非常简单,具体的logging可以使用不同的实现,如log4j,jdk log等,即使没有这些,它还是能在控制台上输出,它可以帮你选择一种合适的logging实现。

commons-logging有LogFactory和Log两个主要接口,LogFactory实现了如何找到合适的Log,而Log是一个标准的logging接口。

LogFactory是一个抽象类,它的具体实现通过以下顺序确定:

  1. 系统属性org.apache.commons.logging.LogFactory
  2. META-INF/services/org.apache.commons.logging.LogFactory
  3. commons-logging.properties的org.apache.commons.logging.LogFactory
  4. org.apache.commons.logging.impl.LogFactoryImpl

基本上,都会是LogFactoryImpl这个实现。

另外,commons-logging可以采用SPI指定LogFactory实现,不过commons-logging并没有使用标准的ServiceLoader来处理,可能是由于commons-logging要兼容老的java版本吧。

还有,commons-logging.properties是支持重新加载的,按道理classpath加载资源是有缓存的, 见LogFactory中的getProperties,它不是直接使用getResourceAsStream,而是采用getResources/getResource,对得到的URL进行openConnection得到URLConnection对象,对它设置setUseCache为false,这的确是个小技巧。

对于Log实现,如果没有通过commons-logging.properties的的org.apache.commons.logging.Log这个key指定的话,是按照下面的方式尝试获取的:

  1. org.apache.commons.logging.impl.Log4JLogger
  2. org.apache.commons.logging.impl.Jdk14Logger
  3. org.apache.commons.logging.impl.Jdk13LumberjackLogger
  4. org.apache.commons.logging.impl.SimpleLog

很明显,只要有log4j的jar包就会选择log4j,否则就会选择jdk logging或者System.err。

所以正常情况下,不需要设置这个commons-logging.properties里边的org.apache.commons.logging.Log对应的属性值(其实这个配置文件都是不需要的)。

曾经就有项目,依赖一个自己写的jar包,就把commons-logging.properties打包进去,里边配置成SimpleLog,导致很多框架的日志不能输出到log4j指定的文件中去。

svn报文转发出现handshake_failure的问题

问题描述

昨天svn报文转发xx程序突然出现连不上svn的情况,报错信息如下:

org.tmatesoft.svn.core.SVNException: svn: E175002: Connection has been shutdown: javax.net.ssl.SSLHandshakeException: Received fatal alert: handshake_failure
svn: E175002: OPTIONS request failed on '/XXXX'
	at org.tmatesoft.svn.core.internal.wc.SVNErrorManager.error(SVNErrorManager.java:106)
	at org.tmatesoft.svn.core.internal.wc.SVNErrorManager.error(SVNErrorManager.java:90)
	at org.tmatesoft.svn.core.internal.io.dav.http.HTTPConnection.request(HTTPConnection.java:798)
	at org.tmatesoft.svn.core.internal.io.dav.http.HTTPConnection.request(HTTPConnection.java:398)
	at org.tmatesoft.svn.core.internal.io.dav.http.HTTPConnection.request(HTTPConnection.java:386)
	at org.tmatesoft.svn.core.internal.io.dav.DAVConnection.performHttpRequest(DAVConnection.java:863)
	at org.tmatesoft.svn.core.internal.io.dav.DAVConnection.exchangeCapabilities(DAVConnection.java:699)
	at org.tmatesoft.svn.core.internal.io.dav.DAVConnection.open(DAVConnection.java:118)
	at org.tmatesoft.svn.core.internal.io.dav.DAVRepository.openConnection(DAVRepository.java:1049)
	at org.tmatesoft.svn.core.internal.io.dav.DAVRepository.testConnection(DAVRepository.java:100)
	...
	at java.lang.Thread.run(Thread.java:744)
Caused by: javax.net.ssl.SSLException: Connection has been shutdown: javax.net.ssl.SSLHandshakeException: Received fatal alert: handshake_failure
	at sun.security.ssl.SSLSocketImpl.checkEOF(SSLSocketImpl.java:1476)
	at sun.security.ssl.SSLSocketImpl.checkWrite(SSLSocketImpl.java:1488)
	at sun.security.ssl.AppOutputStream.write(AppOutputStream.java:70)
	at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82)
	at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:140)
	at org.tmatesoft.svn.core.internal.io.dav.http.HTTPConnection.sendData(HTTPConnection.java:340)
	at org.tmatesoft.svn.core.internal.io.dav.http.HTTPRequest.dispatch(HTTPRequest.java:170)
	at org.tmatesoft.svn.core.internal.io.dav.http.HTTPConnection.request(HTTPConnection.java:497)
	... 14 more

初步检查

  • 检查了svn用户名密码是正常的
  • 检查了代码也没有变化,java版本也没有变更
  • 初步怀疑是svn服务器做了配置更新,禁用了某些东西,由于是https,尝试开启debug信息看看

调试过程

通过设置vm参数javax.net.debug=all开启网络相关的全部调试信息,可以看到:

*** ClientHello, SSLv3
RandomCookie:  GMT: 1460716796 bytes = { 214, 15, 157, 159, 83, 144, 248, 115, 164, 210, 12, 247, 143, 96, 117, 244, 202, 251, 111, 187, 109, 171, 81, 216, 101, 89, 33, 240 }
Session ID:  {}
Cipher Suites: [TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA, TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA, TLS_RSA_WITH_AES_128_CBC_SHA, TLS_ECDH_ECDSA_WITH_AES_128_CBC_SHA, TLS_ECDH_RSA_WITH_AES_128_CBC_SHA, TLS_DHE_RSA_WITH_AES_128_CBC_SHA, TLS_DHE_DSS_WITH_AES_128_CBC_SHA, TLS_ECDHE_ECDSA_WITH_RC4_128_SHA, TLS_ECDHE_RSA_WITH_RC4_128_SHA, SSL_RSA_WITH_RC4_128_SHA, TLS_ECDH_ECDSA_WITH_RC4_128_SHA, TLS_ECDH_RSA_WITH_RC4_128_SHA, TLS_ECDHE_ECDSA_WITH_3DES_EDE_CBC_SHA, TLS_ECDHE_RSA_WITH_3DES_EDE_CBC_SHA, SSL_RSA_WITH_3DES_EDE_CBC_SHA, TLS_ECDH_ECDSA_WITH_3DES_EDE_CBC_SHA, TLS_ECDH_RSA_WITH_3DES_EDE_CBC_SHA, SSL_DHE_RSA_WITH_3DES_EDE_CBC_SHA, SSL_DHE_DSS_WITH_3DES_EDE_CBC_SHA, SSL_RSA_WITH_RC4_128_MD5, TLS_EMPTY_RENEGOTIATION_INFO_SCSV]
Compression Methods:  { 0 }
Extension elliptic_curves, curve names: {secp256r1, sect163k1, sect163r2, secp192r1, secp224r1, sect233k1, sect233r1, sect283k1, sect283r1, secp384r1, sect409k1, sect409r1, secp521r1, sect571k1, sect571r1, secp160k1, secp160r1, secp160r2, sect163r1, secp192k1, sect193r1, sect193r2, secp224k1, sect239k1, secp256k1}
Extension ec_point_formats, formats: [uncompressed]
***
[write] MD5 and SHA1 hashes:  len = 149
0000: 01 00 00 91 03 00 57 11   C5 FC D6 0F 9D 9F 53 90  ......W.......S.
0010: F8 73 A4 D2 0C F7 8F 60   75 F4 CA FB 6F BB 6D AB  .s.....`u...o.m.
0020: 51 D8 65 59 21 F0 00 00   2A C0 09 C0 13 00 2F C0  Q.eY!...*...../.
0030: 04 C0 0E 00 33 00 32 C0   07 C0 11 00 05 C0 02 C0  ....3.2.........
0040: 0C C0 08 C0 12 00 0A C0   03 C0 0D 00 16 00 13 00  ................
0050: 04 00 FF 01 00 00 3E 00   0A 00 34 00 32 00 17 00  ......>...4.2...
0060: 01 00 03 00 13 00 15 00   06 00 07 00 09 00 0A 00  ................
0070: 18 00 0B 00 0C 00 19 00   0D 00 0E 00 0F 00 10 00  ................
0080: 11 00 02 00 12 00 04 00   05 00 14 00 08 00 16 00  ................
0090: 0B 00 02 01 00                                     .....
Thread-0, WRITE: SSLv3 Handshake, length = 149
[Raw write]: length = 154
0000: 16 03 00 00 95 01 00 00   91 03 00 57 11 C5 FC D6  ...........W....
0010: 0F 9D 9F 53 90 F8 73 A4   D2 0C F7 8F 60 75 F4 CA  ...S..s.....`u..
0020: FB 6F BB 6D AB 51 D8 65   59 21 F0 00 00 2A C0 09  .o.m.Q.eY!...*..
0030: C0 13 00 2F C0 04 C0 0E   00 33 00 32 C0 07 C0 11  .../.....3.2....
0040: 00 05 C0 02 C0 0C C0 08   C0 12 00 0A C0 03 C0 0D  ................
0050: 00 16 00 13 00 04 00 FF   01 00 00 3E 00 0A 00 34  ...........>...4
0060: 00 32 00 17 00 01 00 03   00 13 00 15 00 06 00 07  .2..............
0070: 00 09 00 0A 00 18 00 0B   00 0C 00 19 00 0D 00 0E  ................
0080: 00 0F 00 10 00 11 00 02   00 12 00 04 00 05 00 14  ................
0090: 00 08 00 16 00 0B 00 02   01 00                    ..........
[Raw read]: length = 5
0000: 15 03 00 00 02                                     .....
[Raw read]: length = 2
0000: 02 28                                              .(
Thread-0, READ: SSLv3 Alert, length = 2
Thread-0, RECV TLSv1 ALERT:  fatal, handshake_failure

和提示信息描述的一样,是在SSL握手阶段就失败了,采用的协议是SSLv3。估计是这个协议被svn服务器禁用了。
尝试配置成TLSv1,发现可以正常访问。

最终处理方式

由于原来的协议配置是在代码写死的,现在调整代码修改成在配置文件形式,见xxx.properties, 修改部分如下所示。
和原来一样,如果需要修改,可以在xxx-user.properties进行覆盖。

# 系统属性,通过System.setProperty设置,不清楚具体含义请不要随意修改
# 调试时可以设置为all,否则设置为none
javax.net.debug=none
https.protocols=SSLv2Hello,SSLv3,TLSv1
svnkit.http.sslProtocols=SSLv2Hello,SSLv3,TLSv1
jsse.enableSNIExtension=false

或许以后用得着的内容:

  • 调试网络信息,可以考虑javax.net.debug这个参数,它的值有很多选择,可以查阅相关材料
  • svnkit的协议配置是通过svnkit.http.sslProtocols这个参数指定的
  • 有空了解一下HTTPS/SSL的基本原理和过程

heapdump分析简单总结

  • 详细的材料可以查看IBM的HeapAnalyzer胶片
  • 本文只是自己的一些简单总结(废话比较多),重点还是大家基于实际dump文件去积累经验
  • 就一个工具,大家都掌握好了就可以有更多时间研究其他东西。

heapdump是什么

  • 通常的名字类似heapdump.20150919.162323.43385076.0055.phd,参考ppt的第12页
  • java堆内存快照(不包括jni,不是c/c++通常说的那个堆)
  • 用来分析oom的原因

heapdump如何生成

  • 参考ppt的第8~12页,通常维护/CMO都知道
  • 需要注意的是,大型中间件的dump是挺大的,需要有足够的硬盘空间,否则频繁的dump会导致空间不足引发其他问题。(频繁dump在生产上是可能的事情)

heapdump分析用什么工具

  • 使用IBM HeapAnalyzer(目前最新ha456.jar, 比之前的版本有更多视图,性能更好)
  • 启动方式: java -jar -Xms512m -Xmx3g ha456.jar
  • 通常要文件大小5倍+的内存, 而websphere之类的dump多在500m以上,所以需要64位的大内存机器,用64位的jdk,堆内存开2g以上
  • 工具需要界面,如果大内存64位机器如果只能找到服务器,可以采用远程运行(但受网速影响)。参考”export DISPLAY=192.168.88.71:0.0”设置xmanager的远程界面显示

ha概念要点

  • 本质上是根据对象引用关系生成一个树结构(可以结合gc的原理加深理解),参考ppt的第14页
  • 结合图例说明

图例说明

ha关注要点

  • 关注Leak Suspect,这是检测出来的可能的问题点,有时候非常方便。参考ppt的第34~37页
  • 关注内存占用比例较大的对象,ha支持按TotalSize大小顺序排列(如上图)
  • 关注节点数众多的情况,而且基本上是挂靠在容器上的(不大可能一个对象有n多内部变量),常见的有map,array,list
  • 关注自己的类,com.huawei开头的。ha支持查询,参考ppt的第54~59页。
  • 有多种维度的视图,多摸索,例如Type List就可以根据特定类型的对象数量进行排序,或许可以找到一些小的内存问题。
  • 如果能够拿到javacore,可以进行对比,定位是哪个功能引起的(单靠类名不一定能够识别哪个业务)。

常见的原因

常见的问题原因如下(有交集,并没有严格分类):

  • 内存设置太低,不过这个几率比较小。一般的web应用内存分配2G还不够,调大也不是办法。
  • 大量的线程泄露(或者某种原因阻塞),java的线程是系统线程,占用的资源还是可观的,相关的可以看Xss参数。生产一般看到的websphere也就300左右。
  • 查询/导出大量数据, 常见于SQL查询结果没有限制数量、或者在内存中集中写出。
  • 远程调用传输大量数据,常见于cics返回大量数据(其实和上面差不多是一个道理)
  • 上传并处理数据,没有分批分段处理或延后处理。
  • 数据没能及时释放,可能是处理较多的数据或较长的处理流程,不过需要显式释放对象引用的情况是比较少见的。

不过,需要注意的是:

  • 像dbc这样的jni实现可能和这个没什么关系,原因在于64位机器进程空间很大。
  • 像数据库,远程调用等响应慢,是不一定会出现dump问题的。但它会导致线程数增多(同步),数据(占用内存)未及时处理,从而导致dump。

源码阅读应该得到什么?

我们平时会接触到不少开源项目, 很多人都期望能够通过阅读源码理解更多东西,把从中学到的东西用于平时的框架使用,设计和编码实现过程。

不过,浩瀚的代码量,应该关注什么? 作为一个屌丝程序员,分享一下屌丝经验:

  1. 首先,你应该有一定的使用经验。从使用中,去找相关特性是如何实现的。
  2. 最好阅读一下官方文档,了解使用的场景,高层设计、特性介绍。做到心中有数。
  3. 关于设计模式。提前学习一下还是有用的,学习源码的时候就不用揪着设计模式不放,会崩溃的。
  4. 同上,很多源码书会画很庞大的类图,时序图等。这些看上去很高大上,然并卯。
  5. 还是要带的问题去跟踪,一次跟踪一小部分,就是一次要有一个关注点,集中分析。别走马观花。
  6. 建议使用maven等高大上工具关联源码,应该多调试调试,但是单步调试帮助不大。
  7. 同上,应该提高代码”猜想”能力,大步调试过去,验证自己的猜测。
  8. linus说: 烂程序员关心的是代码。好程序员关心的是数据结构和它们之间的关系。
  9. 多补充理论知识。虽然很花时间。
  10. 凑数的,找个感兴趣的开始吧。

上面废话很多,下面来个事例。

commons httpclinet 3.x 这是一个很超好用的库,实际上也是比较容易理解的。

我阅读的时候,列了一下自己的关注点或者问题列表。

  • 如何打开HttpClient库的详细日志
  • httpclient默认参数有哪些?如User Agent、Charset怎么进行定制?
  • httpclient的连接是怎样管理的? 内部是连接池还是什么? HttpClient能用于多线程环境么?如何应用?
  • 关于MultiThreadedHttpConnectionManager的数据结构是怎样的?
  • uri和content中的字符编码是怎么处理的? 例如像处理带中文的路径。
  • HttpClient#executeMethod实现细节,为什么hostconfig要克隆一份?为什么不能直接设置?
          if (hostconfig == defaulthostconfig || uri.isAbsoluteURI()) {
              // make a deep copy of the host defaults
              hostconfig = (HostConfiguration) hostconfig.clone();
              if (uri.isAbsoluteURI()) {
                  hostconfig.setHost(uri);
              }
          }
    
  • HttpClient、HttpMethod(GetMethod、PostMethod)、HostConfiguration、HttpConnectionManager、HttpClientParams、HttpConnection、HttpState、AuthChallengeProcessor主要负责什么?
  • 命令行参数、HttpClient、HttpMethod、HostConfiguration都可以设置params,有区别? 参数在框架中是怎样存储的?
          HttpClient httpClient = new HttpClient();
          httpClient.getParams().setConnectionManagerTimeout(30000L);
          httpClient.getHostConfiguration().getParams().setLongParameter(
                  HttpClientParams.CONNECTION_MANAGER_TIMEOUT, 30000L);
          GetMethod post = new GetMethod("http://10.132.10.59:4567");
          post.getParams().setHttpElementCharset("UTF-8");
    
  • HttpClient会自动处理请求跳转? 会不会出现死循环? 怎样的响应才会自动跳转? 如何关闭这个特性
  • HttpClient的自动重试功能是怎样? 怎么进行定制?
  • HttpClient是使用java自带的HttpUrlConnection实现的么? 报文是怎么组装和解析的?
  • 连接超时、读取超时、读写缓冲区、还有禁用Nagle等常见属性如何设置?
  • 多次调用之间的cookie怎么管理的?
  • chunked模式是怎么实现的? 多大刷一次?

大家可以参考这个,在阅读的时候,列出问题列表,然后从源码中找找答案。

细节是魔鬼:)

========================华丽的分割线========================

关于第8点,以MultiThreadedHttpConnectionManager为例,如何分析数据结构? (昨晚分析的,时间有限,不保证正确性)

从本质来说,整个链接管理的结构是:

维护一个connectionPool, 内部维护一个mapHosts,它的结构是Map<HostConfiguration, HostConnectionPool>
HostConnectionPool的内部结构是两个链表,freeConnections维护空闲连接,waitingThreads维护正在等待连接的线程

还有一个静态的ReferenceQueue和ReferenceQueueThread,用来实现防止某些连接丢失的情况。至于是怎么做到丢失的连接能够回到ReferenceQueue,就是通过对HttpConnection进行加强得到的。

实际上通过管理器得到的HttpConnection是经过层层代理的。层次是这样的: HttpConnectionAdapter - HttpConnectionWithReference - HttpConnection
HttpConnectionWithReference就是通过一个WeakReference关联到ReferenceQueue,这样根据弱引用特性,一定可被回收就会进入ReferenceQueue从而被线程扫描到。

为了实现闲时连接关闭的功能,使用了IdleConnectionHandler,它的内部结构是有个Map记录空闲连接(在releaseConnection的时候放入)和当时的时间。

代码就是围绕这些核心数据结构进行操作的。通过上面的基本结构,就可以实现以下特性:

  1. 总连接数和每主机总连接数限制。连接数默认50,每host默认2连接(经常容易忽略,通常需要定制)
  2. 能够防止连接丢失。如上面所说,拿出去的HttpConnection是加强过的,会关联到一个静态的ReferenceQueue,并使用一个线程ReferenceQueueThread不停监听并回收。
  3. 实现了获取连接的超时限制。就是通过waitingThreads实现的。当找不到空闲连接的时候就添加进去,然后wait。如果有releaseConnection的时候,就会interupt等待的第一个线程。我个人认为线程有可能被interupt之后仍然占用不到连接,从而排到最后去,真是悲剧。
  4. 能够支持连接闲时关闭。这个默认是需要主动触发,通过IdleConnectionHandler比较时间来实现的。

最后,这个类是支持多线程的,主要是使用了同步机制,锁定ConnectionPool对象实现的。
另外,HttpConnection对象实际上并不是一个正式的连接,要open之后才会真的建立连接。
实际上也是一个lazy代理对象,可以避免整个连接管理操作不被阻塞,只有到实际操作时open的时候才连接。

========================华丽的分割线========================

关于第9点,以commons-httpclient为例,这当中涉及到哪些理论基础呢? 简单列举一下:

  1. java弱引用、克隆特性
  2. 线程协调、中断机制
  3. 网络编码、http协议
  4. tcp相关参数的含义
  5. 常见对象池化技术

从commons-dbcp源码学习设计思路

由于整个连接池的性能是由commons-pool决定的,有空再讲解一下commons-pool的实现,特别是1.x和2.x的区别。
此次分析的是commons-dbcp 1.x源码,对应commons-pool 1.x版本。

commons-dbcp怎样与commons-pool集成?

commons-dbcp怎样与commons-pool集成

如上图所示,集成commons-dbcp的时候采用BasicDataSource这个实现类,它的实际功能是交给PoolingDataSource的(内部是通过commons-pool来管理连接对象)。
不过,我不是很理解为什么要这么设计?

commons-dbcp的连接有什么特别?

commons-dbcp的连接有什么特别

连接这种对象有点特殊的,所以commons-dbcp提供了一些connection方面的增强特性。例如:

  • PoolGuardConnectionWrapper是最终客户端拿到的对象,能够防止多次关闭等误操作
  • PoolableConnection是PoolGuardConnectionWrapper内部的对象,可以结合pool进行管理,最大的优势就是可以保留客户端代码无需任何改动。实际上,很多自带生命周期api的对象,一旦池化之后都会考虑这么设计。
  • PoolingConnection是开启statement pool的时候PoolableConnection的内部对象,内部采用一个KeyedObjectPool进行管理(key主要是通过执行的sql语句来生成的)。不过这种对象一般不需要池化

如何优化Connection、Statement、ResultSet的生命周期管理?

jdbc的api有个非常烦人的地方,就是每个Connection、Statement、ResultSet对象都是需要关闭。所以写起来代码繁琐的,很多人就跳过这些健壮性代码。
我研究了一下dbcp的实现,发现它能够发现未关闭的Statement、ResultSet对象,并在适当的时候进行关闭。

如何优化生命周期管理

具体实现思路是这样的:

  • 需要实现生命周期管理的对象需要继承AbandonedTrace,这包括了DelegatingStatement、DelegatingResultSet、DelegatingConnection等
  • 通过DelegatingConnection生成的statement、resultset等都是带Delegating的,也就是带trace特性的。
  • 对于上图,有个特别的是DelegatingConnection的trace可能包括ResultSet,这个主要由DelegatingDatabaseMetaData产生的。因为metadata的查询不需要先有statement。
  • 处理流程调用connection.close(), 会返回到池中(见PoolableConnection), 触发PoolableConnectionFactory的passivateObject(commons-pool的内置回调),最后触发DelegatingConnection的passivate,在这里会递归检查所有的trace。
  • 注意的是,DelegatingConnection的close方法除了触发trace对象的关闭,还会关闭底层的连接对象。