-XX:+PrintCompilation
输出是这样的：
60 1 java.lang.String::hashCode (55 bytes) 74 2 sun.nio.cs.UTF_8$Encoder::encode (361 bytes)
第一列是以毫秒为单位的时间戳,当打印日志时,我想将此时间戳与ManagementFactory.getRuntimeMXBean()返回的值进行比较.getUptime()：
long jvmUpTime = ManagementFactory.getRuntimeMXBean().getUptime();
要么
long jvmStartTime = ManagementFactory.getRuntimeMXBean().getStartTime();
但我的结果是这样的：
[62:log from Java code] 103 5 benchmark.AbstractBenchmarkST::benchmark (82 bytes) [62:log from Java code]
似乎它们之间有大约40毫秒的差异,这使得两个时间戳无法比拟.任何想法如何处理这个？
解决方法
在HotSpots JIT编译日志的第一列中打印的时间(当使用“-XX：PrintCompilation”参数启动JVM时)的持续时间大于ManagementFactory.getRuntimeMXBean()返回的时间.getUptime()(给定在编译日志被打印的大约同一时间调用getUptime).
对于在Windows 7下运行的JDK 7,这至少是正确的,并且可以通过使用“-XX：PrintCompilation”执行以下代码来轻松验证：
public static void main(String[] args) {
System.out.println("JVM uptime: " + ManagementFactory.getRuntimeMXBean().getUptime());
}
结果应如下所示：
06001
JVM uptime: 43
即使在打印的JIT编译之后调用了ManagementFactory.getRuntimeMXBean().getUptime(),返回的时间似乎也指向了早期的调用.
It seems that they have a around 40 ms difference,this difference makes it incomparable. Any ideas how to deal with this?
由于时间差是恒定的,并且在运行JVM时不应该改变,因此只要考虑时间差,就应该仍然可以比较时间.
答案很长
“-XX：PrintCompilation”JVM参数几乎没有记录,只能猜测第一列表示相对于JVM启动的时间戳.如果看一下HotSpot编译器的源代码,很明显,PrintCompilation打印的时间和ManagementFactory.getRuntimeMXBean()返回的时间.getStartTime()引用两个完全不同的时间戳,这两个时间戳都在JVM的启动.
在调用CompileTask::print_compilation_impl期间打印编译日志：
void CompileTask::print_compilation_impl(outputStream* st,Method* method,int compile_id,int comp_level,bool is_osr_method,int osr_bci,bool is_blocking,const char* msg,bool short_form) {
if (!short_form) {
st->print("%7d ",(int) st->time_stamp().milliseconds()); // print timestamp
}
st->print("%4d ",compile_id); // print compilation number
[...]
}
st-> time_stamp()在ostream.cpp中实现,并引用了一个TimeStamp,它使用os :: elapsed_counter()返回的时间进行初始化：
void outputStream::stamp() {
if (! _stamp.is_updated()) {
_stamp.update(); // start at 0 on first call to stamp()
}
[...]
}
void TimeStamp::update() {
update_to(os::elapsed_counter());
}
os :: elapsed_counter()在startup of the JVM期间通过调用os :: init()进行初始化：
jint Threads::create_vm(JavaVMInitArgs* args,bool* canTryAgain) {
[...]
os::init();
[...]
}
另一方面,java方法ManagementFactory.getRuntimeMXBean().getStartTime()引用了VMManagementImpl.java中的本机方法：
public native long getStartupTime();
它在VMManagementImpl.c中实现,并从JmmInterface常量JMM_JVM_INIT_DONE_TIME_MS返回时间：
case JMM_JVM_INIT_DONE_TIME_MS:
return Management::vm_init_done_time();
在调用os :: init()之后的一段时间内,它在JVM启动期间被初始化：
jint Threads::create_vm(JavaVMInitArgs* args,bool* canTryAgain) {
[...]
os::init();
[...]
// record VM initialization completion time
Management::record_vm_init_completed();
[...]
}
因此,JIT编译日志打印的时间与ManagementFactory.getRuntimeMXBean().getStartTime()返回的时间不同.
