7

测试代码： 

import java.io.BufferedReader;
import java.io.FileReader;
import java.io.IOException;
import java.util.Map.Entry;

public class ReadLine {

    /**
     * @param args
     * @throws IOException
     */
    public static void main(String[] args) throws IOException {
        System.getenv();
        System.getProperties();

        BufferedReader br = new BufferedReader(new FileReader(args[0]), 2 << 17);
        int lineTotal = 0;
        int lineDone = 0;
        long start = System.currentTimeMillis();
        long totalSincePre = System.currentTimeMillis();
        while (br.readLine() != null) {
            lineTotal++;
            if (lineTotal % 100000 == 0) {
                long end = System.currentTimeMillis();
                System.out.println("total speed=" + lineTotal / (end - totalSincePre) + "k/s. curr speed="
                        + (lineTotal - lineDone) / (end - start));
                start = end;
                lineDone = lineTotal;
            }
        }
        printEnv();
    }

    static void printEnv() {

        for (Entry<?, ?> e : System.getenv().entrySet()) {
            System.out.println(e.getKey() + ":" + e.getValue());
        }

        for (Entry<?, ?> e : System.getProperties().entrySet()) {
            System.out.println(e.getKey() + ":" + e.getValue());
        }
    }
}

测试环境： 操作系统：Linux，文件大小：7.2G（csv 文本文件，每行超过 1k），java 版本“1.6.0_32”

测试运行：

代码被打包到一个 jar 中。我在同一个主机上运行了两个测试，使用同一个 jar，读取同一个文件。

1）运行./java -cp=my.jar ReadLine TestFile.txt 性能稳定在150k line/s左右。

控制台输出如下：

total speed=251k/s. curr speed=251
total speed=304k/s. curr speed=384
total speed=323k/s. curr speed=371
total speed=337k/s. curr speed=387
total speed=350k/s. curr speed=414
total speed=358k/s. curr speed=401
total speed=363k/s. curr speed=395
total speed=349k/s. curr speed=277
total speed=304k/s. curr speed=150
total speed=277k/s. curr speed=153
total speed=258k/s. curr speed=154
total speed=244k/s. curr speed=152
total speed=233k/s. curr speed=152
total speed=225k/s. curr speed=154
total speed=218k/s. curr speed=153
total speed=196k/s. curr speed=149
total speed=193k/s. curr speed=146
......stabled.......
total speed=163k/s. curr speed=150
total speed=162k/s. curr speed=155
total speed=162k/s. curr speed=155
total speed=162k/s. curr speed=149
total speed=162k/s. curr speed=147
total speed=162k/s. curr speed=150
total speed=161k/s. curr speed=148
total speed=161k/s. curr speed=145
total speed=161k/s. curr speed=151
total speed=161k/s. curr speed=154
total speed=161k/s. curr speed=163
total speed=161k/s. curr speed=179

2）没有代码更改，只是将 JAR（在生产环境中使用）添加到类路径中（在生产中需要，但不是这个程序），比如./java -cp=my.jar:hundreds_of_other_jars ReadLine TestFile.txt. 性能下降到约90k线/s

total speed=312k/s. curr speed=383
total speed=335k/s. curr speed=393
total speed=348k/s. curr speed=395
total speed=361k/s. curr speed=423
total speed=369k/s. curr speed=414
total speed=374k/s. curr speed=404
total speed=342k/s. curr speed=214
total speed=264k/s. curr speed=93
total speed=224k/s. curr speed=95
total speed=200k/s. curr speed=95
total speed=182k/s. curr speed=94
total speed=170k/s. curr speed=94
total speed=161k/s. curr speed=95
total speed=154k/s. curr speed=95
total speed=148k/s. curr speed=93
.....stabled.....
total speed=139k/s. curr speed=92
total speed=135k/s. curr speed=92
total speed=132k/s. curr speed=92
total speed=129k/s. curr speed=92
total speed=127k/s. curr speed=92
total speed=125k/s. curr speed=90
total speed=123k/s. curr speed=91
total speed=121k/s. curr speed=92
total speed=120k/s. curr speed=89
total speed=118k/s. curr speed=92
total speed=117k/s. curr speed=91
total speed=116k/s. curr speed=91
total speed=115k/s. curr speed=91
total speed=114k/s. curr speed=90
total speed=113k/s. curr speed=91

我的分析：

