# HG changeset patch # User mgronlun # Date 1385205913 -3600 # Node ID 41eaa9a170593a33949482c74d0cf06a6bc4a899 # Parent 941f6e3a15674ae15fe73a58269445fa5376403d 8028128: Add a type safe alternative for working with counter based data Reviewed-by: dholmes, egahlin diff -r 941f6e3a1567 -r 41eaa9a17059 hotspot/src/share/vm/classfile/classLoaderData.cpp --- a/hotspot/src/share/vm/classfile/classLoaderData.cpp Sat Nov 23 09:56:59 2013 +0100 +++ b/hotspot/src/share/vm/classfile/classLoaderData.cpp Sat Nov 23 12:25:13 2013 +0100 @@ -62,13 +62,13 @@ #include "runtime/safepoint.hpp" #include "runtime/synchronizer.hpp" #include "utilities/growableArray.hpp" +#include "utilities/macros.hpp" #include "utilities/ostream.hpp" #if INCLUDE_TRACE #include "trace/tracing.hpp" #endif - ClassLoaderData * ClassLoaderData::_the_null_class_loader_data = NULL; ClassLoaderData::ClassLoaderData(Handle h_class_loader, bool is_anonymous, Dependencies dependencies) : @@ -754,7 +754,7 @@ if (Tracing::enabled()) { if (Tracing::is_event_enabled(TraceClassUnloadEvent)) { assert(_unloading != NULL, "need class loader data unload list!"); - _class_unload_time = Tracing::time(); + _class_unload_time = Ticks::now(); classes_unloading_do(&class_unload_event); } Tracing::on_unloading_classes(); @@ -832,7 +832,7 @@ #if INCLUDE_TRACE -TracingTime ClassLoaderDataGraph::_class_unload_time; +Ticks ClassLoaderDataGraph::_class_unload_time; void ClassLoaderDataGraph::class_unload_event(Klass* const k) { diff -r 941f6e3a1567 -r 41eaa9a17059 hotspot/src/share/vm/classfile/classLoaderData.hpp --- a/hotspot/src/share/vm/classfile/classLoaderData.hpp Sat Nov 23 09:56:59 2013 +0100 +++ b/hotspot/src/share/vm/classfile/classLoaderData.hpp Sat Nov 23 12:25:13 2013 +0100 @@ -33,7 +33,7 @@ #include "utilities/growableArray.hpp" #if INCLUDE_TRACE -# include "trace/traceTime.hpp" +# include "utilities/ticks.hpp" #endif // @@ -98,7 +98,7 @@ #if INCLUDE_TRACE private: - static TracingTime _class_unload_time; + static Ticks _class_unload_time; static void class_unload_event(Klass* const k); #endif }; diff -r 941f6e3a1567 -r 41eaa9a17059 hotspot/src/share/vm/classfile/systemDictionary.cpp --- a/hotspot/src/share/vm/classfile/systemDictionary.cpp Sat Nov 23 09:56:59 2013 +0100 +++ b/hotspot/src/share/vm/classfile/systemDictionary.cpp Sat Nov 23 12:25:13 2013 +0100 @@ -55,13 +55,13 @@ #include "runtime/signature.hpp" #include "services/classLoadingService.hpp" #include "services/threadService.hpp" +#include "utilities/macros.hpp" +#include "utilities/ticks.hpp" #if INCLUDE_TRACE #include "trace/tracing.hpp" - #include "trace/traceMacros.hpp" #endif - Dictionary* SystemDictionary::_dictionary = NULL; PlaceholderTable* SystemDictionary::_placeholders = NULL; Dictionary* SystemDictionary::_shared_dictionary = NULL; @@ -598,7 +598,7 @@ assert(name != NULL && !FieldType::is_array(name) && !FieldType::is_obj(name), "invalid class name"); - TracingTime class_load_start_time = Tracing::time(); + Ticks class_load_start_time = Ticks::now(); // UseNewReflection // Fix for 4474172; see evaluation for more details @@ -1006,7 +1006,7 @@ TRAPS) { TempNewSymbol parsed_name = NULL; - TracingTime class_load_start_time = Tracing::time(); + Ticks class_load_start_time = Ticks::now(); ClassLoaderData* loader_data; if (host_klass.not_null()) { @@ -2665,13 +2665,12 @@ } // utility function for class load event -void SystemDictionary::post_class_load_event(TracingTime start_time, +void SystemDictionary::post_class_load_event(const Ticks& start_time, instanceKlassHandle k, Handle initiating_loader) { #if INCLUDE_TRACE EventClassLoad event(UNTIMED); if (event.should_commit()) { - event.set_endtime(Tracing::time()); event.set_starttime(start_time); event.set_loadedClass(k()); oop defining_class_loader = k->class_loader(); diff -r 941f6e3a1567 -r 41eaa9a17059 hotspot/src/share/vm/classfile/systemDictionary.hpp --- a/hotspot/src/share/vm/classfile/systemDictionary.hpp Sat Nov 23 09:56:59 2013 +0100 +++ b/hotspot/src/share/vm/classfile/systemDictionary.hpp Sat Nov 23 12:25:13 2013 +0100 @@ -31,7 +31,6 @@ #include "oops/symbol.hpp" #include "runtime/java.hpp" #include "runtime/reflectionUtils.hpp" -#include "trace/traceTime.hpp" #include "utilities/hashtable.hpp" #include "utilities/hashtable.inline.hpp" @@ -78,6 +77,7 @@ template class HashtableBucket; class ResolutionErrorTable; class SymbolPropertyTable; +class Ticks; // Certain classes are preloaded, such as java.lang.Object and java.lang.String. // They are all "well-known", in the sense that no class loader is allowed @@ -637,7 +637,7 @@ static void add_to_hierarchy(instanceKlassHandle k, TRAPS); // event based tracing - static void post_class_load_event(TracingTime start_time, instanceKlassHandle k, + static void post_class_load_event(const Ticks& start_time, instanceKlassHandle k, Handle initiating_loader); // We pass in the hashtable index so we can calculate it outside of // the SystemDictionary_lock. diff -r 941f6e3a1567 -r 41eaa9a17059 hotspot/src/share/vm/gc_implementation/concurrentMarkSweep/concurrentMarkSweepGeneration.cpp --- a/hotspot/src/share/vm/gc_implementation/concurrentMarkSweep/concurrentMarkSweepGeneration.cpp Sat Nov 23 09:56:59 2013 +0100 +++ b/hotspot/src/share/vm/gc_implementation/concurrentMarkSweep/concurrentMarkSweepGeneration.cpp Sat Nov 23 12:25:13 2013 +0100 @@ -1993,7 +1993,7 @@ GenCollectedHeap* gch = GenCollectedHeap::heap(); STWGCTimer* gc_timer = GenMarkSweep::gc_timer(); - gc_timer->register_gc_start(os::elapsed_counter()); + gc_timer->register_gc_start(); SerialOldTracer* gc_tracer = GenMarkSweep::gc_tracer(); gc_tracer->report_gc_start(gch->gc_cause(), gc_timer->gc_start()); @@ -2089,7 +2089,7 @@ size_policy()->msc_collection_end(gch->gc_cause()); } - gc_timer->register_gc_end(os::elapsed_counter()); + gc_timer->register_gc_end(); gc_tracer->report_gc_end(gc_timer->gc_end(), gc_timer->time_partitions()); @@ -2475,7 +2475,7 @@ void CMSCollector::register_gc_start(GCCause::Cause cause) { _cms_start_registered = true; - _gc_timer_cm->register_gc_start(os::elapsed_counter()); + _gc_timer_cm->register_gc_start(); _gc_tracer_cm->report_gc_start(cause, _gc_timer_cm->gc_start()); } @@ -2483,7 +2483,7 @@ if (_cms_start_registered) { report_heap_summary(GCWhen::AfterGC); - _gc_timer_cm->register_gc_end(os::elapsed_counter()); + _gc_timer_cm->register_gc_end(); _gc_tracer_cm->report_gc_end(_gc_timer_cm->gc_end(), _gc_timer_cm->time_partitions()); _cms_start_registered = false; } diff -r 941f6e3a1567 -r 41eaa9a17059 hotspot/src/share/vm/gc_implementation/concurrentMarkSweep/vmCMSOperations.cpp --- a/hotspot/src/share/vm/gc_implementation/concurrentMarkSweep/vmCMSOperations.cpp Sat Nov 23 09:56:59 2013 +0100 +++ b/hotspot/src/share/vm/gc_implementation/concurrentMarkSweep/vmCMSOperations.cpp Sat Nov 23 12:25:13 2013 +0100 @@ -145,7 +145,7 @@ ); #endif /* USDT2 */ - _collector->_gc_timer_cm->register_gc_pause_start("Initial Mark", os::elapsed_counter()); + _collector->_gc_timer_cm->register_gc_pause_start("Initial Mark"); GenCollectedHeap* gch = GenCollectedHeap::heap(); GCCauseSetter gccs(gch, GCCause::_cms_initial_mark); @@ -157,7 +157,7 @@ VM_CMS_Operation::verify_after_gc(); - _collector->_gc_timer_cm->register_gc_pause_end(os::elapsed_counter()); + _collector->_gc_timer_cm->register_gc_pause_end(); #ifndef USDT2 HS_DTRACE_PROBE(hs_private, cms__initmark__end); @@ -182,7 +182,7 @@ ); #endif /* USDT2 */ - _collector->_gc_timer_cm->register_gc_pause_start("Final Mark", os::elapsed_counter()); + _collector->_gc_timer_cm->register_gc_pause_start("Final Mark"); GenCollectedHeap* gch = GenCollectedHeap::heap(); GCCauseSetter gccs(gch, GCCause::_cms_final_remark); @@ -195,7 +195,7 @@ VM_CMS_Operation::verify_after_gc(); _collector->save_heap_summary(); - _collector->_gc_timer_cm->register_gc_pause_end(os::elapsed_counter()); + _collector->_gc_timer_cm->register_gc_pause_end(); #ifndef USDT2 HS_DTRACE_PROBE(hs_private, cms__remark__end); diff -r 941f6e3a1567 -r 41eaa9a17059 hotspot/src/share/vm/gc_implementation/g1/g1CollectedHeap.cpp --- a/hotspot/src/share/vm/gc_implementation/g1/g1CollectedHeap.cpp Sat Nov 23 09:56:59 2013 +0100 +++ b/hotspot/src/share/vm/gc_implementation/g1/g1CollectedHeap.cpp Sat Nov 23 12:25:13 2013 +0100 @@ -56,6 +56,7 @@ #include "oops/oop.inline.hpp" #include "oops/oop.pcgc.inline.hpp" #include "runtime/vmThread.hpp" +#include "utilities/ticks.hpp" size_t G1CollectedHeap::_humongous_object_threshold_in_words = 0; @@ -1284,7 +1285,7 @@ } STWGCTimer* gc_timer = G1MarkSweep::gc_timer(); - gc_timer->register_gc_start(os::elapsed_counter()); + gc_timer->register_gc_start(); SerialOldTracer* gc_tracer = G1MarkSweep::gc_tracer(); gc_tracer->report_gc_start(gc_cause(), gc_timer->gc_start()); @@ -1552,7 +1553,7 @@ post_full_gc_dump(gc_timer); - gc_timer->register_gc_end(os::elapsed_counter()); + gc_timer->register_gc_end(); gc_tracer->report_gc_end(gc_timer->gc_end(), gc_timer->time_partitions()); } @@ -2482,7 +2483,7 @@ FullGCCount_lock->notify_all(); } -void G1CollectedHeap::register_concurrent_cycle_start(jlong start_time) { +void G1CollectedHeap::register_concurrent_cycle_start(const Ticks& start_time) { _concurrent_cycle_started = true; _gc_timer_cm->register_gc_start(start_time); @@ -2496,7 +2497,7 @@ _gc_tracer_cm->report_concurrent_mode_failure(); } - _gc_timer_cm->register_gc_end(os::elapsed_counter()); + _gc_timer_cm->register_gc_end(); _gc_tracer_cm->report_gc_end(_gc_timer_cm->gc_end(), _gc_timer_cm->time_partitions()); _concurrent_cycle_started = false; @@ -3887,7 +3888,7 @@ return false; } - _gc_timer_stw->register_gc_start(os::elapsed_counter()); + _gc_timer_stw->register_gc_start(); _gc_tracer_stw->report_gc_start(gc_cause(), _gc_timer_stw->gc_start()); @@ -4265,7 +4266,7 @@ _gc_tracer_stw->report_evacuation_info(&evacuation_info); _gc_tracer_stw->report_tenuring_threshold(_g1_policy->tenuring_threshold()); - _gc_timer_stw->register_gc_end(os::elapsed_counter()); + _gc_timer_stw->register_gc_end(); _gc_tracer_stw->report_gc_end(_gc_timer_stw->gc_end(), _gc_timer_stw->time_partitions()); } // It should now be safe to tell the concurrent mark thread to start diff -r 941f6e3a1567 -r 41eaa9a17059 hotspot/src/share/vm/gc_implementation/g1/g1CollectedHeap.hpp --- a/hotspot/src/share/vm/gc_implementation/g1/g1CollectedHeap.hpp Sat Nov 23 09:56:59 2013 +0100 +++ b/hotspot/src/share/vm/gc_implementation/g1/g1CollectedHeap.hpp Sat Nov 23 12:25:13 2013 +0100 @@ -72,6 +72,7 @@ class G1OldTracer; class EvacuationFailedInfo; class nmethod; +class Ticks; typedef OverflowTaskQueue RefToScanQueue; typedef GenericTaskQueueSet RefToScanQueueSet; @@ -746,7 +747,7 @@ return _old_marking_cycles_completed; } - void register_concurrent_cycle_start(jlong start_time); + void register_concurrent_cycle_start(const Ticks& start_time); void register_concurrent_cycle_end(); void trace_heap_after_concurrent_cycle(); diff -r 941f6e3a1567 -r 41eaa9a17059 hotspot/src/share/vm/gc_implementation/parNew/parNewGeneration.cpp --- a/hotspot/src/share/vm/gc_implementation/parNew/parNewGeneration.cpp Sat Nov 23 09:56:59 2013 +0100 +++ b/hotspot/src/share/vm/gc_implementation/parNew/parNewGeneration.cpp Sat Nov 23 12:25:13 2013 +0100 @@ -915,7 +915,7 @@ GenCollectedHeap* gch = GenCollectedHeap::heap(); - _gc_timer->register_gc_start(os::elapsed_counter()); + _gc_timer->register_gc_start(); assert(gch->kind() == CollectedHeap::GenCollectedHeap, "not a CMS generational heap"); @@ -1091,7 +1091,7 @@ gch->trace_heap_after_gc(&gc_tracer); gc_tracer.report_tenuring_threshold(tenuring_threshold()); - _gc_timer->register_gc_end(os::elapsed_counter()); + _gc_timer->register_gc_end(); gc_tracer.report_gc_end(_gc_timer->gc_end(), _gc_timer->time_partitions()); } diff -r 941f6e3a1567 -r 41eaa9a17059 hotspot/src/share/vm/gc_implementation/parallelScavenge/psMarkSweep.cpp --- a/hotspot/src/share/vm/gc_implementation/parallelScavenge/psMarkSweep.cpp Sat Nov 23 09:56:59 2013 +0100 +++ b/hotspot/src/share/vm/gc_implementation/parallelScavenge/psMarkSweep.cpp Sat Nov 23 12:25:13 2013 +0100 @@ -114,7 +114,7 @@ assert(heap->kind() == CollectedHeap::ParallelScavengeHeap, "Sanity"); GCCause::Cause gc_cause = heap->gc_cause(); - _gc_timer->register_gc_start(os::elapsed_counter()); + _gc_timer->register_gc_start(); _gc_tracer->report_gc_start(gc_cause, _gc_timer->gc_start()); PSAdaptiveSizePolicy* size_policy = heap->size_policy(); @@ -390,7 +390,7 @@ ParallelTaskTerminator::print_termination_counts(); #endif - _gc_timer->register_gc_end(os::elapsed_counter()); + _gc_timer->register_gc_end(); _gc_tracer->report_gc_end(_gc_timer->gc_end(), _gc_timer->time_partitions()); diff -r 941f6e3a1567 -r 41eaa9a17059 hotspot/src/share/vm/gc_implementation/parallelScavenge/psParallelCompact.cpp --- a/hotspot/src/share/vm/gc_implementation/parallelScavenge/psParallelCompact.cpp Sat Nov 23 09:56:59 2013 +0100 +++ b/hotspot/src/share/vm/gc_implementation/parallelScavenge/psParallelCompact.cpp Sat Nov 23 12:25:13 2013 +0100 @@ -2006,7 +2006,7 @@ ParallelScavengeHeap* heap = gc_heap(); - _gc_timer.register_gc_start(os::elapsed_counter()); + _gc_timer.register_gc_start(); _gc_tracer.report_gc_start(heap->gc_cause(), _gc_timer.gc_start()); TimeStamp marking_start; @@ -2244,7 +2244,7 @@ ParallelTaskTerminator::print_termination_counts(); #endif - _gc_timer.register_gc_end(os::elapsed_counter()); + _gc_timer.register_gc_end(); _gc_tracer.report_dense_prefix(dense_prefix(old_space_id)); _gc_tracer.report_gc_end(_gc_timer.gc_end(), _gc_timer.time_partitions()); diff -r 941f6e3a1567 -r 41eaa9a17059 hotspot/src/share/vm/gc_implementation/parallelScavenge/psScavenge.cpp --- a/hotspot/src/share/vm/gc_implementation/parallelScavenge/psScavenge.cpp Sat Nov 23 09:56:59 2013 +0100 +++ b/hotspot/src/share/vm/gc_implementation/parallelScavenge/psScavenge.cpp Sat Nov 23 12:25:13 2013 +0100 @@ -263,7 +263,7 @@ assert(_preserved_mark_stack.is_empty(), "should be empty"); assert(_preserved_oop_stack.is_empty(), "should be empty"); - _gc_timer.register_gc_start(os::elapsed_counter()); + _gc_timer.register_gc_start(); TimeStamp scavenge_entry; TimeStamp scavenge_midpoint; @@ -691,7 +691,7 @@ #endif - _gc_timer.register_gc_end(os::elapsed_counter()); + _gc_timer.register_gc_end(); _gc_tracer.report_gc_end(_gc_timer.gc_end(), _gc_timer.time_partitions()); diff -r 941f6e3a1567 -r 41eaa9a17059 hotspot/src/share/vm/gc_implementation/shared/gcTimer.cpp --- a/hotspot/src/share/vm/gc_implementation/shared/gcTimer.cpp Sat Nov 23 09:56:59 2013 +0100 +++ b/hotspot/src/share/vm/gc_implementation/shared/gcTimer.cpp Sat Nov 23 12:25:13 2013 +0100 @@ -25,52 +25,55 @@ #include "precompiled.hpp" #include "gc_implementation/shared/gcTimer.hpp" #include "utilities/growableArray.hpp" +#include "utilities/ticks.inline.hpp" -void GCTimer::register_gc_start(jlong time) { +// the "time" parameter for most functions +// has a default value set by Ticks::now() + +void GCTimer::register_gc_start(const Ticks& time) { _time_partitions.clear(); _gc_start = time; } -void GCTimer::register_gc_end(jlong time) { +void GCTimer::register_gc_end(const Ticks& time) { assert(!_time_partitions.has_active_phases(), "We should have ended all started phases, before ending the GC"); _gc_end = time; } -void GCTimer::register_gc_pause_start(const char* name, jlong time) { +void GCTimer::register_gc_pause_start(const char* name, const Ticks& time) { _time_partitions.report_gc_phase_start(name, time); } -void GCTimer::register_gc_pause_end(jlong time) { +void GCTimer::register_gc_pause_end(const Ticks& time) { _time_partitions.report_gc_phase_end(time); } -void GCTimer::register_gc_phase_start(const char* name, jlong time) { +void GCTimer::register_gc_phase_start(const char* name, const Ticks& time) { _time_partitions.report_gc_phase_start(name, time); } -void GCTimer::register_gc_phase_end(jlong time) { +void GCTimer::register_gc_phase_end(const Ticks& time) { _time_partitions.report_gc_phase_end(time); } - -void STWGCTimer::register_gc_start(jlong time) { +void STWGCTimer::register_gc_start(const Ticks& time) { GCTimer::register_gc_start(time); register_gc_pause_start("GC Pause", time); } -void STWGCTimer::register_gc_end(jlong time) { +void STWGCTimer::register_gc_end(const Ticks& time) { register_gc_pause_end(time); GCTimer::register_gc_end(time); } -void ConcurrentGCTimer::register_gc_pause_start(const char* name, jlong time) { - GCTimer::register_gc_pause_start(name, time); +void ConcurrentGCTimer::register_gc_pause_start(const char* name) { + GCTimer::register_gc_pause_start(name); } -void ConcurrentGCTimer::register_gc_pause_end(jlong time) { - GCTimer::register_gc_pause_end(time); +void ConcurrentGCTimer::register_gc_pause_end() { + GCTimer::register_gc_pause_end(); } void PhasesStack::clear() { @@ -111,11 +114,11 @@ void TimePartitions::clear() { _phases->clear(); _active_phases.clear(); - _sum_of_pauses = 0; - _longest_pause = 0; + _sum_of_pauses = Tickspan(); + _longest_pause = Tickspan(); } -void TimePartitions::report_gc_phase_start(const char* name, jlong time) { +void TimePartitions::report_gc_phase_start(const char* name, const Ticks& time) { assert(_phases->length() <= 1000, "Too many recored phases?"); int level = _active_phases.count(); @@ -133,13 +136,13 @@ void TimePartitions::update_statistics(GCPhase* phase) { // FIXME: This should only be done for pause phases if (phase->level() == 0) { - jlong pause = phase->end() - phase->start(); + const Tickspan pause = phase->end() - phase->start(); _sum_of_pauses += pause; _longest_pause = MAX2(pause, _longest_pause); } } -void TimePartitions::report_gc_phase_end(jlong time) { +void TimePartitions::report_gc_phase_end(const Ticks& time) { int phase_index = _active_phases.pop(); GCPhase* phase = _phases->adr_at(phase_index); phase->set_end(time); @@ -157,14 +160,6 @@ return _phases->adr_at(index); } -jlong TimePartitions::sum_of_pauses() { - return _sum_of_pauses; -} - -jlong TimePartitions::longest_pause() { - return _longest_pause; -} - bool TimePartitions::has_active_phases() { return _active_phases.count() > 0; } @@ -194,7 +189,7 @@ max_nested_pause_phases(); } - static void validate_pause_phase(GCPhase* phase, int level, const char* name, jlong start, jlong end) { + static void validate_pause_phase(GCPhase* phase, int level, const char* name, const Ticks& start, const Ticks& end) { assert(phase->level() == level, "Incorrect level"); assert(strcmp(phase->name(), name) == 0, "Incorrect name"); assert(phase->start() == start, "Incorrect start"); @@ -209,8 +204,8 @@ TimePartitionPhasesIterator iter(&time_partitions); validate_pause_phase(iter.next(), 0, "PausePhase", 2, 8); - assert(time_partitions.sum_of_pauses() == 8-2, "Incorrect"); - assert(time_partitions.longest_pause() == 8-2, "Incorrect"); + assert(time_partitions.sum_of_pauses() == Ticks(8) - Ticks(2), "Incorrect"); + assert(time_partitions.longest_pause() == Ticks(8) - Ticks(2), "Incorrect"); assert(!iter.has_next(), "Too many elements"); } @@ -227,8 +222,8 @@ validate_pause_phase(iter.next(), 0, "PausePhase1", 2, 3); validate_pause_phase(iter.next(), 0, "PausePhase2", 4, 6); - assert(time_partitions.sum_of_pauses() == 3, "Incorrect"); - assert(time_partitions.longest_pause() == 2, "Incorrect"); + assert(time_partitions.sum_of_pauses() == Ticks(3) - Ticks(0), "Incorrect"); + assert(time_partitions.longest_pause() == Ticks(2) - Ticks(0), "Incorrect"); assert(!iter.has_next(), "Too many elements"); } @@ -245,8 +240,8 @@ validate_pause_phase(iter.next(), 0, "PausePhase", 2, 5); validate_pause_phase(iter.next(), 1, "SubPhase", 3, 4); - assert(time_partitions.sum_of_pauses() == 3, "Incorrect"); - assert(time_partitions.longest_pause() == 3, "Incorrect"); + assert(time_partitions.sum_of_pauses() == Ticks(3) - Ticks(0), "Incorrect"); + assert(time_partitions.longest_pause() == Ticks(3) - Ticks(0), "Incorrect"); assert(!iter.has_next(), "Too many elements"); } @@ -269,8 +264,8 @@ validate_pause_phase(iter.next(), 2, "SubPhase2", 4, 7); validate_pause_phase(iter.next(), 3, "SubPhase3", 5, 6); - assert(time_partitions.sum_of_pauses() == 7, "Incorrect"); - assert(time_partitions.longest_pause() == 7, "Incorrect"); + assert(time_partitions.sum_of_pauses() == Ticks(7) - Ticks(0), "Incorrect"); + assert(time_partitions.longest_pause() == Ticks(7) - Ticks(0), "Incorrect"); assert(!iter.has_next(), "Too many elements"); } @@ -298,8 +293,8 @@ validate_pause_phase(iter.next(), 1, "SubPhase3", 7, 8); validate_pause_phase(iter.next(), 1, "SubPhase4", 9, 10); - assert(time_partitions.sum_of_pauses() == 9, "Incorrect"); - assert(time_partitions.longest_pause() == 9, "Incorrect"); + assert(time_partitions.sum_of_pauses() == Ticks(9) - Ticks(0), "Incorrect"); + assert(time_partitions.longest_pause() == Ticks(9) - Ticks(0), "Incorrect"); assert(!iter.has_next(), "Too many elements"); } @@ -336,8 +331,8 @@ validate_pause_phase(iter.next(), 2, "SubPhase22", 12, 13); validate_pause_phase(iter.next(), 1, "SubPhase3", 15, 16); - assert(time_partitions.sum_of_pauses() == 15, "Incorrect"); - assert(time_partitions.longest_pause() == 15, "Incorrect"); + assert(time_partitions.sum_of_pauses() == Ticks(15) - Ticks(0), "Incorrect"); + assert(time_partitions.longest_pause() == Ticks(15) - Ticks(0), "Incorrect"); assert(!iter.has_next(), "Too many elements"); } diff -r 941f6e3a1567 -r 41eaa9a17059 hotspot/src/share/vm/gc_implementation/shared/gcTimer.hpp --- a/hotspot/src/share/vm/gc_implementation/shared/gcTimer.hpp Sat Nov 23 09:56:59 2013 +0100 +++ b/hotspot/src/share/vm/gc_implementation/shared/gcTimer.hpp Sat Nov 23 12:25:13 2013 +0100 @@ -28,6 +28,7 @@ #include "memory/allocation.hpp" #include "prims/jni_md.h" #include "utilities/macros.hpp" +#include "utilities/ticks.hpp" class ConcurrentPhase; class GCPhase; @@ -45,21 +46,21 @@ class GCPhase { const char* _name; int _level; - jlong _start; - jlong _end; + Ticks _start; + Ticks _end; public: void set_name(const char* name) { _name = name; } - const char* name() { return _name; } + const char* name() const { return _name; } - int level() { return _level; } + int level() const { return _level; } void set_level(int level) { _level = level; } - jlong start() { return _start; } - void set_start(jlong time) { _start = time; } + const Ticks start() const { return _start; } + void set_start(const Ticks& time) { _start = time; } - jlong end() { return _end; } - void set_end(jlong time) { _end = time; } + const Ticks end() const { return _end; } + void set_end(const Ticks& time) { _end = time; } virtual void accept(PhaseVisitor* visitor) = 0; }; @@ -102,22 +103,22 @@ GrowableArray* _phases; PhasesStack _active_phases; - jlong _sum_of_pauses; - jlong _longest_pause; + Tickspan _sum_of_pauses; + Tickspan _longest_pause; public: TimePartitions(); ~TimePartitions(); void clear(); - void report_gc_phase_start(const char* name, jlong time); - void report_gc_phase_end(jlong time); + void report_gc_phase_start(const char* name, const Ticks& time); + void report_gc_phase_end(const Ticks& time); int num_phases() const; GCPhase* phase_at(int index) const; - jlong sum_of_pauses(); - jlong longest_pause(); + const Tickspan sum_of_pauses() const { return _sum_of_pauses; } + const Tickspan longest_pause() const { return _longest_pause; } bool has_active_phases(); private: @@ -133,40 +134,37 @@ class GCTimer : public ResourceObj { NOT_PRODUCT(friend class GCTimerTest;) protected: - jlong _gc_start; - jlong _gc_end; + Ticks _gc_start; + Ticks _gc_end; TimePartitions _time_partitions; public: - virtual void register_gc_start(jlong time); - virtual void register_gc_end(jlong time); + virtual void register_gc_start(const Ticks& time = Ticks::now()); + virtual void register_gc_end(const Ticks& time = Ticks::now()); - void register_gc_phase_start(const char* name, jlong time); - void register_gc_phase_end(jlong time); + void register_gc_phase_start(const char* name, const Ticks& time); + void register_gc_phase_end(const Ticks& time); - jlong gc_start() { return _gc_start; } - jlong gc_end() { return _gc_end; } + const Ticks gc_start() const { return _gc_start; } + const Ticks gc_end() const { return _gc_end; } TimePartitions* time_partitions() { return &_time_partitions; } - long longest_pause(); - long sum_of_pauses(); - protected: - void register_gc_pause_start(const char* name, jlong time); - void register_gc_pause_end(jlong time); + void register_gc_pause_start(const char* name, const Ticks& time = Ticks::now()); + void register_gc_pause_end(const Ticks& time = Ticks::now()); }; class STWGCTimer : public GCTimer { public: - virtual void register_gc_start(jlong time); - virtual void register_gc_end(jlong time); + virtual void register_gc_start(const Ticks& time = Ticks::now()); + virtual void register_gc_end(const Ticks& time = Ticks::now()); }; class ConcurrentGCTimer : public GCTimer { public: - void register_gc_pause_start(const char* name, jlong time); - void register_gc_pause_end(jlong time); + void register_gc_pause_start(const char* name); + void register_gc_pause_end(); }; class TimePartitionPhasesIterator { diff -r 941f6e3a1567 -r 41eaa9a17059 hotspot/src/share/vm/gc_implementation/shared/gcTrace.cpp --- a/hotspot/src/share/vm/gc_implementation/shared/gcTrace.cpp Sat Nov 23 09:56:59 2013 +0100 +++ b/hotspot/src/share/vm/gc_implementation/shared/gcTrace.cpp Sat Nov 23 12:25:13 2013 +0100 @@ -32,6 +32,7 @@ #include "memory/referenceProcessorStats.hpp" #include "runtime/os.hpp" #include "utilities/globalDefinitions.hpp" +#include "utilities/ticks.inline.hpp" #if INCLUDE_ALL_GCS #include "gc_implementation/g1/evacuationInfo.hpp" @@ -45,7 +46,7 @@ return GCTracer_next_gc_id++; } -void GCTracer::report_gc_start_impl(GCCause::Cause cause, jlong timestamp) { +void GCTracer::report_gc_start_impl(GCCause::Cause cause, const Ticks& timestamp) { assert_unset_gc_id(); GCId gc_id = create_new_gc_id(); @@ -54,7 +55,7 @@ _shared_gc_info.set_start_timestamp(timestamp); } -void GCTracer::report_gc_start(GCCause::Cause cause, jlong timestamp) { +void GCTracer::report_gc_start(GCCause::Cause cause, const Ticks& timestamp) { assert_unset_gc_id(); report_gc_start_impl(cause, timestamp); @@ -64,7 +65,7 @@ return _shared_gc_info.id() != SharedGCInfo::UNSET_GCID; } -void GCTracer::report_gc_end_impl(jlong timestamp, TimePartitions* time_partitions) { +void GCTracer::report_gc_end_impl(const Ticks& timestamp, TimePartitions* time_partitions) { assert_set_gc_id(); _shared_gc_info.set_sum_of_pauses(time_partitions->sum_of_pauses()); @@ -75,7 +76,7 @@ send_garbage_collection_event(); } -void GCTracer::report_gc_end(jlong timestamp, TimePartitions* time_partitions) { +void GCTracer::report_gc_end(const Ticks& timestamp, TimePartitions* time_partitions) { assert_set_gc_id(); report_gc_end_impl(timestamp, time_partitions); @@ -97,10 +98,10 @@ const GCId _gc_id; const double _size_threshold_percentage; const size_t _total_size_in_words; - const jlong _timestamp; + const Ticks _timestamp; public: - ObjectCountEventSenderClosure(GCId gc_id, size_t total_size_in_words, jlong timestamp) : + ObjectCountEventSenderClosure(GCId gc_id, size_t total_size_in_words, const Ticks& timestamp) : _gc_id(gc_id), _size_threshold_percentage(ObjectCountCutOffPercent / 100), _total_size_in_words(total_size_in_words), @@ -131,9 +132,7 @@ if (!cit.allocation_failed()) { HeapInspection hi(false, false, false, NULL); hi.populate_table(&cit, is_alive_cl); - - jlong timestamp = os::elapsed_counter(); - ObjectCountEventSenderClosure event_sender(_shared_gc_info.id(), cit.size_of_instances_in_words(), timestamp); + ObjectCountEventSenderClosure event_sender(_shared_gc_info.id(), cit.size_of_instances_in_words(), Ticks::now()); cit.iterate(&event_sender); } } @@ -147,7 +146,7 @@ send_meta_space_summary_event(when, meta_space_summary); } -void YoungGCTracer::report_gc_end_impl(jlong timestamp, TimePartitions* time_partitions) { +void YoungGCTracer::report_gc_end_impl(const Ticks& timestamp, TimePartitions* time_partitions) { assert_set_gc_id(); assert(_tenuring_threshold != UNSET_TENURING_THRESHOLD, "Tenuring threshold has not been reported"); @@ -167,14 +166,14 @@ _tenuring_threshold = tenuring_threshold; } -void OldGCTracer::report_gc_end_impl(jlong timestamp, TimePartitions* time_partitions) { +void OldGCTracer::report_gc_end_impl(const Ticks& timestamp, TimePartitions* time_partitions) { assert_set_gc_id(); GCTracer::report_gc_end_impl(timestamp, time_partitions); send_old_gc_event(); } -void ParallelOldTracer::report_gc_end_impl(jlong timestamp, TimePartitions* time_partitions) { +void ParallelOldTracer::report_gc_end_impl(const Ticks& timestamp, TimePartitions* time_partitions) { assert_set_gc_id(); OldGCTracer::report_gc_end_impl(timestamp, time_partitions); @@ -200,7 +199,7 @@ _g1_young_gc_info.set_type(type); } -void G1NewTracer::report_gc_end_impl(jlong timestamp, TimePartitions* time_partitions) { +void G1NewTracer::report_gc_end_impl(const Ticks& timestamp, TimePartitions* time_partitions) { assert_set_gc_id(); YoungGCTracer::report_gc_end_impl(timestamp, time_partitions); diff -r 941f6e3a1567 -r 41eaa9a17059 hotspot/src/share/vm/gc_implementation/shared/gcTrace.hpp --- a/hotspot/src/share/vm/gc_implementation/shared/gcTrace.hpp Sat Nov 23 09:56:59 2013 +0100 +++ b/hotspot/src/share/vm/gc_implementation/shared/gcTrace.hpp Sat Nov 23 12:25:13 2013 +0100 @@ -35,6 +35,7 @@ #include "gc_implementation/g1/g1YCTypes.hpp" #endif #include "utilities/macros.hpp" +#include "utilities/ticks.hpp" typedef uint GCId; @@ -47,8 +48,6 @@ class BoolObjectClosure; class SharedGCInfo VALUE_OBJ_CLASS_SPEC { - static const jlong UNSET_TIMESTAMP = -1; - public: static const GCId UNSET_GCID = (GCId)-1; @@ -56,23 +55,30 @@ GCId _id; GCName _name; GCCause::Cause _cause; - jlong _start_timestamp; - jlong _end_timestamp; - jlong _sum_of_pauses; - jlong _longest_pause; + Ticks _start_timestamp; + Ticks _end_timestamp; + Tickspan _sum_of_pauses; + Tickspan _longest_pause; public: - SharedGCInfo(GCName name) : _id(UNSET_GCID), _name(name), _cause(GCCause::_last_gc_cause), - _start_timestamp(UNSET_TIMESTAMP), _end_timestamp(UNSET_TIMESTAMP), _sum_of_pauses(0), _longest_pause(0) {} + SharedGCInfo(GCName name) : + _id(UNSET_GCID), + _name(name), + _cause(GCCause::_last_gc_cause), + _start_timestamp(), + _end_timestamp(), + _sum_of_pauses(), + _longest_pause() { + } void set_id(GCId id) { _id = id; } GCId id() const { return _id; } - void set_start_timestamp(jlong timestamp) { _start_timestamp = timestamp; } - jlong start_timestamp() const { return _start_timestamp; } + void set_start_timestamp(const Ticks& timestamp) { _start_timestamp = timestamp; } + const Ticks start_timestamp() const { return _start_timestamp; } - void set_end_timestamp(jlong timestamp) { _end_timestamp = timestamp; } - jlong end_timestamp() const { return _end_timestamp; } + void set_end_timestamp(const Ticks& timestamp) { _end_timestamp = timestamp; } + const Ticks end_timestamp() const { return _end_timestamp; } void set_name(GCName name) { _name = name; } GCName name() const { return _name; } @@ -80,11 +86,11 @@ void set_cause(GCCause::Cause cause) { _cause = cause; } GCCause::Cause cause() const { return _cause; } - void set_sum_of_pauses(jlong duration) { _sum_of_pauses = duration; } - jlong sum_of_pauses() const { return _sum_of_pauses; } + void set_sum_of_pauses(const Tickspan& duration) { _sum_of_pauses = duration; } + const Tickspan sum_of_pauses() const { return _sum_of_pauses; } - void set_longest_pause(jlong duration) { _longest_pause = duration; } - jlong longest_pause() const { return _longest_pause; } + void set_longest_pause(const Tickspan& duration) { _longest_pause = duration; } + const Tickspan longest_pause() const { return _longest_pause; } }; class ParallelOldGCInfo VALUE_OBJ_CLASS_SPEC { @@ -116,8 +122,8 @@ SharedGCInfo _shared_gc_info; public: - void report_gc_start(GCCause::Cause cause, jlong timestamp); - void report_gc_end(jlong timestamp, TimePartitions* time_partitions); + void report_gc_start(GCCause::Cause cause, const Ticks& timestamp); + void report_gc_end(const Ticks& timestamp, TimePartitions* time_partitions); void report_gc_heap_summary(GCWhen::Type when, const GCHeapSummary& heap_summary, const MetaspaceSummary& meta_space_summary) const; void report_gc_reference_stats(const ReferenceProcessorStats& rp) const; void report_object_count_after_gc(BoolObjectClosure* object_filter) NOT_SERVICES_RETURN; @@ -125,8 +131,8 @@ protected: GCTracer(GCName name) : _shared_gc_info(name) {} - virtual void report_gc_start_impl(GCCause::Cause cause, jlong timestamp); - virtual void report_gc_end_impl(jlong timestamp, TimePartitions* time_partitions); + virtual void report_gc_start_impl(GCCause::Cause cause, const Ticks& timestamp); + virtual void report_gc_end_impl(const Ticks& timestamp, TimePartitions* time_partitions); private: void send_garbage_collection_event() const; @@ -143,7 +149,7 @@ protected: YoungGCTracer(GCName name) : GCTracer(name), _tenuring_threshold(UNSET_TENURING_THRESHOLD) {} - virtual void report_gc_end_impl(jlong timestamp, TimePartitions* time_partitions); + virtual void report_gc_end_impl(const Ticks& timestamp, TimePartitions* time_partitions); public: void report_promotion_failed(const PromotionFailedInfo& pf_info); @@ -157,7 +163,7 @@ class OldGCTracer : public GCTracer { protected: OldGCTracer(GCName name) : GCTracer(name) {} - virtual void report_gc_end_impl(jlong timestamp, TimePartitions* time_partitions); + virtual void report_gc_end_impl(const Ticks& timestamp, TimePartitions* time_partitions); public: void report_concurrent_mode_failure(); @@ -175,7 +181,7 @@ void report_dense_prefix(void* dense_prefix); protected: - void report_gc_end_impl(jlong timestamp, TimePartitions* time_partitions); + void report_gc_end_impl(const Ticks& timestamp, TimePartitions* time_partitions); private: void send_parallel_old_event() const; @@ -209,7 +215,7 @@ G1NewTracer() : YoungGCTracer(G1New) {} void report_yc_type(G1YCType type); - void report_gc_end_impl(jlong timestamp, TimePartitions* time_partitions); + void report_gc_end_impl(const Ticks& timestamp, TimePartitions* time_partitions); void report_evacuation_info(EvacuationInfo* info); void report_evacuation_failed(EvacuationFailedInfo& ef_info); diff -r 941f6e3a1567 -r 41eaa9a17059 hotspot/src/share/vm/gc_implementation/shared/gcTraceSend.cpp --- a/hotspot/src/share/vm/gc_implementation/shared/gcTraceSend.cpp Sat Nov 23 09:56:59 2013 +0100 +++ b/hotspot/src/share/vm/gc_implementation/shared/gcTraceSend.cpp Sat Nov 23 12:25:13 2013 +0100 @@ -55,12 +55,11 @@ } void GCTracer::send_reference_stats_event(ReferenceType type, size_t count) const { - EventGCReferenceStatistics e(UNTIMED); + EventGCReferenceStatistics e; if (e.should_commit()) { e.set_gcId(_shared_gc_info.id()); e.set_type((u1)type); e.set_count(count); - e.set_endtime(os::elapsed_counter()); e.commit(); } } @@ -107,22 +106,20 @@ } void YoungGCTracer::send_promotion_failed_event(const PromotionFailedInfo& pf_info) const { - EventPromotionFailed e(UNTIMED); + EventPromotionFailed e; if (e.should_commit()) { e.set_gcId(_shared_gc_info.id()); e.set_data(to_trace_struct(pf_info)); e.set_thread(pf_info.thread()->thread_id()); - e.set_endtime(os::elapsed_counter()); e.commit(); } } // Common to CMS and G1 void OldGCTracer::send_concurrent_mode_failure_event() { - EventConcurrentModeFailure e(UNTIMED); + EventConcurrentModeFailure e; if (e.should_commit()) { e.set_gcId(_shared_gc_info.id()); - e.set_endtime(os::elapsed_counter()); e.commit(); } } @@ -140,7 +137,7 @@ } void G1NewTracer::send_evacuation_info_event(EvacuationInfo* info) { - EventEvacuationInfo e(UNTIMED); + EventEvacuationInfo e; if (e.should_commit()) { e.set_gcId(_shared_gc_info.id()); e.set_cSetRegions(info->collectionset_regions()); @@ -151,17 +148,15 @@ e.set_allocRegionsUsedAfter(info->alloc_regions_used_before() + info->bytes_copied()); e.set_bytesCopied(info->bytes_copied()); e.set_regionsFreed(info->regions_freed()); - e.set_endtime(os::elapsed_counter()); e.commit(); } } void G1NewTracer::send_evacuation_failed_event(const EvacuationFailedInfo& ef_info) const { - EventEvacuationFailed e(UNTIMED); + EventEvacuationFailed e; if (e.should_commit()) { e.set_gcId(_shared_gc_info.id()); e.set_data(to_trace_struct(ef_info)); - e.set_endtime(os::elapsed_counter()); e.commit(); } } @@ -195,13 +190,12 @@ void visit(const GCHeapSummary* heap_summary) const { const VirtualSpaceSummary& heap_space = heap_summary->heap(); - EventGCHeapSummary e(UNTIMED); + EventGCHeapSummary e; if (e.should_commit()) { e.set_gcId(_id); e.set_when((u1)_when); e.set_heapSpace(to_trace_struct(heap_space)); e.set_heapUsed(heap_summary->used()); - e.set_endtime(os::elapsed_counter()); e.commit(); } } @@ -216,7 +210,7 @@ const SpaceSummary& from_space = ps_heap_summary->from(); const SpaceSummary& to_space = ps_heap_summary->to(); - EventPSHeapSummary e(UNTIMED); + EventPSHeapSummary e; if (e.should_commit()) { e.set_gcId(_id); e.set_when((u1)_when); @@ -227,7 +221,6 @@ e.set_edenSpace(to_trace_struct(ps_heap_summary->eden())); e.set_fromSpace(to_trace_struct(ps_heap_summary->from())); e.set_toSpace(to_trace_struct(ps_heap_summary->to())); - e.set_endtime(os::elapsed_counter()); e.commit(); } } @@ -249,14 +242,13 @@ } void GCTracer::send_meta_space_summary_event(GCWhen::Type when, const MetaspaceSummary& meta_space_summary) const { - EventMetaspaceSummary e(UNTIMED); + EventMetaspaceSummary e; if (e.should_commit()) { e.set_gcId(_shared_gc_info.id()); e.set_when((u1) when); e.set_metaspace(to_trace_struct(meta_space_summary.meta_space())); e.set_dataSpace(to_trace_struct(meta_space_summary.data_space())); e.set_classSpace(to_trace_struct(meta_space_summary.class_space())); - e.set_endtime(os::elapsed_counter()); e.commit(); } } diff -r 941f6e3a1567 -r 41eaa9a17059 hotspot/src/share/vm/gc_implementation/shared/gcTraceTime.cpp --- a/hotspot/src/share/vm/gc_implementation/shared/gcTraceTime.cpp Sat Nov 23 09:56:59 2013 +0100 +++ b/hotspot/src/share/vm/gc_implementation/shared/gcTraceTime.cpp Sat Nov 23 12:25:13 2013 +0100 @@ -31,12 +31,13 @@ #include "runtime/thread.inline.hpp" #include "runtime/timer.hpp" #include "utilities/ostream.hpp" +#include "utilities/ticks.inline.hpp" GCTraceTime::GCTraceTime(const char* title, bool doit, bool print_cr, GCTimer* timer) : - _title(title), _doit(doit), _print_cr(print_cr), _timer(timer) { + _title(title), _doit(doit), _print_cr(print_cr), _timer(timer), _start_counter() { if (_doit || _timer != NULL) { - _start_counter = os::elapsed_counter(); + _start_counter.stamp(); } if (_timer != NULL) { @@ -57,10 +58,10 @@ } GCTraceTime::~GCTraceTime() { - jlong stop_counter = 0; + Ticks stop_counter; if (_doit || _timer != NULL) { - stop_counter = os::elapsed_counter(); + stop_counter.stamp(); } if (_timer != NULL) { @@ -68,11 +69,12 @@ } if (_doit) { - double seconds = TimeHelper::counter_to_seconds(stop_counter - _start_counter); + const Tickspan duration = stop_counter - _start_counter; + double duration_in_seconds = TicksToTimeHelper::seconds(duration); if (_print_cr) { - gclog_or_tty->print_cr(", %3.7f secs]", seconds); + gclog_or_tty->print_cr(", %3.7f secs]", duration_in_seconds); } else { - gclog_or_tty->print(", %3.7f secs]", seconds); + gclog_or_tty->print(", %3.7f secs]", duration_in_seconds); } gclog_or_tty->flush(); } diff -r 941f6e3a1567 -r 41eaa9a17059 hotspot/src/share/vm/gc_implementation/shared/gcTraceTime.hpp --- a/hotspot/src/share/vm/gc_implementation/shared/gcTraceTime.hpp Sat Nov 23 09:56:59 2013 +0100 +++ b/hotspot/src/share/vm/gc_implementation/shared/gcTraceTime.hpp Sat Nov 23 12:25:13 2013 +0100 @@ -26,6 +26,7 @@ #define SHARE_VM_GC_IMPLEMENTATION_SHARED_GCTRACETIME_HPP #include "prims/jni_md.h" +#include "utilities/ticks.hpp" class GCTimer; @@ -34,7 +35,7 @@ bool _doit; bool _print_cr; GCTimer* _timer; - jlong _start_counter; + Ticks _start_counter; public: GCTraceTime(const char* title, bool doit, bool print_cr, GCTimer* timer); diff -r 941f6e3a1567 -r 41eaa9a17059 hotspot/src/share/vm/gc_implementation/shared/objectCountEventSender.cpp --- a/hotspot/src/share/vm/gc_implementation/shared/objectCountEventSender.cpp Sat Nov 23 09:56:59 2013 +0100 +++ b/hotspot/src/share/vm/gc_implementation/shared/objectCountEventSender.cpp Sat Nov 23 12:25:13 2013 +0100 @@ -28,10 +28,11 @@ #include "memory/heapInspection.hpp" #include "trace/tracing.hpp" #include "utilities/globalDefinitions.hpp" +#include "utilities/ticks.hpp" #if INCLUDE_SERVICES -void ObjectCountEventSender::send(const KlassInfoEntry* entry, GCId gc_id, jlong timestamp) { +void ObjectCountEventSender::send(const KlassInfoEntry* entry, GCId gc_id, const Ticks& timestamp) { #if INCLUDE_TRACE assert(Tracing::is_event_enabled(EventObjectCountAfterGC::eventId), "Only call this method if the event is enabled"); diff -r 941f6e3a1567 -r 41eaa9a17059 hotspot/src/share/vm/gc_implementation/shared/objectCountEventSender.hpp --- a/hotspot/src/share/vm/gc_implementation/shared/objectCountEventSender.hpp Sat Nov 23 09:56:59 2013 +0100 +++ b/hotspot/src/share/vm/gc_implementation/shared/objectCountEventSender.hpp Sat Nov 23 12:25:13 2013 +0100 @@ -32,10 +32,11 @@ #if INCLUDE_SERVICES class KlassInfoEntry; +class Ticks; class ObjectCountEventSender : public AllStatic { public: - static void send(const KlassInfoEntry* entry, GCId gc_id, jlong timestamp); + static void send(const KlassInfoEntry* entry, GCId gc_id, const Ticks& timestamp); static bool should_send_event(); }; diff -r 941f6e3a1567 -r 41eaa9a17059 hotspot/src/share/vm/memory/defNewGeneration.cpp --- a/hotspot/src/share/vm/memory/defNewGeneration.cpp Sat Nov 23 09:56:59 2013 +0100 +++ b/hotspot/src/share/vm/memory/defNewGeneration.cpp Sat Nov 23 12:25:13 2013 +0100 @@ -562,7 +562,7 @@ GenCollectedHeap* gch = GenCollectedHeap::heap(); - _gc_timer->register_gc_start(os::elapsed_counter()); + _gc_timer->register_gc_start(); DefNewTracer gc_tracer; gc_tracer.report_gc_start(gch->gc_cause(), _gc_timer->gc_start()); @@ -709,7 +709,7 @@ gch->trace_heap_after_gc(&gc_tracer); gc_tracer.report_tenuring_threshold(tenuring_threshold()); - _gc_timer->register_gc_end(os::elapsed_counter()); + _gc_timer->register_gc_end(); gc_tracer.report_gc_end(_gc_timer->gc_end(), _gc_timer->time_partitions()); } diff -r 941f6e3a1567 -r 41eaa9a17059 hotspot/src/share/vm/memory/generation.cpp --- a/hotspot/src/share/vm/memory/generation.cpp Sat Nov 23 09:56:59 2013 +0100 +++ b/hotspot/src/share/vm/memory/generation.cpp Sat Nov 23 12:25:13 2013 +0100 @@ -635,16 +635,16 @@ x(ref_processor(), gch->reserved_region()); STWGCTimer* gc_timer = GenMarkSweep::gc_timer(); - gc_timer->register_gc_start(os::elapsed_counter()); + gc_timer->register_gc_start(); SerialOldTracer* gc_tracer = GenMarkSweep::gc_tracer(); gc_tracer->report_gc_start(gch->gc_cause(), gc_timer->gc_start()); GenMarkSweep::invoke_at_safepoint(_level, ref_processor(), clear_all_soft_refs); - gc_timer->register_gc_end(os::elapsed_counter()); + gc_timer->register_gc_end(); - gc_tracer->report_gc_end(os::elapsed_counter(), gc_timer->time_partitions()); + gc_tracer->report_gc_end(gc_timer->gc_end(), gc_timer->time_partitions()); SpecializationStats::print(); } diff -r 941f6e3a1567 -r 41eaa9a17059 hotspot/src/share/vm/opto/compile.hpp --- a/hotspot/src/share/vm/opto/compile.hpp Sat Nov 23 09:56:59 2013 +0100 +++ b/hotspot/src/share/vm/opto/compile.hpp Sat Nov 23 12:25:13 2013 +0100 @@ -42,6 +42,7 @@ #include "runtime/deoptimization.hpp" #include "runtime/vmThread.hpp" #include "trace/tracing.hpp" +#include "utilities/ticks.hpp" class Block; class Bundle; @@ -597,20 +598,19 @@ bool has_method_handle_invokes() const { return _has_method_handle_invokes; } void set_has_method_handle_invokes(bool z) { _has_method_handle_invokes = z; } - jlong _latest_stage_start_counter; + Ticks _latest_stage_start_counter; void begin_method() { #ifndef PRODUCT if (_printer) _printer->begin_method(this); #endif - C->_latest_stage_start_counter = os::elapsed_counter(); + C->_latest_stage_start_counter.stamp(); } void print_method(CompilerPhaseType cpt, int level = 1) { - EventCompilerPhase event(UNTIMED); + EventCompilerPhase event; if (event.should_commit()) { event.set_starttime(C->_latest_stage_start_counter); - event.set_endtime(os::elapsed_counter()); event.set_phase((u1) cpt); event.set_compileID(C->_compile_id); event.set_phaseLevel(level); @@ -621,14 +621,13 @@ #ifndef PRODUCT if (_printer) _printer->print_method(this, CompilerPhaseTypeHelper::to_string(cpt), level); #endif - C->_latest_stage_start_counter = os::elapsed_counter(); + C->_latest_stage_start_counter.stamp(); } void end_method(int level = 1) { - EventCompilerPhase event(UNTIMED); + EventCompilerPhase event; if (event.should_commit()) { event.set_starttime(C->_latest_stage_start_counter); - event.set_endtime(os::elapsed_counter()); event.set_phase((u1) PHASE_END); event.set_compileID(C->_compile_id); event.set_phaseLevel(level); diff -r 941f6e3a1567 -r 41eaa9a17059 hotspot/src/share/vm/runtime/sweeper.cpp --- a/hotspot/src/share/vm/runtime/sweeper.cpp Sat Nov 23 09:56:59 2013 +0100 +++ b/hotspot/src/share/vm/runtime/sweeper.cpp Sat Nov 23 12:25:13 2013 +0100 @@ -38,6 +38,7 @@ #include "runtime/vm_operations.hpp" #include "trace/tracing.hpp" #include "utilities/events.hpp" +#include "utilities/ticks.inline.hpp" #include "utilities/xmlstream.hpp" #ifdef ASSERT @@ -144,10 +145,10 @@ // 3) zombie -> marked_for_reclamation int NMethodSweeper::_total_nof_methods_reclaimed = 0; // Accumulated nof methods flushed -jlong NMethodSweeper::_total_time_sweeping = 0; // Accumulated time sweeping -jlong NMethodSweeper::_total_time_this_sweep = 0; // Total time this sweep -jlong NMethodSweeper::_peak_sweep_time = 0; // Peak time for a full sweep -jlong NMethodSweeper::_peak_sweep_fraction_time = 0; // Peak time sweeping one fraction +Tickspan NMethodSweeper::_total_time_sweeping; // Accumulated time sweeping +Tickspan NMethodSweeper::_total_time_this_sweep; // Total time this sweep +Tickspan NMethodSweeper::_peak_sweep_time; // Peak time for a full sweep +Tickspan NMethodSweeper::_peak_sweep_fraction_time; // Peak time sweeping one fraction int NMethodSweeper::_hotness_counter_reset_val = 0; @@ -209,7 +210,7 @@ _sweep_fractions_left = NmethodSweepFraction; _current = CodeCache::first_nmethod(); _traversals += 1; - _total_time_this_sweep = 0; + _total_time_this_sweep = Tickspan(); if (PrintMethodFlushing) { tty->print_cr("### Sweep: stack traversal %d", _traversals); @@ -303,7 +304,7 @@ } void NMethodSweeper::sweep_code_cache() { - jlong sweep_start_counter = os::elapsed_counter(); + Ticks sweep_start_counter = Ticks::now(); _flushed_count = 0; _zombified_count = 0; @@ -367,8 +368,8 @@ assert(_sweep_fractions_left > 1 || _current == NULL, "must have scanned the whole cache"); - jlong sweep_end_counter = os::elapsed_counter(); - jlong sweep_time = sweep_end_counter - sweep_start_counter; + const Ticks sweep_end_counter = Ticks::now(); + const Tickspan sweep_time = sweep_end_counter - sweep_start_counter; _total_time_sweeping += sweep_time; _total_time_this_sweep += sweep_time; _peak_sweep_fraction_time = MAX2(sweep_time, _peak_sweep_fraction_time); @@ -389,7 +390,8 @@ #ifdef ASSERT if(PrintMethodFlushing) { - tty->print_cr("### sweeper: sweep time(%d): " INT64_FORMAT, _sweep_fractions_left, (jlong)sweep_time); + tty->print_cr("### sweeper: sweep time(%d): " + INT64_FORMAT, _sweep_fractions_left, (jlong)sweep_time.value()); } #endif diff -r 941f6e3a1567 -r 41eaa9a17059 hotspot/src/share/vm/runtime/sweeper.hpp --- a/hotspot/src/share/vm/runtime/sweeper.hpp Sat Nov 23 09:56:59 2013 +0100 +++ b/hotspot/src/share/vm/runtime/sweeper.hpp Sat Nov 23 12:25:13 2013 +0100 @@ -25,6 +25,7 @@ #ifndef SHARE_VM_RUNTIME_SWEEPER_HPP #define SHARE_VM_RUNTIME_SWEEPER_HPP +#include "utilities/ticks.hpp" // An NmethodSweeper is an incremental cleaner for: // - cleanup inline caches // - reclamation of nmethods @@ -71,10 +72,10 @@ // 3) zombie -> marked_for_reclamation // Stat counters static int _total_nof_methods_reclaimed; // Accumulated nof methods flushed - static jlong _total_time_sweeping; // Accumulated time sweeping - static jlong _total_time_this_sweep; // Total time this sweep - static jlong _peak_sweep_time; // Peak time for a full sweep - static jlong _peak_sweep_fraction_time; // Peak time sweeping one fraction + static Tickspan _total_time_sweeping; // Accumulated time sweeping + static Tickspan _total_time_this_sweep; // Total time this sweep + static Tickspan _peak_sweep_time; // Peak time for a full sweep + static Tickspan _peak_sweep_fraction_time; // Peak time sweeping one fraction static int process_nmethod(nmethod *nm); static void release_nmethod(nmethod* nm); @@ -87,9 +88,9 @@ public: static long traversal_count() { return _traversals; } static int total_nof_methods_reclaimed() { return _total_nof_methods_reclaimed; } - static jlong total_time_sweeping() { return _total_time_sweeping; } - static jlong peak_sweep_time() { return _peak_sweep_time; } - static jlong peak_sweep_fraction_time() { return _peak_sweep_fraction_time; } + static const Tickspan total_time_sweeping() { return _total_time_sweeping; } + static const Tickspan peak_sweep_time() { return _peak_sweep_time; } + static const Tickspan peak_sweep_fraction_time() { return _peak_sweep_fraction_time; } static void log_sweep(const char* msg, const char* format = NULL, ...); diff -r 941f6e3a1567 -r 41eaa9a17059 hotspot/src/share/vm/trace/noTraceBackend.hpp --- a/hotspot/src/share/vm/trace/noTraceBackend.hpp Sat Nov 23 09:56:59 2013 +0100 +++ b/hotspot/src/share/vm/trace/noTraceBackend.hpp Sat Nov 23 12:25:13 2013 +0100 @@ -25,9 +25,7 @@ #define SHARE_VM_TRACE_NOTRACEBACKEND_HPP #include "prims/jni.h" - -typedef jlong TracingTime; -typedef jlong RelativeTracingTime; +#include "trace/traceTime.hpp" class NoTraceBackend { public: @@ -44,5 +42,3 @@ typedef NoTraceBackend Tracing; #endif - - diff -r 941f6e3a1567 -r 41eaa9a17059 hotspot/src/share/vm/trace/trace.xml --- a/hotspot/src/share/vm/trace/trace.xml Sat Nov 23 09:56:59 2013 +0100 +++ b/hotspot/src/share/vm/trace/trace.xml Sat Nov 23 12:25:13 2013 +0100 @@ -176,8 +176,8 @@ - - + + class TraceEvent : public StackObj { - protected: - jlong _startTime; - jlong _endTime; - private: bool _started; #ifdef ASSERT @@ -54,6 +51,18 @@ bool _ignore_check; #endif + protected: + jlong _startTime; + jlong _endTime; + + void set_starttime(const TracingTime& time) { + _startTime = time; + } + + void set_endtime(const TracingTime& time) { + _endTime = time; + } + public: TraceEvent(EventStartTime timing=TIMED) : _startTime(0), @@ -100,12 +109,12 @@ set_commited(); } - void set_starttime(jlong time) { - _startTime = time; + void set_starttime(const Ticks& time) { + _startTime = time.value(); } - void set_endtime(jlong time) { - _endTime = time; + void set_endtime(const Ticks& time) { + _endTime = time.value(); } TraceEventId id() const { diff -r 941f6e3a1567 -r 41eaa9a17059 hotspot/src/share/vm/trace/traceEventClasses.xsl --- a/hotspot/src/share/vm/trace/traceEventClasses.xsl Sat Nov 23 09:56:59 2013 +0100 +++ b/hotspot/src/share/vm/trace/traceEventClasses.xsl Sat Nov 23 12:25:13 2013 +0100 @@ -40,6 +40,7 @@ #include "tracefiles/traceTypes.hpp" #include "trace/traceEvent.hpp" #include "utilities/macros.hpp" +#include "utilities/ticks.hpp" #if INCLUDE_TRACE @@ -55,8 +56,8 @@ class TraceEvent { public: TraceEvent() {} - void set_starttime(jlong time) const {} - void set_endtime(jlong time) const {} + void set_starttime(const Ticks& time) {} + void set_endtime(const Ticks& time) {} bool should_commit() const { return false; } void commit() const {} }; @@ -170,23 +171,23 @@ - #if INCLUDE_TRACE - + #else - + #endif - + #if INCLUDE_TRACE - + #else - + #endif + @@ -226,7 +227,17 @@ - + + + + + + + + + + + ts.print(", "); diff -r 941f6e3a1567 -r 41eaa9a17059 hotspot/src/share/vm/trace/traceTime.hpp --- a/hotspot/src/share/vm/trace/traceTime.hpp Sat Nov 23 09:56:59 2013 +0100 +++ b/hotspot/src/share/vm/trace/traceTime.hpp Sat Nov 23 12:25:13 2013 +0100 @@ -28,6 +28,5 @@ #include "prims/jni.h" typedef jlong TracingTime; -typedef jlong RelativeTracingTime; -#endif +#endif // SHARE_VM_TRACE_TRACETIME_HPP diff -r 941f6e3a1567 -r 41eaa9a17059 hotspot/src/share/vm/trace/traceTypes.xsl --- a/hotspot/src/share/vm/trace/traceTypes.xsl Sat Nov 23 09:56:59 2013 +0100 +++ b/hotspot/src/share/vm/trace/traceTypes.xsl Sat Nov 23 12:25:13 2013 +0100 @@ -32,9 +32,11 @@ #ifndef TRACEFILES_JFRTYPES_HPP #define TRACEFILES_JFRTYPES_HPP +#include "oops/symbol.hpp" #include "trace/traceDataTypes.hpp" #include "utilities/globalDefinitions.hpp" -#include "oops/symbol.hpp" +#include "utilities/ticks.hpp" + enum JVMContentType { _not_a_content_type = (JVM_CONTENT_TYPES_START - 1), diff -r 941f6e3a1567 -r 41eaa9a17059 hotspot/src/share/vm/trace/tracetypes.xml --- a/hotspot/src/share/vm/trace/tracetypes.xml Sat Nov 23 09:56:59 2013 +0100 +++ b/hotspot/src/share/vm/trace/tracetypes.xml Sat Nov 23 12:25:13 2013 +0100 @@ -249,13 +249,13 @@ - + + type="Ticks" sizeop="sizeof(s8)"/> - - + + = start, "negative time!"); + + _span_ticks = end.value() - start.value(); +} + +template +static ReturnType time_conversion(const Tickspan& span, TicksToTimeHelper::Unit unit) { + assert(TicksToTimeHelper::SECONDS == unit || + TicksToTimeHelper::MILLISECONDS == unit, "invalid unit!"); + + ReturnType frequency_per_unit = (ReturnType)os::elapsed_frequency() / (ReturnType)unit; + + return (ReturnType) ((ReturnType)span.value() / frequency_per_unit); +} + +double TicksToTimeHelper::seconds(const Tickspan& span) { + return time_conversion(span, SECONDS); +} + +jlong TicksToTimeHelper::milliseconds(const Tickspan& span) { + return time_conversion(span, MILLISECONDS); +} diff -r 941f6e3a1567 -r 41eaa9a17059 hotspot/src/share/vm/utilities/ticks.hpp --- /dev/null Thu Jan 01 00:00:00 1970 +0000 +++ b/hotspot/src/share/vm/utilities/ticks.hpp Sat Nov 23 12:25:13 2013 +0100 @@ -0,0 +1,111 @@ +/* + * Copyright (c) 2013, Oracle and/or its affiliates. All rights reserved. + * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER. + * + * This code is free software; you can redistribute it and/or modify it + * under the terms of the GNU General Public License version 2 only, as + * published by the Free Software Foundation. + * + * This code is distributed in the hope that it will be useful, but WITHOUT + * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or + * FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License + * version 2 for more details (a copy is included in the LICENSE file that + * accompanied this code). + * + * You should have received a copy of the GNU General Public License version + * 2 along with this work; if not, write to the Free Software Foundation, + * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA. + * + * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA + * or visit www.oracle.com if you need additional information or have any + * questions. + * + */ + +#ifndef SHARE_VM_UTILITIES_TICKS_HPP +#define SHARE_VM_UTILITIES_TICKS_HPP + +#include "memory/allocation.hpp" +#include "utilities/globalDefinitions.hpp" + +class Ticks; + +class Tickspan VALUE_OBJ_CLASS_SPEC { + friend class Ticks; + friend Tickspan operator-(const Ticks& end, const Ticks& start); + + private: + jlong _span_ticks; + + Tickspan(const Ticks& end, const Ticks& start); + + public: + Tickspan() : _span_ticks(0) {} + + Tickspan& operator+=(const Tickspan& rhs) { + _span_ticks += rhs._span_ticks; + return *this; + } + + jlong value() const { + return _span_ticks; + } + +}; + +class Ticks VALUE_OBJ_CLASS_SPEC { + private: + jlong _stamp_ticks; + + public: + Ticks() : _stamp_ticks(0) { + assert((_stamp_ticks = invalid_time_stamp) == invalid_time_stamp, + "initial unstamped time value assignment"); + } + + Ticks& operator+=(const Tickspan& span) { + _stamp_ticks += span.value(); + return *this; + } + + Ticks& operator-=(const Tickspan& span) { + _stamp_ticks -= span.value(); + return *this; + } + + void stamp(); + + jlong value() const { + return _stamp_ticks; + } + + static const Ticks now(); + +#ifdef ASSERT + static const jlong invalid_time_stamp; +#endif + +#ifndef PRODUCT + // only for internal use by GC VM tests + friend class TimePartitionPhasesIteratorTest; + friend class GCTimerTest; + + private: + // implicit type conversion + Ticks(int ticks) : _stamp_ticks(ticks) {} + +#endif // !PRODUCT + +}; + +class TicksToTimeHelper : public AllStatic { + public: + enum Unit { + SECONDS = 1, + MILLISECONDS = 1000 + }; + static double seconds(const Tickspan& span); + static jlong milliseconds(const Tickspan& span); +}; + +#endif // SHARE_VM_UTILITIES_TICKS_HPP diff -r 941f6e3a1567 -r 41eaa9a17059 hotspot/src/share/vm/utilities/ticks.inline.hpp --- /dev/null Thu Jan 01 00:00:00 1970 +0000 +++ b/hotspot/src/share/vm/utilities/ticks.inline.hpp Sat Nov 23 12:25:13 2013 +0100 @@ -0,0 +1,97 @@ +/* + * Copyright (c) 2013, Oracle and/or its affiliates. All rights reserved. + * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER. + * + * This code is free software; you can redistribute it and/or modify it + * under the terms of the GNU General Public License version 2 only, as + * published by the Free Software Foundation. + * + * This code is distributed in the hope that it will be useful, but WITHOUT + * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or + * FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License + * version 2 for more details (a copy is included in the LICENSE file that + * accompanied this code). + * + * You should have received a copy of the GNU General Public License version + * 2 along with this work; if not, write to the Free Software Foundation, + * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA. + * + * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA + * or visit www.oracle.com if you need additional information or have any + * questions. + * + */ + +#ifndef SHARE_VM_UTILITIES_TICKS_INLINE_HPP +#define SHARE_VM_UTILITIES_TICKS_INLINE_HPP + +#include "utilities/ticks.hpp" + +inline Tickspan operator+(Tickspan lhs, const Tickspan& rhs) { + lhs += rhs; + return lhs; +} + +inline bool operator==(const Tickspan& lhs, const Tickspan& rhs) { + return lhs.value() == rhs.value(); +} + +inline bool operator!=(const Tickspan& lhs, const Tickspan& rhs) { + return !operator==(lhs,rhs); +} + +inline bool operator<(const Tickspan& lhs, const Tickspan& rhs) { + return lhs.value() < rhs.value(); +} + +inline bool operator>(const Tickspan& lhs, const Tickspan& rhs) { + return operator<(rhs,lhs); +} + +inline bool operator<=(const Tickspan& lhs, const Tickspan& rhs) { + return !operator>(lhs,rhs); +} + +inline bool operator>=(const Tickspan& lhs, const Tickspan& rhs) { + return !operator<(lhs,rhs); +} + +inline Ticks operator+(Ticks lhs, const Tickspan& span) { + lhs += span; + return lhs; +} + +inline Ticks operator-(Ticks lhs, const Tickspan& span) { + lhs -= span; + return lhs; +} + +inline Tickspan operator-(const Ticks& end, const Ticks& start) { + return Tickspan(end, start); +} + +inline bool operator==(const Ticks& lhs, const Ticks& rhs) { + return lhs.value() == rhs.value(); +} + +inline bool operator!=(const Ticks& lhs, const Ticks& rhs) { + return !operator==(lhs,rhs); +} + +inline bool operator<(const Ticks& lhs, const Ticks& rhs) { + return lhs.value() < rhs.value(); +} + +inline bool operator>(const Ticks& lhs, const Ticks& rhs) { + return operator<(rhs,lhs); +} + +inline bool operator<=(const Ticks& lhs, const Ticks& rhs) { + return !operator>(lhs,rhs); +} + +inline bool operator>=(const Ticks& lhs, const Ticks& rhs) { + return !operator<(lhs,rhs); +} + +#endif // SHARE_VM_UTILITIES_TICKS_INLINE_HPP