程序为基于Tomcat的WEB应用,在并发请求很少的情况下,程序运行正常,而当并发请求较多(70~300/30秒)时,WEB应用的页面几乎无法访问,通常需要刷新多次才可能成功访问一次。
通过Tomcat的status页面,可以发现Tomcat 当前线程数已达配置文件中设定的最大值(800个https,200个http),并且当前所有线程均处于忙碌状态,大部分线程的生存期比较长,最长的可达20分钟。
观察数据库连接池,数据库连接数量已达配置文件设定最大值,但繁忙的数据库连接并不多,大部分处于空闲状态。
二、调试与跟踪面临的问题
多线程程序相对于单线程程序在跟踪和调试方面要麻烦许多,特别是在当众多线程启动时才会发生的BUG,期望通过IDE进行调试是不可能完成的任务。此时,记录log是最容易想到的跟踪方式。
但是在多线程中记录log面临的问题是由于线程众多,记录的log是也是由线程混杂生成的,因而很难从中抽取出一个线程的执行log进行分析。但是,要有效地分析线程运行情况,必须从繁杂的线程中抽取出一个线程的执行log。
显然,如果每一条log能够有当前线程(更确切地说,是针对当前请求的响应)的惟一标识,那么抽取一个线程就成为可能。
三、日志记录解决方案
要在log中标识惟一线程,很容易想到的方式是在记录log时同时记录线程ID,但是对于Tomcat及类似的WEB的应用,使用线程ID存在以下两个问题:
Tomcat等服务器会维护一个线程池,线程池中的线程会被反复使用,以便高效地响应请求,在这些种情况下,会有多个请求的log使用同一标识,依然无法抽取针对一次请求响应的log。
JDK1.4及之前并不支持线程ID,而当前面临的应用正好使用的是JDK1.4.2。
利用线程类Thread提供的以下方法,可以实现对对每一请求进行惟一标识:
public static Thread currentThread() // 取得当前线程对象
public final void setName(String name) // 为线程设定一个名称
public final String getName() // 取得线程的名称
具体实现过程如下:
在请求的入口处通过currentThread方法取得线程对象,然后调用其setName方法为线程设定一个惟一标识,惟一标识根据不同的应用可以设计不同的标识,只要其符合惟一性的标准即可。
在需要添加log的地方通过通过currentThread方法取得线程对象,然后调用getName方法取得当前线程的名称,并将其记入当前log。
由于怀疑是某些操作耗时过长,所以在需要记录log的方法中,入口处与出口处均需添加log。
更新程序后,取得log文件即可抽取一个请求的执行流程进行分析。
四、日志结果分析
通过日志,很快发现在线程中,以下方法被频繁调用并且耗时较长:
synchronized public static XXX getInstance()
{
if (m_instance == null)
{
m_instance = new XXX();
}
return m_instance;
}
该类是一个单实例类,通过分析其代码,并没有需要特别注意线程安全的地方,故可以直接取消方法getInstance的同步特性,只是这样可能在线程调用getInstance产生多余一个的实例,但此后它会被Java进行垃圾回收,并没有太大影响。或者,可以将同步范围缩小至需要创建对象的代码块处,这样将仅在程序刚开始运行时受到互斥的影响。
public static XXX getInstance()
{
if (m_instance == null)
{
Synchronized(this)
{
if (m_instance == null)
{
m_instance = new XXX();
}
}
}
return m_instance;
}
五、总结
多线程应用,取得能够惟一标识一个线程的log是迅速查找问题的关键,单纯依据现象及经验进行分析,可能会耗费大量的时间。前期在分析问题可能产生原因的同时,能取得有效log是一项优先度极高的工作。
单实列类的使用要慎重,其对空间占用率的影响可能远不如因同步而带来的负面影响。通常,应当只将具有状态的类设计成单实例类。
看起来似乎可以很快执行完毕的同步方法,在线程众多、被频繁调用时,也有可能是线程执行的瓶颈所在,不要将关注点只放在哪些可能比较耗时的操作上。