唯一的区别是类路径。第二个测试的类路径在类路径中有数百个 JAR。但是在这个程序中没有使用它们。

  • 与环境无关。此代码被打包到 JAR 中，并且两个测试都使用相同的 JAR。两个测试都在同一台主机上运行，​​读取相同的文件，使用相同的代码。我还比较了 System.getEnv 和 System.getProperties，除了类路径没有区别。
  • 不是操作系统缓存。这可以重现。经过多次测试，结果都是一样的。无论哪个测试先运行。
  • jmap显示内存使用没有太大差异，所有代都没有被高度使用。
  • jstack 显示两个测试的调用堆栈最有可能是

这个

at java.io.FileInputStream.available(Native Method)
at sun.nio.cs.StreamDecoder.inReady(StreamDecoder.java:343)
at sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:304)
at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:158)
 - locked <0xb4220388> (a java.io.FileReader)
at java.io.InputStreamReader.read(InputStreamReader.java:167)
at java.io.BufferedReader.fill(BufferedReader.java:136)
at java.io.BufferedReader.readLine(BufferedReader.java:299)
- locked <0xb4220388> (a java.io.FileReader)
at java.io.BufferedReader.readLine(BufferedReader.java:362)
at com.amazon.invhealth.metrics.transform.topasin.RL.main(RL.java:24)

或者

at sun.nio.cs.UTF_8$Decoder.decodeArrayLoop(UTF_8.java:240)
at sun.nio.cs.UTF_8$Decoder.decodeLoop(UTF_8.java:305)
at java.nio.charset.CharsetDecoder.decode(CharsetDecoder.java:544)
at sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:298)
at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:158)
- locked <0xb4220388> (a java.io.FileReader)
at java.io.InputStreamReader.read(InputStreamReader.java:167)
at java.io.BufferedReader.fill(BufferedReader.java:136)
at java.io.BufferedReader.readLine(BufferedReader.java:299)
- locked <0xb4220388> (a java.io.FileReader)
at java.io.BufferedReader.readLine(BufferedReader.java:362)
at com.amazon.invhealth.metrics.transform.topasin.RL.main(RL.java:24)

查看调用堆栈，这些测试用例可能使用相同的代码。

  • 这不是由类路径中的某个 JAR 引起的。我尝试删除类路径的前 50% 来运行测试，性能约为 110k line/s。然后我去掉最后的 50% 运行测试，性能也是 110k line/s 左右。如果从类路径中删除超过 2/3 的 jar，则性能约为 120k line/s。所以从测试来看，这个性能问题只与类路径中有多少 JAR 有关。
  • 然后我尝试将所有这些 JAR 打包成一个大 JAR。可悲的是，性能从 90k 下降到 60k....所以准确地说，根据我的测试，这种性能下降是由类路径中有多少类引起的。
  • 我在不同的机器上用不同的文件（文件大小和格式相似）运行了这两个测试，结果是一样的。所以这绝对可以重现。

但我认为这没有意义。我错过了什么吗？如果这确实是真的，那么根本原因是什么？

----------更多调试------

GC 和 Perm 大小

添加-Xmx2432m -Xms256m -XX:MaxNewSize=700m -XX:MaxPermSize=1024m -XX:+PrintGCDetails到两个测试中。有所有只是有PSYoungGen GC。两者的性能相同。

输出细节

长CP一：

