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