SerialGC: Tracing of object movement during SerialGC
Mikael Gerdin
mikael.gerdin at oracle.com
Wed Sep 21 11:34:49 UTC 2016
Hi Alok,
On 2016-09-21 06:41, Sharma, Alok Kumar (OSTL) wrote:
> Just a reminder…
>
>
>
> Can someone please review this?
First of all, thanks for your email.
I have two comments about this change in particular.
1) JDK 9 is now way past its Feature Complete date (with some exceptions
for specific projects) and this feels a lot more like a feature /
enhancement than a bug fix to me. If this change were to be considered
for inclusion then it would need to target a later release.
2) In general this is pretty specific tracing code which you suggest
that we add in the hottest code paths of the serial gc. For any non
trivial workload the overhead and amount of output this tracing code
would generate will be enormous. I'm just not certain that having this
code in the repo is worth it with regard to its maintenance. If for any
reason this kind of detailed "printf-debugging code" is needed then it
is easy to add it in a special ad-hoc build.
Thanks
/Mikael
>
>
>
> Regards,
>
> Alok
>
>
>
> *From:* hotspot-gc-dev [mailto:hotspot-gc-dev-bounces at openjdk.java.net]
> *On Behalf Of *Sharma, Alok Kumar (OSTL)
> *Sent:* Monday, September 19, 2016 1:46 PM
> *To:* hotspot-gc-dev at openjdk.java.net
> *Subject:* SerialGC: Tracing of object movement during SerialGC
>
>
>
> As part of the work on a particular bug, we felt a need for tracing logs
> in Hotspot serial GC to observe Java object movement. As a result, the
> serial GC tracing logs were enhanced to provide information about when:
>
>
>
> 1. Objects are marked
>
> 2. Pointers pointing to these objects are adjusted
>
> 3. Moving of objects
>
>
>
> Usage:
>
> jdk9/build/linux-x86_64-rmal-server-slowdebug/jdk/bin/java
> -Xlog:gc+dump=trace -XX:+UseSerialGC -Xmx4m
> -XX:GCTraceFunctionFilter="java/lang/String" <test>
>
>
>
> Regards,
>
> Alok
>
>
>
> Below is the mercurial diff with openJDK 9
>
>
>
> hg diff jdk9b132_4Aug2016/hotspot/src/
>
>
>
> diff -r a3a3621d555a src/share/vm/gc/serial/defNewGeneration.cpp
>
> --- a/src/share/vm/gc/serial/defNewGeneration.cpp Thu Aug 04
> 17:32:52 2016 +0000
>
> +++ b/src/share/vm/gc/serial/defNewGeneration.cpp Mon Sep 19 11:28:49
> 2016 +0530
>
> @@ -762,6 +762,8 @@
>
> }
>
> }
>
>
>
> +extern Symbol *serial_class_trace_name;
>
> +
>
> oop DefNewGeneration::copy_to_survivor_space(oop old) {
>
> assert(is_in_reserved(old) && !old->is_forwarded(),
>
> "shouldn't be scavenging this oop"); @@ -793,6 +795,20 @@
>
> age_table()->add(obj, s);
>
> }
>
>
>
> + if(log_develop_is_enabled(Trace, gc, dump)) {
>
> + Klass *klass = obj->klass();
>
> + if(klass) {
>
> + Symbol *name = klass->name();
>
> + if((GCTraceOnlyClass == NULL) ||
>
> + (name && (serial_class_trace_name == name))) {
>
> +
>
> + log_develop_trace(gc, dump)("copy_to_survivor_space old %p
> new %p ",old, obj);
>
> + log_develop_trace(gc, dump)("obj name %s \n",
> name->as_C_string());
>
> + }
>
> + }
>
> + }
>
> +
>
> +
>
> // Done, insert forward pointer to obj in this header
>
> old->forward_to(obj);
>
>
>
> diff -r a3a3621d555a src/share/vm/gc/serial/markSweep.cpp
>
> --- a/src/share/vm/gc/serial/markSweep.cpp Thu Aug 04 17:32:52 2016 +0000
>
> +++ b/src/share/vm/gc/serial/markSweep.cpp Mon Sep 19 11:28:49 2016 +0530
>
> @@ -64,6 +64,14 @@
>
> CLDToOopClosure
> MarkSweep::follow_cld_closure(&mark_and_push_closure);
>
> CLDToOopClosure
> MarkSweep::adjust_cld_closure(&adjust_pointer_closure);
>
>
>
> +Symbol *serial_class_trace_name = NULL;
>
> +
>
> +void
>
> +SetTraceSymbol(const char *trace_name) {
>
> + Thread* __the_thread__ = Thread::current_or_null();
>
> + serial_class_trace_name = SymbolTable::new_symbol(trace_name,
>
> +strlen(trace_name), CHECK); }
>
> +
>
> inline void MarkSweep::mark_object(oop obj) { #if INCLUDE_ALL_GCS
>
> if (G1StringDedup::is_enabled()) {
>
> @@ -77,6 +85,21 @@
>
> markOop mark = obj->mark();
>
> obj->set_mark(markOopDesc::prototype()->set_marked());
>
>
>
> + if(log_develop_is_enabled(Trace, gc, dump)) {
>
> + Klass *klass = obj->klass();
>
> +
>
> + if(klass) {
>
> + Symbol *name = klass->name();
>
> + if(name) {
>
> + if((GCTraceOnlyClass == NULL) ||
>
> + strstr(strName, GCTraceOnlyClass)) {
>
> + log_develop_trace(gc, dump) ("Mark object obj %p obj
> class name %s", obj, name->as_C_string());
>
> + }
>
> + }
>
> + }
>
> +
>
> + }
>
> +
>
> if (mark->must_be_preserved(obj)) {
>
> preserve_mark(obj, mark);
>
> }
>
> diff -r a3a3621d555a src/share/vm/gc/serial/markSweep.inline.hpp
>
> --- a/src/share/vm/gc/serial/markSweep.inline.hpp Thu Aug 04
> 17:32:52 2016 +0000
>
> +++ b/src/share/vm/gc/serial/markSweep.inline.hpp Mon Sep 19 11:28:49
> 2016 +0530
>
> @@ -46,6 +46,8 @@
>
> return obj->ms_adjust_pointers();
>
> }
>
>
>
> +extern Symbol *serial_class_trace_name;
>
> +
>
> template <class T> inline void MarkSweep::adjust_pointer(T* p) {
>
> T heap_oop = oopDesc::load_heap_oop(p);
>
> if (!oopDesc::is_null(heap_oop)) {
>
> @@ -66,7 +68,22 @@
>
> oopDesc::encode_store_heap_oop_not_null(p, new_obj);
>
> }
>
> }
>
> +
>
> + if(log_develop_is_enabled(Trace, gc, dump)) {
>
> + Klass *klass = obj->klass();
>
> +
>
> + if(klass) {
>
> + Symbol *name = klass->name();
>
> + if((GCTraceOnlyClass == NULL) ||
>
> + (name && (serial_class_trace_name == name))) {
>
> + log_develop_trace(gc, dump)("adjust_pointer ptr %p obj
> class name %s obj %p new_obj %p \n", p, name->as_C_string(), obj, new_obj);
>
> + } else {
>
> + log_develop_trace(gc, dump)("adjust_pointer Corrupted klass?
> name probably not correct # obj %p klass %p name %p \n",obj, klass, name);
>
> + }
>
> + }
>
> + }
>
> }
>
> +
>
> }
>
>
>
> #endif // SHARE_VM_GC_SERIAL_MARKSWEEP_INLINE_HPP
>
> diff -r a3a3621d555a src/share/vm/gc/shared/genOopClosures.inline.hpp
>
> --- a/src/share/vm/gc/shared/genOopClosures.inline.hpp Thu Aug
> 04 17:32:52 2016 +0000
>
> +++ b/src/share/vm/gc/shared/genOopClosures.inline.hpp Mon Sep 19
> 11:28:49 2016 +0530
>
> @@ -99,6 +99,8 @@
>
> inline void ScanClosure::do_oop_nv(oop* p) {
> ScanClosure::do_oop_work(p); }
>
> inline void ScanClosure::do_oop_nv(narrowOop* p) {
> ScanClosure::do_oop_work(p); }
>
>
>
> +extern Symbol *serial_class_trace_name;
>
> +
>
> // NOTE! Any changes made here should also be made // in
> ScanClosure::do_oop_work() template <class T> inline void
> FastScanClosure::do_oop_work(T* p) { @@ -111,6 +113,18 @@
>
> oop new_obj = obj->is_forwarded() ? obj->forwardee()
>
> : _g->copy_to_survivor_space(obj);
>
> oopDesc::encode_store_heap_oop_not_null(p, new_obj);
>
> + if(log_develop_is_enabled(Trace, gc, dump)) {
>
> + Klass *klass = obj->klass();
>
> + if(klass) {
>
> + Symbol *name = klass->name();
>
> + if((GCTraceOnlyClass == NULL) ||
>
> + (name && (serial_class_trace_name == name))) {
>
> + log_develop_trace(gc, dump)("FastScanClosure Updating
> pointer p %p old %p new %p ",p, obj, new_obj);
>
> + log_develop_trace(gc, dump)("obj name %s \n",
> name->as_C_string() );
>
> + }
>
> + }
>
> + }
>
> +
>
> if (is_scanning_a_klass()) {
>
> do_klass_barrier();
>
> } else if (_gc_barrier) {
>
> diff -r a3a3621d555a src/share/vm/runtime/arguments.cpp
>
> --- a/src/share/vm/runtime/arguments.cpp Thu Aug 04 17:32:52 2016
> +0000
>
> +++ b/src/share/vm/runtime/arguments.cpp Mon Sep 19 11:28:49 2016 +0530
>
> @@ -1949,6 +1949,8 @@
>
> log_trace(gc)("MarkStackSize: %uk MarkStackSizeMax: %uk", (unsigned
> int) (MarkStackSize / K), (uint) (MarkStackSizeMax / K)); }
>
>
>
> +extern void SetTraceSymbol(const char *);
>
> +
>
> void Arguments::set_gc_specific_flags() { #if INCLUDE_ALL_GCS
>
> // Set per-collector flags
>
> @@ -1973,6 +1975,12 @@
>
> #endif // INCLUDE_ALL_GCS
>
> }
>
>
>
> +void Arguments::set_gc_specific_flags_after_globals() {
>
> + if(GCTraceOnlyClass != NULL) {
>
> + SetTraceSymbol(GCTraceOnlyClass);
>
> + }
>
> +}
>
> +
>
> julong Arguments::limit_by_allocatable_memory(julong limit) {
>
> julong max_allocatable;
>
> julong result = limit;
>
> diff -r a3a3621d555a src/share/vm/runtime/arguments.hpp
>
> --- a/src/share/vm/runtime/arguments.hpp Thu Aug 04 17:32:52 2016
> +0000
>
> +++ b/src/share/vm/runtime/arguments.hpp Mon Sep 19 11:28:49 2016 +0530
>
> @@ -603,6 +603,7 @@
>
> static jint adjust_after_os();
>
>
>
> static void set_gc_specific_flags();
>
> + static void set_gc_specific_flags_after_globals();
>
> static bool gc_selected(); // whether a gc has been selected
>
> static void select_gc_ergonomically(); #if INCLUDE_JVMCI diff -r
> a3a3621d555a src/share/vm/runtime/globals.hpp
>
> --- a/src/share/vm/runtime/globals.hpp Thu Aug 04 17:32:52
> 2016 +0000
>
> +++ b/src/share/vm/runtime/globals.hpp Mon Sep 19 11:28:49
> 2016 +0530
>
> @@ -1616,6 +1616,11 @@
>
> "blocked by the GC
> locker") \
>
> range(0,
> max_uintx) \
>
>
> \
>
> + product(ccstr, GCTraceOnlyClass, NULL, \
>
> + "Function name on which the GC internal tracing is done.
> Default" \
>
> + "is to be empty and print GC tracing for all functions.
> " \
>
> + )
> \
>
> +
>
>
> + \
>
> product(bool, UseCMSBestFit,
> true, \
>
> "Use CMS best fit allocation
> strategy") \
>
>
> \ diff -r a3a3621d555a src/share/vm/runtime/thread.cpp
>
> --- a/src/share/vm/runtime/thread.cpp Thu Aug 04 17:32:52
> 2016 +0000
>
> +++ b/src/share/vm/runtime/thread.cpp Mon Sep 19 11:28:49
> 2016 +0530
>
> @@ -3626,6 +3626,8 @@
>
> return status;
>
> }
>
>
>
> + Arguments::set_gc_specific_flags_after_globals();
>
> +
>
> if (TRACE_INITIALIZE() != JNI_OK) {
>
> vm_exit_during_initialization("Failed to initialize tracing backend");
>
> }
>
>
>
>
>
>
>
More information about the hotspot-gc-dev
mailing list