total speed=114k/s. curr speed=91
[GC [PSYoungGen: 247888K->16K(238272K)] 248810K->938K(413056K), 0.0003290 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
total speed=113k/s. curr speed=92
[GC [PSYoungGen: 238096K->16K(228864K)] 239018K->938K(403648K), 0.0003840 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
total speed=113k/s. curr speed=92
[GC [PSYoungGen: 228816K->16K(220096K)] 229738K->938K(394880K), 0.0006030 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
total speed=112k/s. curr speed=92
[GC [PSYoungGen: 219984K->16K(211584K)] 220906K->938K(386368K), 0.0004380 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
total speed=111k/s. curr speed=93
[GC [PSYoungGen: 211536K->16K(203584K)] 212458K->938K(378368K), 0.0005160 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
total speed=111k/s. curr speed=92
[GC [PSYoungGen: 203472K->16K(195840K)] 204394K->938K(370624K), 0.0005920 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
total speed=110k/s. curr speed=94
[GC [PSYoungGen: 195792K->16K(188608K)] 196714K->938K(363392K), 0.0004010 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
[GC [PSYoungGen: 188496K->16K(181568K)] 189418K->938K(356352K), 0.0004440 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 

......................

Heap
 PSYoungGen      total 145984K, used 81767K [0xc8560000, 0xd7780000, 0xf4160000)
  eden space 145920K, 56% used [0xc8560000,0xcd535d18,0xd13e0000)
  from space 64K, 25% used [0xd7760000,0xd7764000,0xd7770000)
  to   space 64K, 0% used [0xd7770000,0xd7770000,0xd7780000)
 PSOldGen        total 174784K, used 922K [0x5c160000, 0x66c10000, 0xc8560000)
  object space 174784K, 0% used [0x5c160000,0x5c246ae8,0x66c10000)
 PSPermGen       total 16384K, used 2032K [0x1c160000, 0x1d160000, 0x5c160000)
  object space 16384K, 12% used [0x1c160000,0x1c35c260,0x1d160000)

一罐CP：

total speed=180k/s. curr speed=148
[GC [PSYoungGen: 87248K->16K(87296K)] 87904K->672K(262080K), 0.0005300 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
[GC [PSYoungGen: 87248K->16K(87296K)] 87904K->672K(262080K), 0.0004950 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
[GC [PSYoungGen: 87248K->16K(87296K)] 87904K->672K(262080K), 0.0005020 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
total speed=179k/s. curr speed=150
[GC [PSYoungGen: 87248K->16K(87296K)] 87904K->672K(262080K), 0.0005360 secs] [Times: user=0.01 sys=0.00, real=0.00 secs] 
[GC [PSYoungGen: 87248K->16K(87296K)] 87904K->672K(262080K), 0.0005190 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
total speed=178k/s. curr speed=151
[GC [PSYoungGen: 87248K->16K(87296K)] 87904K->672K(262080K), 0.0005360 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
[GC [PSYoungGen: 87248K->16K(87296K)] 87904K->672K(262080K), 0.0005400 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
[GC [PSYoungGen: 87248K->16K(87296K)] 87904K->672K(262080K), 0.0003510 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
total speed=177k/s. curr speed=150

Heap
 PSYoungGen      total 87296K, used 83826K [0xc8580000, 0xcdad0000, 0xf4180000)
  eden space 87232K, 96% used [0xc8580000,0xcd758928,0xcdab0000)
  from space 64K, 25% used [0xcdab0000,0xcdab4000,0xcdac0000)
  to   space 64K, 0% used [0xcdac0000,0xcdac0000,0xcdad0000)
 PSOldGen        total 174784K, used 656K [0x5c180000, 0x66c30000, 0xc8580000)
  object space 174784K, 0% used [0x5c180000,0x5c224080,0x66c30000)
 PSPermGen       total 16384K, used 2022K [0x1c180000, 0x1d180000, 0x5c180000)
  object space 16384K, 12% used [0x1c180000,0x1c379bb0,0x1d180000)

JVM 初始值

我非常期待这是原因，因为这是合理的。但是在使用以下代码后：

String filepath = args[0];
while (true) {
    BufferedReader br = new BufferedReader(new FileReader(filepath), 2 << 17);
    System.out.println("Press Enter to start...");
    while (System.in.read() != '\n')
        ;
    int lineTotal = 0;
    int linePre = 0;
    long start = System.currentTimeMillis();
    long totalStart = System.currentTimeMillis();
    while (br.readLine() != null) {
        lineTotal++;
        if (lineTotal % 100000 == 0) {
            long end = System.currentTimeMillis();
            System.out.println("total speed=" + lineTotal / (end - totalStart) + "k/s. curr speed="
                    + (lineTotal - linePre) / (end - start));
            start = end;
            linePre = lineTotal;
        }
    }
}

运行并按进入主次，性能不会改变。

4

2 回答 2

1

我找到了解决方案，但仍然不知道为什么。我使用JDK 1.7.0_21再次运行测试，两个测试用例的性能相同，稳定在180k线/秒。

正如问题中提到的，另一个测试是使用JDK 1.6.0_37，它有性能提升但仍有差距。

因此，如果可能，请升级 JDK。

如果有人知道根本原因并告诉我原因，我将不胜感激:-)

于 2013-04-24T04:04:27.700 回答
0

我认为这取决于您导入文件的方式。

如果速度是一个问题，请始终只导入您使用的类。

思考它的方式是计算机正在做更多的事情来做它以前做的更少的事情。

于 2013-04-18T12:18:45.050 回答