--- old/src/share/vm/gc_implementation/concurrentMarkSweep/concurrentMarkSweepGeneration.cpp Wed Jul 21 17:06:31 2010 +++ new/src/share/vm/gc_implementation/concurrentMarkSweep/concurrentMarkSweepGeneration.cpp Wed Jul 21 17:06:30 2010 @@ -1970,6 +1970,9 @@ _intra_sweep_estimate.padded_average()); } + { + TraceCMSMemoryManagerStats(); + } GenMarkSweep::invoke_at_safepoint(_cmsGen->level(), ref_processor(), clear_all_soft_refs); #ifdef ASSERT @@ -3420,6 +3423,7 @@ void CMSCollector::checkpointRootsInitial(bool asynch) { assert(_collectorState == InitialMarking, "Wrong collector state"); check_correct_thread_executing(); + TraceCMSMemoryManagerStats tms(_collectorState); ReferenceProcessor* rp = ref_processor(); SpecializationStats::clear(); assert(_restart_addr == NULL, "Control point invariant"); @@ -4753,6 +4757,7 @@ // world is stopped at this checkpoint assert(SafepointSynchronize::is_at_safepoint(), "world should be stopped"); + TraceCMSMemoryManagerStats tms(_collectorState); verify_work_stacks_empty(); verify_overflow_empty(); @@ -5854,6 +5859,8 @@ verify_work_stacks_empty(); verify_overflow_empty(); increment_sweep_count(); + TraceCMSMemoryManagerStats tms(_collectorState); + _inter_sweep_timer.stop(); _inter_sweep_estimate.sample(_inter_sweep_timer.seconds()); size_policy()->avg_cms_free_at_sweep()->sample(_cmsGen->free()); @@ -9126,3 +9133,57 @@ } return res; } + +TraceCMSMemoryManagerStats::TraceCMSMemoryManagerStats(CMSCollector::CollectorState phase): TraceMemoryManagerStats() { + + switch (phase) { + case CMSCollector::InitialMarking: + initialize(true /* fullGC */ , + true /* recordGCBeginTime */, + true /* recordPreGCUsage */, + false /* recordPeakUsage */, + false /* recordPostGCusage */, + true /* recordAccumulatedGCTime */, + false /* recordGCEndTime */, + false /* countCollection */ ); + break; + + case CMSCollector::FinalMarking: + initialize(true /* fullGC */ , + false /* recordGCBeginTime */, + false /* recordPreGCUsage */, + false /* recordPeakUsage */, + false /* recordPostGCusage */, + true /* recordAccumulatedGCTime */, + false /* recordGCEndTime */, + false /* countCollection */ ); + break; + + case CMSCollector::Sweeping: + initialize(true /* fullGC */ , + false /* recordGCBeginTime */, + false /* recordPreGCUsage */, + true /* recordPeakUsage */, + true /* recordPostGCusage */, + false /* recordAccumulatedGCTime */, + true /* recordGCEndTime */, + true /* countCollection */ ); + break; + + default: + ShouldNotReachHere(); + } +} + +// when bailing out of cms in concurrent mode failure +TraceCMSMemoryManagerStats::TraceCMSMemoryManagerStats(): TraceMemoryManagerStats() { + initialize(true /* fullGC */ , + true /* recordGCBeginTime */, + true /* recordPreGCUsage */, + true /* recordPeakUsage */, + true /* recordPostGCusage */, + true /* recordAccumulatedGCTime */, + true /* recordGCEndTime */, + true /* countCollection */ ); +} + --- old/src/share/vm/gc_implementation/concurrentMarkSweep/concurrentMarkSweepGeneration.hpp Wed Jul 21 17:06:34 2010 +++ new/src/share/vm/gc_implementation/concurrentMarkSweep/concurrentMarkSweepGeneration.hpp Wed Jul 21 17:06:33 2010 @@ -507,6 +507,7 @@ friend class VM_CMS_Operation; friend class VM_CMS_Initial_Mark; friend class VM_CMS_Final_Remark; + friend class TraceCMSMemoryManagerStats; private: jlong _time_of_last_gc; @@ -1858,3 +1859,11 @@ _dead_bit_map(dead_bit_map) {} size_t do_blk(HeapWord* addr); }; + +class TraceCMSMemoryManagerStats : public TraceMemoryManagerStats { + + public: + TraceCMSMemoryManagerStats(CMSCollector::CollectorState phase); + TraceCMSMemoryManagerStats(); +}; + --- old/src/share/vm/gc_implementation/includeDB_gc_concurrentMarkSweep Wed Jul 21 17:06:35 2010 +++ new/src/share/vm/gc_implementation/includeDB_gc_concurrentMarkSweep Wed Jul 21 17:06:35 2010 @@ -149,6 +149,7 @@ concurrentMarkSweepGeneration.cpp iterator.hpp concurrentMarkSweepGeneration.cpp java.hpp concurrentMarkSweepGeneration.cpp jvmtiExport.hpp +concurrentMarkSweepGeneration.cpp memoryService.hpp concurrentMarkSweepGeneration.cpp oop.inline.hpp concurrentMarkSweepGeneration.cpp parNewGeneration.hpp concurrentMarkSweepGeneration.cpp referencePolicy.hpp @@ -165,6 +166,7 @@ concurrentMarkSweepGeneration.hpp gcStats.hpp concurrentMarkSweepGeneration.hpp generation.hpp concurrentMarkSweepGeneration.hpp generationCounters.hpp +concurrentMarkSweepGeneration.hpp memoryService.hpp concurrentMarkSweepGeneration.hpp mutexLocker.hpp concurrentMarkSweepGeneration.hpp taskqueue.hpp concurrentMarkSweepGeneration.hpp virtualspace.hpp --- old/src/share/vm/services/memoryManager.cpp Wed Jul 21 17:06:37 2010 +++ new/src/share/vm/services/memoryManager.cpp Wed Jul 21 17:06:36 2010 @@ -190,64 +190,105 @@ GCMemoryManager::GCMemoryManager() : MemoryManager() { _num_collections = 0; _last_gc_stat = NULL; + _current_gc_stat = NULL; _num_gc_threads = 1; } GCMemoryManager::~GCMemoryManager() { delete _last_gc_stat; + delete _current_gc_stat; } void GCMemoryManager::initialize_gc_stat_info() { assert(MemoryService::num_memory_pools() > 0, "should have one or more memory pools"); _last_gc_stat = new GCStatInfo(MemoryService::num_memory_pools()); + _current_gc_stat = new GCStatInfo(MemoryService::num_memory_pools()); + // tracking concurrent collections requires two objects: one to update, and one to + // be the publicly available "last (completed) gc". } -void GCMemoryManager::gc_begin() { - assert(_last_gc_stat != NULL, "Just checking"); - _accumulated_timer.start(); - _num_collections++; - _last_gc_stat->set_index(_num_collections); - _last_gc_stat->set_start_time(Management::timestamp()); +void GCMemoryManager::gc_begin(bool recordGCBeginTime, bool recordPreGCUsage, + bool recordAccumulatedGCTime) { + assert(_last_gc_stat != NULL && _current_gc_stat != NULL, "Just checking"); + if (recordAccumulatedGCTime) { + _accumulated_timer.start(); + } + // _num_collections now increases in gc_end, to count completed collections + if (recordGCBeginTime) { + _current_gc_stat->set_index(_num_collections+1); + _current_gc_stat->set_start_time(Management::timestamp()); + } - // Keep memory usage of all memory pools - for (int i = 0; i < MemoryService::num_memory_pools(); i++) { - MemoryPool* pool = MemoryService::get_memory_pool(i); - MemoryUsage usage = pool->get_memory_usage(); - _last_gc_stat->set_before_gc_usage(i, usage); - HS_DTRACE_PROBE8(hotspot, mem__pool__gc__begin, - name(), strlen(name()), - pool->name(), strlen(pool->name()), - usage.init_size(), usage.used(), - usage.committed(), usage.max_size()); + if (recordPreGCUsage) { + // Keep memory usage of all memory pools + for (int i = 0; i < MemoryService::num_memory_pools(); i++) { + MemoryPool* pool = MemoryService::get_memory_pool(i); + MemoryUsage usage = pool->get_memory_usage(); + _current_gc_stat->set_before_gc_usage(i, usage); + HS_DTRACE_PROBE8(hotspot, mem__pool__gc__begin, + name(), strlen(name()), + pool->name(), strlen(pool->name()), + usage.init_size(), usage.used(), + usage.committed(), usage.max_size()); + } } } -void GCMemoryManager::gc_end() { - _accumulated_timer.stop(); - _last_gc_stat->set_end_time(Management::timestamp()); +// A collector MUST, even if it does not complete for some reason, +// make a TraceMemoryManagerStats object where countCollection is true, +// to ensure the current gc stat is placed in _last_gc_stat. +void GCMemoryManager::gc_end(bool recordPostGCUsage, + bool recordAccumulatedGCTime, + bool recordGCEndTime, bool countCollection) { + if (recordAccumulatedGCTime) { + _accumulated_timer.stop(); + } + if (recordGCEndTime) { + _current_gc_stat->set_end_time(Management::timestamp()); + } - int i; - // keep the last gc statistics for all memory pools - for (i = 0; i < MemoryService::num_memory_pools(); i++) { - MemoryPool* pool = MemoryService::get_memory_pool(i); - MemoryUsage usage = pool->get_memory_usage(); + if (recordPostGCUsage) { + int i; + // keep the last gc statistics for all memory pools + for (i = 0; i < MemoryService::num_memory_pools(); i++) { + MemoryPool* pool = MemoryService::get_memory_pool(i); + MemoryUsage usage = pool->get_memory_usage(); - HS_DTRACE_PROBE8(hotspot, mem__pool__gc__end, - name(), strlen(name()), - pool->name(), strlen(pool->name()), - usage.init_size(), usage.used(), - usage.committed(), usage.max_size()); + HS_DTRACE_PROBE8(hotspot, mem__pool__gc__end, + name(), strlen(name()), + pool->name(), strlen(pool->name()), + usage.init_size(), usage.used(), + usage.committed(), usage.max_size()); - _last_gc_stat->set_after_gc_usage(i, usage); - } + _current_gc_stat->set_after_gc_usage(i, usage); + } - // Set last collection usage of the memory pools managed by this collector - for (i = 0; i < num_memory_pools(); i++) { - MemoryPool* pool = get_memory_pool(i); - MemoryUsage usage = pool->get_memory_usage(); + // Set last collection usage of the memory pools managed by this collector + for (i = 0; i < num_memory_pools(); i++) { + MemoryPool* pool = get_memory_pool(i); + MemoryUsage usage = pool->get_memory_usage(); - // Compare with GC usage threshold - pool->set_last_collection_usage(usage); - LowMemoryDetector::detect_after_gc_memory(pool); + // Compare with GC usage threshold + pool->set_last_collection_usage(usage); + LowMemoryDetector::detect_after_gc_memory(pool); + } } + if (countCollection) { + _num_collections++; + // alternately update two objects making one public when complete + GCStatInfo *tmp = _last_gc_stat; + _last_gc_stat = _current_gc_stat; + _current_gc_stat = tmp; +#ifdef ASSERT + // reset the current stat for diagnosability purposes + _current_gc_stat->set_index(0); + _current_gc_stat->set_start_time(0); + _current_gc_stat->set_end_time(0); + for (int i = 0; i < MemoryService::num_memory_pools(); i++) { + MemoryUsage empty_usage = MemoryUsage(); + _current_gc_stat->set_before_gc_usage(i, empty_usage); + _current_gc_stat->set_after_gc_usage(i, empty_usage); + } +#endif + } } --- old/src/share/vm/services/memoryManager.hpp Wed Jul 21 17:06:38 2010 +++ new/src/share/vm/services/memoryManager.hpp Wed Jul 21 17:06:38 2010 @@ -152,7 +152,8 @@ size_t _num_collections; elapsedTimer _accumulated_timer; elapsedTimer _gc_timer; // for measuring every GC duration - GCStatInfo* _last_gc_stat; + GCStatInfo* volatile _last_gc_stat; + GCStatInfo* volatile _current_gc_stat; int _num_gc_threads; public: GCMemoryManager(); @@ -166,11 +167,14 @@ int num_gc_threads() { return _num_gc_threads; } void set_num_gc_threads(int count) { _num_gc_threads = count; } - void gc_begin(); - void gc_end(); + void gc_begin(bool recordGCBeginTime, bool recordPreGCUsage, + bool recordAccumulatedGCTime); + void gc_end(bool recordPostGCUsage, bool recordAccumulatedGCTime, + bool recordGCEndTime, bool countCollection); + void reset_gc_stat() { _num_collections = 0; _accumulated_timer.reset(); } - GCStatInfo* last_gc_stat() { return _last_gc_stat; } + GCStatInfo* last_gc_stat() { return _last_gc_stat; } virtual MemoryManager::Name kind() = 0; }; --- old/src/share/vm/services/memoryService.cpp Wed Jul 21 17:06:39 2010 +++ new/src/share/vm/services/memoryService.cpp Wed Jul 21 17:06:39 2010 @@ -509,7 +509,10 @@ } } -void MemoryService::gc_begin(bool fullGC) { +void MemoryService::gc_begin(bool fullGC, bool recordGCBeginTime, + bool recordAccumulatedGCTime, + bool recordPreGCUsage, bool recordPeakUsage) { + GCMemoryManager* mgr; if (fullGC) { mgr = _major_gc_manager; @@ -517,16 +520,21 @@ mgr = _minor_gc_manager; } assert(mgr->is_gc_memory_manager(), "Sanity check"); - mgr->gc_begin(); + mgr->gc_begin(recordGCBeginTime, recordPreGCUsage, recordAccumulatedGCTime); // Track the peak memory usage when GC begins - for (int i = 0; i < _pools_list->length(); i++) { - MemoryPool* pool = _pools_list->at(i); - pool->record_peak_memory_usage(); + if (recordPeakUsage) { + for (int i = 0; i < _pools_list->length(); i++) { + MemoryPool* pool = _pools_list->at(i); + pool->record_peak_memory_usage(); + } } } -void MemoryService::gc_end(bool fullGC) { +void MemoryService::gc_end(bool fullGC, bool recordPostGCUsage, + bool recordAccumulatedGCTime, + bool recordGCEndTime, bool countCollection) { + GCMemoryManager* mgr; if (fullGC) { mgr = (GCMemoryManager*) _major_gc_manager; @@ -536,7 +544,8 @@ assert(mgr->is_gc_memory_manager(), "Sanity check"); // register the GC end statistics and memory usage - mgr->gc_end(); + mgr->gc_end(recordPostGCUsage, recordAccumulatedGCTime, recordGCEndTime, + countCollection); } void MemoryService::oops_do(OopClosure* f) { @@ -585,12 +594,12 @@ return obj; } // -// GC manager type depends on the type of Generation. Depending the space -// availablity and vm option the gc uses major gc manager or minor gc +// GC manager type depends on the type of Generation. Depending on the space +// availablity and vm options the gc uses major gc manager or minor gc // manager or both. The type of gc manager depends on the generation kind. -// For DefNew, ParNew and ASParNew generation doing scavange gc uses minor -// gc manager (so _fullGC is set to false ) and for other generation kind -// DOing mark-sweep-compact uses major gc manager (so _fullGC is set +// For DefNew, ParNew and ASParNew generation doing scavenge gc uses minor +// gc manager (so _fullGC is set to false ) and for other generation kinds +// doing mark-sweep-compact uses major gc manager (so _fullGC is set // to true). TraceMemoryManagerStats::TraceMemoryManagerStats(Generation::Name kind) { switch (kind) { @@ -611,13 +620,48 @@ default: assert(false, "Unrecognized gc generation kind."); } - MemoryService::gc_begin(_fullGC); + // this has to be called in a stop the world pause and represent + // an entire gc pause, start to finish: + initialize(_fullGC, true, true, true, true, true, true, true); } -TraceMemoryManagerStats::TraceMemoryManagerStats(bool fullGC) { +TraceMemoryManagerStats::TraceMemoryManagerStats(bool fullGC, + bool recordGCBeginTime, + bool recordPreGCUsage, + bool recordPeakUsage, + bool recordPostGCUsage, + bool recordAccumulatedGCTime, + bool recordGCEndTime, + bool countCollection) { + initialize(fullGC, recordGCBeginTime, recordPreGCUsage, recordPeakUsage, + recordPostGCUsage, recordAccumulatedGCTime, recordGCEndTime, + countCollection); +} + +// for a subclass to create then initialize an instance before invoking +// the MemoryService +void TraceMemoryManagerStats::initialize(bool fullGC, + bool recordGCBeginTime, + bool recordPreGCUsage, + bool recordPeakUsage, + bool recordPostGCUsage, + bool recordAccumulatedGCTime, + bool recordGCEndTime, + bool countCollection) { _fullGC = fullGC; - MemoryService::gc_begin(_fullGC); + _recordGCBeginTime = recordGCBeginTime; + _recordPreGCUsage = recordPreGCUsage; + _recordPeakUsage = recordPeakUsage; + _recordPostGCUsage = recordPostGCUsage; + _recordAccumulatedGCTime = recordAccumulatedGCTime; + _recordGCEndTime = recordGCEndTime; + _countCollection = countCollection; + + MemoryService::gc_begin(_fullGC, _recordGCBeginTime, _recordAccumulatedGCTime, + _recordPreGCUsage, _recordPeakUsage); } TraceMemoryManagerStats::~TraceMemoryManagerStats() { - MemoryService::gc_end(_fullGC); + MemoryService::gc_end(_fullGC, _recordPostGCUsage, _recordAccumulatedGCTime, + _recordGCEndTime, _countCollection); } + --- old/src/share/vm/services/memoryService.hpp Wed Jul 21 17:06:41 2010 +++ new/src/share/vm/services/memoryService.hpp Wed Jul 21 17:06:40 2010 @@ -149,9 +149,14 @@ } static void track_memory_pool_usage(MemoryPool* pool); - static void gc_begin(bool fullGC); - static void gc_end(bool fullGC); + static void gc_begin(bool fullGC, bool recordGCBeginTime, + bool recordAccumulatedGCTime, + bool recordPreGCUsage, bool recordPeakUsage); + static void gc_end(bool fullGC, bool recordPostGCUsage, + bool recordAccumulatedGCTime, + bool recordGCEndTime, bool countCollection); + static void oops_do(OopClosure* f); static bool get_verbose() { return PrintGC; } @@ -164,8 +169,34 @@ class TraceMemoryManagerStats : public StackObj { private: bool _fullGC; + bool _recordGCBeginTime; + bool _recordPreGCUsage; + bool _recordPeakUsage; + bool _recordPostGCUsage; + bool _recordAccumulatedGCTime; + bool _recordGCEndTime; + bool _countCollection; + public: - TraceMemoryManagerStats(bool fullGC); + TraceMemoryManagerStats() {} + TraceMemoryManagerStats(bool fullGC, + bool recordGCBeginTime = true, + bool recordPreGCUsage = true, + bool recordPeakUsage = true, + bool recordPostGCUsage = true, + bool recordAccumulatedGCTime = true, + bool recordGCEndTime = true, + bool countCollection = true); + + void initialize(bool fullGC, + bool recordGCBeginTime, + bool recordPreGCUsage, + bool recordPeakUsage, + bool recordPostGCUsage, + bool recordAccumulatedGCTime, + bool recordGCEndTime, + bool countCollection); + TraceMemoryManagerStats(Generation::Name kind); ~TraceMemoryManagerStats(); }; --- /dev/null Wed Jul 21 17:06:42 2010 +++ new/test/gc/6581734/Test6581734.java Wed Jul 21 17:06:42 2010 @@ -0,0 +1,164 @@ +/* + * Copyright (c) 2010, 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. + */ + +/* + * @test Test6581734.java + * @bug 6581734 + * @summary CMS Old Gen's collection usage is zero after GC which is incorrect + * @run main/othervm -server -Xmx512m -verbose:gc -XX:+UseConcMarkSweepGC Test6581734 + * + */ +import java.util.*; +import java.lang.management.*; + +// 6581734 states that memory pool usage via the mbean is wrong +// for CMS (zero, even after a collection). +// +// 6580448 states that the collection count similarly is wrong +// (stays at zero for CMS collections) +// -- closed as dup of 6581734 as the same fix resolves both. + + +public class Test6581734 { + +private String poolName = "CMS"; +private String collectorName = "ConcurrentMarkSweep"; + +public static void main(String [] args) { + + Test6581734 t = null; + if (args.length==2) { + t = new Test6581734(args[0], args[1]); + } else { + System.out.println("Defaulting to monitor CMS pool and collector."); + t = new Test6581734(); + } + t.run(); + +} + +public Test6581734(String pool, String collector) { + poolName = pool; + collectorName = collector; +} +public Test6581734() { +} + +public void run() { + + // Use some memory, enough that we expect collections should + // have happened. + // Must run with options to ensure no stop the world full GC, + // but e.g. at least one CMS cycle. + + allocationWork(300*1024*1024); + System.out.println("Done allocationWork"); + + // Verify some non-zero results are stored. + + List pools = + ManagementFactory.getMemoryPoolMXBeans(); + int poolsFound = 0; + int poolsWithStats = 0; + for (int i=0; i collectors = + ManagementFactory.getGarbageCollectorMXBeans(); + int collectorsFound = 0; + int collectorsWithTime= 0; + for (int i=0; i 0) { + collectorsWithTime++; + } + } + } + // verify: + if (poolsWithStats < poolsFound) { + throw new RuntimeException("pools found with zero stats"); + } + + if (collectorsWithTime