如何在不破坏应用程序输出的情况下重定向JVM输出？

Question

最近我正在编写一些微基准代码,所以我必须打印出JVM行为以及我的基准信息.我用

-XX:+PrintCompilation
-XX:+PrintGCDetails

以及获取JVM状态的其他选项.对于基准信息,我只是使用System.out.print()方法.因为我需要知道我打印的消息的顺序和JVM输出.

当我在控制台中打印它们时,我可以得到很好的结果,虽然JVM输出有时会撕掉我的消息,但由于它们处于不同的线程中,因此它是可以理解和可接受的.

当我需要做一些批次的基准,我想redirect the output into a file用pipe (> in Linux system),并使用Python从文件中获取结果,并进行分析.

这是问题所在:

The JVM output always overlapped with the messages I printed in the Java application. 它破坏了消息的完成.

知道如何应对这种情况吗？我需要both the JVM output and application output in the same place in order to preserve the sequence because it is important. And they do not overlap on each other so I don't lose anything.

Answer 1

我建议稍微绕道一下,看看使用Java Instrumentation API - 使用(编写)一个简单的Java代理来完成这项工作.从您的基准测试角度来看,这也将为您提供更多功能.您可以使用Java代理记录所有内容(因此不同的记录器线程之间不会发生争用).

您可以在http://www.javabeat.net/2012/06/introduction-to-java-agents/或http://today.java.net/pub/a/today/2008/04/24/阅读更多内容.添加日志记录,以一流的负载时间与- instrumentation.html

Answer 2

尝试使用System.out.println()而不是System.out.print(). System.out.println()强制同步部分内的流冲洗,至少你的输出不会混合.

Answer 3

使用Log4J或消息驱动的日志记录框架System.out.println().

Log4J使用消息事件模型来保证消息的排序.此外,各种"appenders"可用于登录数据库或其他输出/文件,允许通过Java包和其他属性进行分离,因此数据不会混合.

此外,沿着这些思路,考虑使用高性能计时器和/或不要尝试测量非常短(毫秒)的事件.原因是呼叫System.currentTimeMillis()将依次调用操作系统时钟.在每个OS上都存在一些"时钟漂移"和缓存,使得底层系统功能可以返回相同的值,从而在实际时间内产生+/- 30ms的偏移.要解决此问题或提高准确性,请将测量的函数分组为足够大的样本大小,然后除以迭代次数.

例如,执行10K操作,平均1-2毫秒作为一个测量操作.然后除以10K以获得每次操作的时间.

否则,再次需要高性能计时器.