我正在测试一个名为JOLT的JSON转换库。图书馆看起来不错，但是我们想确保它不会给我们的垃圾收集器带来太大的压力。因此，我创建了一个小程序(转载如下)，它可以完成以下操作：
- precompiles JSON tranformation scriptlet
- loop for a long time in each of ten threads, doing the following:
- create randomized JSON string input (approx 300 bytes)
- parse input using JOLT and apply tranform
当我们查看我们的漱口液收集器日志时，我们从未看到完整的GC(即使在运行了一半之后一天)，更可疑的是，据报道发生在第一天的GC启动程序几分钟后，几个小时过去了，我们看不到单个附加GC。该程序正在执行数量惊人的事务每秒。。根据JOLT文件：
"The transform process will create and discard a lot of objects, so the garbage collector will have work to do."
所以，我想我应该很高兴我们的gc日志在运行了一个小时后仍然是这样的：
Server VM (25.66-b17) for linux-amd64 JRE (1.8.0_66-b17), built on Oct 6 2015 17:28:34 by "java_re" with gcc 4.3.0 20080428 (Red Hat 4.3.0-8)
Memory: 4k page, physical 12439584k(11065340k free), swap 12721148k(12721148k free)
CommandLine flags: -XX:InitialHeapSize=199033344 -XX:MaxHeapSize=3184533504 -XX:MaxNewSize=348966912 -XX:MaxTenuringThreshold=6 -XX:OldPLABSize=16 -XX:+PrintGC -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:SoftRefLRUPolicyMSPerMB=1 -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC -XX:+UseParNewGC
2017-01-10T11:13:39.752-0800: 1.458: [GC (Allocation Failure) 2017-01-10T11:13:39.753-0800: 1.459: [ParNew: 51904K->6464K(58368K), 0.0123836 secs] 51904K->8148K(188096K), 0.0138403 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]
2017-01-10T11:13:40.416-0800: 2.122: [GC (Allocation Failure) 2017-01-10T11:13:40.416-0800: 2.123: [ParNew: 58368K->6463K(58368K), 0.0193642 secs] 60052K->10934K(188096K), 0.0197870 secs] [Times: user=0.03 sys=0.00, real=0.02 secs]
2017-01-10T11:13:40.611-0800: 2.317: [GC (Allocation Failure) 2017-01-10T11:13:40.611-0800: 2.318: [ParNew: 58367K->4378K(58368K), 0.0098514 secs] 62838K->12472K(188096K), 0.0102622 secs] [Times: user=0.03 sys=0.00, real=0.01 secs]
2017-01-10T11:13:40.762-0800: 2.468: [GC (Allocation Failure) 2017-01-10T11:13:40.762-0800: 2.468: [ParNew: 56282K->6464K(58368K), 0.0067945 secs] 64376K->14714K(188096K), 0.0071342 secs] [Times: user=0.03 sys=0.00, real=0.01 secs]
2017-01-10T11:13:40.954-0800: 2.661: [GC (Allocation Failure) 2017-01-10T11:13:40.955-0800: 2.661: [ParNew: 58368K->6464K(58368K), 0.0102488 secs] 66618K->17490K(188096K), 0.0108123 secs] [Times: user=0.03 sys=0.00, real=0.01 secs]
2017-01-10T11:13:41.216-0800: 2.922: [GC (Allocation Failure) 2017-01-10T11:13:41.216-0800: 2.922: [ParNew: 58368K->6464K(58368K), 0.0110529 secs] 69394K->21205K(188096K), 0.0114348 secs] [Times: user=0.04 sys=0.00, real=0.01 secs]
2017-01-10T11:13:41.412-0800: 3.119: [GC (Allocation Failure) 2017-01-10T11:13:41.413-0800: 3.119: [ParNew: 58368K->5049K(58368K), 0.0073977 secs] 73109K->22139K(188096K), 0.0077819 secs] [Times: user=0.02 sys=0.00, real=0.00 secs]
但也许这太好了，不可能是真的？也许我没有指定正确的JVM开关catch>all<GC，并且确实有一些事情没有被记录？
该程序不断运行(并不断生成小对象)，因此看起来这将填满eden空间，并且将发生内存分配失败，并且因此将启动GC。。尽管我(我认为)对垃圾收集器有相当的了解概念，我有点困惑。我唯一能想到的可能发生在这里的事情是：1)也许JOLT将其小对象分配在堆栈上(如在大数组中)而不是堆上？或者2)(更有可能)，也许我没有正确指定JVM开关。以下是我对交换机所做的操作：
export MAVEN_OPTS=" -XX:+UseConcMarkSweepGC
-XX:SoftRefLRUPolicyMSPerMB=1
-XX:+PrintGCTimeStamps
-XX:+PrintGCDateStamps
-XX:+PrintGCDetails
-Xloggc:/tmp/gc.log -Xmx2048m "
然后，我将该程序作为一个单元测试运行，如下所示：
mvn clean test
测试的源代码如下所示。
(如果需要的话，我可以在github上发布完整的maven项目。)谢谢前进寻求帮助！
import com.bazaarvoice.jolt.Chainr;
import com.bazaarvoice.jolt.JsonUtils;
import org.apache.commons.io.IOUtils;
import org.apache.commons.math.stat.descriptive.SummaryStatistics;
import org.junit.BeforeClass;
import org.junit.Test;
import org.junit.jupiter.api.DisplayName;
import java.util.Collections;
import java.util.List;
import java.util.Random;
import java.util.concurrent.Callable;
import java.util.concurrent.ExecutionException;
import java.util.concurrent.ExecutorService;
import java.util.concurrent.Executors;
import java.util.concurrent.atomic.AtomicLong;
public class BenchmarkJoltTest {
static int numThreads = 20;
static int numSecondsToRun = 360 * 1000; // 10 hours
static boolean randomize = true; /* for non-random we will validate that the output always remains constant */
static int hashOfExpectedOutput = 0;
static SummaryStatistics summaryStatistics = new SummaryStatistics();
static String inputJson = "";
static String transformSpecJson = "";
static Random random = new Random();
static Chainr chainr = null;
static AtomicLong completedTransformsCountForInterval = new AtomicLong(0);
static AtomicLong completedTransformsCountGrandTotal = new AtomicLong(0);
//summaryStatistics
@BeforeClass
public static void initialize() throws Exception {
System.out.println("HI HI HO");
inputJson =
String.join( " ", IOUtils.readLines(ClassLoader.getSystemResourceAsStream("input.json")));
transformSpecJson =
String.join( " ", IOUtils.readLines(ClassLoader.getSystemResourceAsStream("spec.json")));
chainr = Chainr.fromSpec(JsonUtils.jsonToList( transformSpecJson ));
/* Warm up: do JIT compilation, load classes and whatever else might need to be done only during startup */
for (int i = 0; i < 100; i++) {
runOneTransform(false);
}
}
@Test
@DisplayName("Benchmark for Jolt Json transforms")
public void runBenchmark() throws Exception {
runTransformsInThreadPool(10 /* threads */);
System.out.println("OK - here");
for (int i = 0; i < numSecondsToRun; i++) {
Thread.sleep(1000); /* 1 second */
double value = completedTransformsCountForInterval.doubleValue();
System.out.println("adding to count: " + value );
summaryStatistics.addValue(value);
completedTransformsCountForInterval.set(0L); // reset counter
if (completedTransformsCountForInterval.get() > 100) {
throw new Exception("how did the counter suddenly jump so high? -- unexpected");
}
}
System.out.println(
"Summary statistics for number of transforms performed per secondnn" +
summaryStatistics.toString() + "ntotalCount: "+ completedTransformsCountForInterval);
System.out.println("Grand total of completed operations: " + completedTransformsCountGrandTotal);
System.exit(0);
}
private void runTransformsInThreadPool(final int threadCount) throws InterruptedException, ExecutionException {
Callable<Void> task = new Callable<Void>() {
@Override
public Void call() throws Exception {
while (true) {
runOneTransform(true /* include in official count */);
}
}
};
List<Callable<Void>> tasks = Collections.nCopies(threadCount, task);
ExecutorService executorService = Executors.newFixedThreadPool(threadCount);
for (Callable c : tasks) {
System.out.println("submitting " + c);
executorService.submit(c);
System.out.println("finished submitting ");
}
System.out.println("INVOKED all");
}
private static void runOneTransform(boolean includeInOfficialCount /* don't include if in warm-up mode */) throws Exception {
String targetJson = randomize ? getRandomizedJson() : inputJson;
Object transformedJson = chainr.transform(JsonUtils.jsonToObject(targetJson));
String transformedJsonAsString = JsonUtils.toJsonString(transformedJson);
if (hashOfExpectedOutput == 0) {
hashOfExpectedOutput = transformedJsonAsString.hashCode();
}
if (! randomize && hashOfExpectedOutput != transformedJsonAsString.hashCode()) {
throw new Exception("hash codes of transformed strings don't match. multi-threading issue ?");
}
if (includeInOfficialCount) {
completedTransformsCountForInterval.incrementAndGet();
completedTransformsCountGrandTotal.incrementAndGet();
} else {
System.out.println(transformedJsonAsString);
}
}
private static String getRandomizedJson() {
Integer num = random.nextInt() % 10;
inputJson.replaceAll("3", num.toString());
return inputJson;
}
}
看起来runOneTransform只是在创建寿命很短的对象。由于跟踪GC的成本取决于活动对象集的大小，而这些对象的寿命不长，这意味着GC几乎没有什么可做的
很可能，在这个人工测试用例中，您主要衡量的是实际代码执行和分配的成本，而不是垃圾收集的成本。
现实世界中的应用程序通常有一个不太左偏的生存期直方图，需要收集器进行更多的跟踪和复制工作。
日志表明垃圾收集器>>是<lt；跑步这些行中的每一行都是ParNew收集器的一个运行。然而，如果我正确地解释了日志，它们都是"新对象"空间的集合，而且速度相当快。
如果你的应用程序继续这样运行，它最终会达到CMS收集器需要运行来收集新空间中已升级的垃圾的地步。
应用程序似乎没有产生太多负载这一事实并不一定是可疑的。您在Jolt文档中发现的内容可能已过期或不准确。(例如，他们可能一直在错误地概括。)
如果您怀疑您的应用程序工作不正常，请寻找另一种方法来验证结果。
也许我没有正确指定JVM开关。
低GC速率是一个>>好<lt；事情只有在出现问题时，才应该考虑调整开关。
感谢Stephen C、@the8472和@Holger的提示。我将总结我从Jolt开发人员(特别是Milo Simpson)那里得到的答案，并发布详细信息的链接。
总之：Milo给出的解释是EscapeAnalysis正在启动，Jolt为执行转换而创建的对象正在堆栈上分配。如果我想强制GC(我宁愿在生产中不这样做；^)，他建议设置测试，以便对输出JSON的引用跨越线程边界。
我不认为我会这么做，因为我们练习的目的是评估Jolt的表现。。。它看起来非常坚固。
我从这个练习中学到了很多，建议我完整阅读Milo的答案。https://github.com/bazaarvoice/jolt/issues/305#issuecomment-271861868