一个用Java写的GUI程序,作用是分析日志, 它会将一定数量的格式相同的文本日志文件读入内存分析处理,然后将结果合并输出。

文件数量几十个,文件大小几KB, 日志记录几千条左右, 此工具可以流畅处理, 轻松满足需求。

然而, 因为记录日志的方案调整,记录日志类型范围从warn、error级别扩大到了连info、debug级别的日志也要记录,从而导致了日志量激增, 固定时间范围内产生的日志文件增加到了几百个, 单个大小也增加到几M,日志记录一下子达到几十万条,然后工具就跑的跟蜗牛一样慢, 几十秒才能出结果。

要继续使用这个工具,自然需要优化,要优化则需要定位性能瓶颈在哪里。 这个工具不复杂,没有复杂的计算, 也没有无谓的运行损耗, 最可能导致问题的地方是文件内容读取的I/O开销,可是以Java的能耐,从几百个文件中读取几百M内容, 没有可能需要几十秒时间。 而且为了提升速度我还使用了多线程处理,使用线程池为每个日志文件的读取和处理分配一个线程,于是我以此处为中心开始分析问题所在,直觉上, 线程的使用总是容易和性能问题联系在一起。

因为使用

Executors.newCachedThreadPool()

创建我所使用的线程池,而使用这个线程池太过于潦草, 它没有大小限制,为每个日志文件的处理分配一个线程,假如有100个文件需要处理, 那么线程池就会创建100个线程, 而我的机器CPU只有4核心,显然这100个线程无法被同时执行,而且还增加了线程之间切换的开销,所以怀疑这是导致性能问题的原因之一。

从相关网络资料中得知,最佳线程数目可通过以下公式确定

最佳线程数目 = ((线程等待时间+线程CPU时间)/线程CPU时间 )* CPU数目

显然,公式中所有变量除了CPU数目, 其它一概不知,所以我采用了另外一个简单粗暴的公式

线程数据 = 2 * CPU核心数 + 1

这是I/O密集型程序的计算公式。因为这个工具需要频繁读取磁盘文件,所以我将他定位为I/O密集型

ExecutorService executorService = Executors.newFixedThreadPool(9);

通过使用有数量限制的线程池对程序进行改进后,运行速度似乎有所改善, 可是对于让程序以可以接受的速度运行而言却是杯水车薪。当然,我本来也对此改进没有抱多大希望,因为上百个线程的切换不可能要花几十秒。

我知道程序存在问题, 可对于一个没有问题的程序在正常情况下处理这些日志文件需要花多少时间没有一个明确的概念,所以并没有充足的信心确定程序出问题的模块所在,只能没有证据的猜测, 因此不能迅速的定位问题所在。

可能是直觉的将性能与并发和线程挂钩,因此接下来的优化仍旧以这个主题进行。

我决定将日志文件的读取与处理分开,读取文件使用一个线程, 日志数据处理使用一个线程, 读取文件的线程将读取的内容存入一个阻塞队列,数据处理响线程从阻塞队列中读取数据进行处理,这是典型的生产消费模式。

费了很大力气实现这个模式,信心满满的以为程序的运行速度会有所改善,然而,出乎意料的程序运行的速度非但没有改善,而且比以前更加缓慢了,并且伴随卡死的现象, 我很沮丧, 可不得不承认,性能瓶颈不在并发处理上,朝这个方向优化永远不能解决问题,高大上的并发技能在这里毫无用武之地。

我意识必须不断缩小问题范围,精确定位到问题代码所在,才能啃掉这块骨头。

我虽然怀疑性能瓶颈在文件读取上,可并没有明确证据, 必须需要一个明确的数据指标才行。

我在程序的关键部位加上调试代码,计算执行各个环节所需要的时间,从数据中明确得知,大部分时间的确被文件读取占用了。

我定位到最接近文件的代码,一个从其它项目中拷贝过来的方法

public static String readStringFromFile(File file) {
try {
if (file.isFile() && file.exists()) {
InputStreamReader read = new InputStreamReader(new FileInputStream(file), "UTF-8");
BufferedReader bufferedReader = new BufferedReader(read);
String lineTxt = bufferedReader.readLine();
String result = "";
while (lineTxt != null) {
result += lineTxt;
lineTxt = bufferedReader.readLine();
}
return result;
}
} catch (IOException e) {
e.printStackTrace();
}
return null;
}

这个方法似乎没什么毛病, 还使用 BufferedReader 来提升性能,我百思不得其解,并开始推测问题所在。

程序是逐行读去内容的,问题会不会出现在这里?

如果一次性读取整个文件的内容速度会不会快一点?

正思考间,目光被一行代码吸引

result += lineTxt;

然后灵光一现,一个编程概念再我脑海中闪现: String类型是线程安全的,状态不可变, 每次操作都会复制一个自身的副本,因此性能很低,在频繁拼接字符串的情况下, 应该以StringBuffer或者StringBuilder代替String。

几百个日志文件, 几十万条日志记录,即使一行一条记录, Java虚拟机也执行了几十万次的字符串的拷贝,速度慢是必然的。

确定问题所在,改进就很容易了,我用StringBuilder类替代String进行字符串处理

public static String readStringFromFile(File file) {
try {
if (file.isFile() && file.exists()) {
InputStreamReader read = new InputStreamReader(new FileInputStream(file), "UTF-8");
BufferedReader bufferedReader = new BufferedReader(read);
String lineTxt = bufferedReader.readLine();
StringBuilder result = new StringBuilder();
while (lineTxt != null) {
result.append(lineTxt);
lineTxt = bufferedReader.readLine();
}
return result.toString();
}
} catch (IOException e) {
e.printStackTrace();
}
return null;
}

程序运行速度提升惊人,之前几十秒才能出的结果,现在不到一秒就完成,问题迎刃而解。 至于为什么不用StringBuffer是因为StringBuffer是StringBuffer的并发安全版本,性能略微不及StringBuider,而这里不存在并发处理问题,因此自然选着性能更优的StringBuilder。

只改三行代码就能解决的问题却令我折腾了半天, 究其原因在于以下原因思路先入为主, 总是把性能问题和并发挂上钩,利用多线程处理优化

凭直觉判断问题形成的原因,没有确切的依据, 致使优化方向错误

很多情况下, 程序性能问题跟并发处理无关, 当一个程序运行缓慢时, 并不会因为多加几个线程处理就会变的很快,真正引起问题的原因往往出人意料,而且极有可能是非常低级的问题, 排除掉这些问题所在,保证代码健康,如果性能问题依旧存在, 再使用并发手段去解决不迟。

再者,优化程序性能必须确定造成性能问题的代码块所在,不能评直觉判断, 否者不但解决不了问题,还浪费时间。