X-Git-Url: http://wien.tomnetworks.com/gitweb/?a=blobdiff_plain;f=src%2Fvm%2Fstatistics.c;h=9c07ef78b47af9ea09433e58e58bb31a1d9a0b6e;hb=8b1896a0eef0945f802ea2dbd5edb25ee853b810;hp=6f7ccbb666b35fba570cf836b4df49abe666fb74;hpb=17dc808b0afaacd27e46549208f4501f5e31a301;p=cacao.git diff --git a/src/vm/statistics.c b/src/vm/statistics.c index 6f7ccbb66..9c07ef78b 100644 --- a/src/vm/statistics.c +++ b/src/vm/statistics.c @@ -1,9 +1,7 @@ -/* src/vm/statistics.c - global varables for statistics +/* src/vm/statistics.c - global variables for statistics - Copyright (C) 1996-2005, 2006 R. Grafl, A. Krall, C. Kruegel, - C. Oates, R. Obermaisser, M. Platter, M. Probst, S. Ring, - E. Steiner, C. Thalinger, D. Thuernbeck, P. Tomsich, C. Ullrich, - J. Wenninger, Institut f. Computersprachen - TU Wien + Copyright (C) 1996-2005, 2006, 2007, 2008 + CACAOVM - Verein zur Foerderung der freien virtuellen Maschine CACAO This file is part of CACAO. @@ -22,30 +20,41 @@ Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301, USA. - Contact: cacao@cacaojvm.org - - Authors: Christian Thalinger - - Changes: - - $Id: statistics.c 4375 2006-01-27 17:35:13Z twisti $ - */ #include "config.h" +#include #include -#include -#include + +#if defined(HAVE_TIME_H) +# include +#endif + +#if defined(HAVE_SYS_TIME_H) +# include +#endif + +#if defined(HAVE_SYS_RESOURCE_H) +# include +#endif #include "vm/types.h" -#include "toolbox/logging.h" +#include "mm/gc.hpp" + +#include "toolbox/logging.hpp" + +#include "vm/class.hpp" +#include "vm/field.hpp" #include "vm/global.h" +#include "vm/method.hpp" #include "vm/options.h" #include "vm/statistics.h" +#include "vm/jit/code.hpp" + /* global variables ***********************************************************/ @@ -70,7 +79,36 @@ s4 maxdumpsize = 0; s4 globalallocateddumpsize = 0; s4 globaluseddumpsize = 0; -int count_class_infos = 0; /* variables for measurements */ + +/* variables for measurements *************************************************/ + +s4 size_classinfo = 0; +s4 size_fieldinfo = 0; +s4 size_methodinfo = 0; +s4 size_lineinfo = 0; +s4 size_codeinfo = 0; + +s4 size_stub_native = 0; + +s4 size_stack_map = 0; +s4 size_string = 0; + +s4 size_threadobject = 0; +int32_t size_thread_index_t = 0; +int32_t size_stacksize = 0; + +s4 size_lock_record = 0; +s4 size_lock_hashtable = 0; +s4 size_lock_waiter = 0; + +int32_t count_linenumbertable = 0; +int32_t size_linenumbertable = 0; + +s4 size_patchref = 0; + +u8 count_calls_java_to_native = 0; +u8 count_calls_native_to_java = 0; + int count_const_pool_len = 0; int count_classref_len = 0; int count_parsed_desc_len = 0; @@ -105,8 +143,12 @@ int count_mov_mem_mem = 0; int count_jit_calls = 0; int count_methods = 0; -int count_spills = 0; -int count_spills_read = 0; +int count_spills_read_ila = 0; +int count_spills_read_flt = 0; +int count_spills_read_dbl = 0; +int count_spills_write_ila = 0; +int count_spills_write_flt = 0; +int count_spills_write_dbl = 0; int count_pcmd_activ = 0; int count_pcmd_drop = 0; int count_pcmd_zero = 0; @@ -139,31 +181,20 @@ int count_tryblocks = 0; int count_code_len = 0; int count_data_len = 0; int count_cstub_len = 0; -int count_nstub_len = 0; int count_max_new_stack = 0; int count_upper_bound_new_stack = 0; - /* in_ inline statistics */ -int count_in = 0; -int count_in_uniqVirt = 0; -int count_in_uniqIntf = 0; -int count_in_rejected = 0; -int count_in_rejected_mult = 0; -int count_in_outsiders = 0; -int count_in_uniqueVirt_not_inlined = 0; -int count_in_uniqueInterface_not_inlined = 0; -int count_in_maxDepth = 0; -int count_in_maxMethods = 0; - -u8 count_native_function_calls=0; -u8 count_compiled_function_calls=0; -u8 count_jni_callXmethod_calls=0; -u8 count_jni_calls=0; -u2 count_in_not [512]; -/*** -int count_no_in[12] = {0,0,0,0, 0,0,0,0, 0,0,0,0}; -***/ +int count_emit_branch = 0; +int count_emit_branch_8bit = 0; +int count_emit_branch_16bit = 0; +int count_emit_branch_32bit = 0; +int count_emit_branch_64bit = 0; + +s4 count_branches_resolved = 0; +s4 count_branches_unresolved = 0; +u8 count_jni_callXmethod_calls=0; +u8 count_jni_calls=0; static int count_block_stack_init[11] = { @@ -213,32 +244,6 @@ s4 count_schedule_max_leaders = 0; s4 count_schedule_critical_path = 0; -/* nativeinvokation *********************************************************** - - increments the native invokation count by one - -*******************************************************************************/ - -void nativeinvokation(void) -{ - /* XXX do locking here */ - count_native_function_calls++; -} - - -/* compiledinvokation ********************************************************* - - increments the compiled invokation count by one - -*******************************************************************************/ - -void compiledinvokation(void) -{ - /* XXX do locking here */ - count_compiled_function_calls++; -} - - /* jnicallXmethodinvokation *************************************************** increments the jni CallXMethod invokation count by one @@ -273,14 +278,21 @@ void jniinvokation(void) s8 getcputime(void) { +#if defined(HAVE_GETRUSAGE) struct rusage ru; int sec, usec; getrusage(RUSAGE_SELF, &ru); - sec = ru.ru_utime.tv_sec + ru.ru_stime.tv_sec; + + sec = ru.ru_utime.tv_sec + ru.ru_stime.tv_sec; usec = ru.ru_utime.tv_usec + ru.ru_stime.tv_usec; return sec * 1000000 + usec; +#else + /* If we don't have getrusage, simply return 0. */ + + return 0; +#endif } @@ -392,9 +404,6 @@ void print_stats(void) dolog("Number of JIT compiler calls: %6d", count_jit_calls); dolog("Number of compiled methods: %6d", count_methods); - if (opt_rt) - dolog("Number of Methods marked Used: %d", count_methods_marked_used); - dolog("Number of compiled basic blocks: %6d", count_basic_blocks); dolog("Number of max. basic blocks per method: %6d", @@ -409,8 +418,12 @@ void print_stats(void) dolog("Size of compiled Exception Tables: %d", count_javaexcsize); dolog("Number of Machine-Instructions: %d", count_code_len >> 2); - dolog("Number of Spills (write to memory): %d", count_spills); - dolog("Number of Spills (read from memory): %d", count_spills_read); + dolog("Number of Spills (write to memory) : %d [%d|%d|%d]", + count_spills_write_ila + count_spills_write_flt + count_spills_write_dbl, + count_spills_write_ila, count_spills_write_flt, count_spills_write_dbl); + dolog("Number of Spills (read from memory) : %d [%d|%d|%d]", + count_spills_read_ila + count_spills_read_flt + count_spills_read_dbl, + count_spills_read_ila, count_spills_read_flt, count_spills_read_dbl); dolog("Number of Activ Pseudocommands: %6d", count_pcmd_activ); dolog("Number of Drop Pseudocommands: %6d", count_pcmd_drop); dolog("Number of Const Pseudocommands: %6d (zero:%5d)", @@ -427,12 +440,19 @@ void print_stats(void) dolog("Number of Method Pseudocommands: %6d", count_pcmd_met); dolog("Number of Branch Pseudocommands: %6d (rets:%5d, Xrets: %5d)", count_pcmd_bra, count_pcmd_return, count_pcmd_returnx); + log_println(" resolved branches: %6d", count_branches_resolved); + log_println(" unresolved branches: %6d", count_branches_unresolved); dolog("Number of Table Pseudocommands: %6d", count_pcmd_table); dolog("Number of Useful Pseudocommands: %6d", count_pcmd_table + count_pcmd_bra + count_pcmd_load + count_pcmd_mem + count_pcmd_op); dolog("Number of Null Pointer Checks: %6d", count_check_null); dolog("Number of Array Bound Checks: %6d", count_check_bound); dolog("Number of Try-Blocks: %d", count_tryblocks); + + dolog("Number of branch_emit (total, 8bit/16bit/32bit/64bit offset): %d, %d/%d/%d/%d", + count_emit_branch, count_emit_branch_8bit, count_emit_branch_16bit, + count_emit_branch_32bit, count_emit_branch_64bit); + dolog("Maximal count of stack elements: %d", count_max_new_stack); dolog("Upper bound of max stack elements: %d", count_upper_bound_new_stack); dolog("Distribution of stack sizes at block boundary"); @@ -532,20 +552,7 @@ void print_stats(void) } log_finish(); - dolog("Size of Code Area: %10.3f kB", (float) count_code_len / 1024); - dolog("Size of Data Area: %10.3f kB", (float) count_data_len / 1024); - dolog("Size of Class Infos: %10.3f kB", (float) count_class_infos / 1024); - dolog("Size of Const Pool: %10.3f kB", (float) (count_const_pool_len + count_utf_len) / 1024); - dolog("Size of Class refs: %10.3f kB", (float) count_classref_len / 1024); - dolog("Size of descriptors: %10.3f kB", (float) count_parsed_desc_len / 1024); - dolog("Size of vftbl: %10.3f kB", (float) count_vftbl_len / 1024); - dolog("Size of compiler stubs: %10.3f kB", (float) count_cstub_len / 1024); - dolog("Size of native stubs: %10.3f kB", (float) count_nstub_len / 1024); - dolog("Size of utf: %10.3f kB", (float) count_utf_len / 1024); - dolog("Size of VMCode: %10.3f kB (%d)", - (float) count_vmcode_len / 1024, - count_vmcode_len - 18 * count_all_methods); - dolog("Size of exception tables: %10.3f kB\n", (float) count_extable_len / 1024); + statistics_print_memory_usage(); dolog("Number of class loads: %6d", count_class_loads); dolog("Number of class inits: %6d", count_class_inits); @@ -578,149 +585,221 @@ void print_stats(void) dolog("Number of Methods kept in registers: %6d\n", count_method_in_register); - - /****if (useinlining) ***/ - { - u2 i; - char * in_not_reasons[IN_MAX] = { - "unqVirt | ", - "unqIntf | ", - "outsider | ", - "maxDepth | ", - "maxcode | ", - "maxlen | ", - "exception | ", - "notUnqVirt | ", - "notUnqIntf |" - }; - - dolog("Number of Methods Inlined : \t%6d", - count_in); - - if (inlinevirtuals) { - dolog("Number of Unique Virtual Methods inlined: \t%6d", - count_in_uniqVirt); - dolog("Number of Unique Implemented Interface Methods inlined: %6d", - count_in_uniqIntf); - } - - dolog("Number of Methods Inlines (total) rejected: \t%6d", - count_in_rejected); - dolog("Number of Methods Inlined rejected for multiple reasons: \t%6d", - count_in_rejected_mult); - dolog("Number of Methods where Inline max depth hit: \t%6d", - count_in_maxDepth); - dolog("Number of Methods Inlined rejected for max methods \t%6d\n", - count_in_maxMethods); - dolog("Number of Methods calls fom Outsider Class not inlined: \t%6d", - count_in_outsiders); - - dolog("Number of Unique Virtual Methods not inlined: \t%6d", - count_in_uniqueVirt_not_inlined); - dolog("Number of Unique Implemented Interface Methods not inlined:%6d\n", - count_in_uniqueInterface_not_inlined); - -#define INLINEDETAILS -#ifdef INLINEDETAILS - dolog("Details about Not Inlined Reasons:"); - - for (i = 0; i < 512; i++) { - if (count_in_not[i] > 0) { - /* XXX Please reimplement me! I'm ugly and insecure! */ - char logtext2[1024]="\t"; - - if (inlinevirtuals) { - if (i & IN_UNIQUEVIRT) - strcat(logtext2, in_not_reasons[N_UNIQUEVIRT]); - - if (i & IN_UNIQUE_INTERFACE) - strcat(logtext2, in_not_reasons[N_UNIQUE_INTERFACE]); - - if (i & IN_NOT_UNIQUE_VIRT) - strcat(logtext2, in_not_reasons[N_NOT_UNIQUE_VIRT]); - - if (i & IN_NOT_UNIQUE_INTERFACE) - strcat(logtext2, in_not_reasons[N_NOT_UNIQUE_INTERFACE]); - } - - if (i & IN_OUTSIDERS) - strcat(logtext2, in_not_reasons[N_OUTSIDERS]); - - if (i & IN_MAXDEPTH) - strcat(logtext2, in_not_reasons[N_MAXDEPTH]); - - if (i & IN_MAXCODE) - strcat(logtext2, in_not_reasons[N_MAXCODE]); - - if (i & IN_JCODELENGTH) - strcat(logtext2, in_not_reasons[N_JCODELENGTH]); - - if (i & IN_EXCEPTION) - strcat(logtext2, in_not_reasons[N_EXCEPTION]); - - dolog(" [%X]=%6d %s", i, count_in_not[i], logtext2); - } - } -#endif - } - - /* instruction scheduler statistics **************************************/ + /* instruction scheduler statistics ***************************************/ #if defined(USE_SCHEDULER) - dolog("Instruction scheduler statistics:"); - dolog("Number of basic blocks: %7d", count_schedule_basic_blocks); - dolog("Number of nodes: %7d", count_schedule_nodes); - dolog("Number of leaders nodes: %7d", count_schedule_leaders); - dolog("Number of max. leaders nodes: %7d", count_schedule_max_leaders); - dolog("Length of critical path: %7d\n", count_schedule_critical_path); + dolog("Instruction scheduler statistics:"); + dolog("Number of basic blocks: %7d", count_schedule_basic_blocks); + dolog("Number of nodes: %7d", count_schedule_nodes); + dolog("Number of leaders nodes: %7d", count_schedule_leaders); + dolog("Number of max. leaders nodes: %7d", count_schedule_max_leaders); + dolog("Length of critical path: %7d\n", count_schedule_critical_path); #endif /* call statistics ********************************************************/ - dolog("Function call statistics:"); - dolog("Number of native function invokations: %ld", - count_native_function_calls); - dolog("Number of compiled function invokations: %ld", - count_compiled_function_calls); - dolog("Number of jni->CallXMethod function invokations: %ld", - count_jni_callXmethod_calls); - dolog("Overall number of jni invokations: %ld", - count_jni_calls); + dolog("Function call statistics:"); + dolog("Number of jni->CallXMethod function invokations: %ld", + count_jni_callXmethod_calls); + dolog("Overall number of jni invokations: %ld", + count_jni_calls); + + log_println("java-to-native calls: %10ld", count_calls_java_to_native); + log_println("native-to-java calls: %10ld", count_calls_native_to_java); - /* now print other statistics ********************************************/ + /* now print other statistics ********************************************/ #if defined(ENABLE_INTRP) - print_dynamic_super_statistics(); + print_dynamic_super_statistics(); #endif } -/* mem_usagelog **************************************************************** +/* statistics_print_date ******************************************************* - prints some memory related infos + Print current date and time. *******************************************************************************/ -void mem_usagelog(bool givewarnings) +void statistics_print_date(void) { - if ((memoryusage != 0) && givewarnings) { - dolog("Allocated memory not returned: %9d", (s4) memoryusage); - } + time_t t; + struct tm tm; - if ((globalallocateddumpsize != 0) && givewarnings) { - dolog("Dump memory not returned: %9d", - (s4) globalallocateddumpsize); - } +#if defined(HAVE_TIME) + time(&t); +#else +# error !HAVE_TIME +#endif + +#if defined(HAVE_LOCALTIME_R) + localtime_r(&t, &tm); +#else +# error !HAVE_LOCALTIME_R +#endif + + log_println("%d-%02d-%02d %02d:%02d:%02d", + 1900 + tm.tm_year, tm.tm_mon + 1, tm.tm_mday, + tm.tm_hour, tm.tm_min, tm.tm_sec); +} + + +/* statistics_print_memory_usage *********************************************** - dolog("Code - max. memory usage: %9d kB", - (s4) ((maxcodememusage + 1023) / 1024)); - dolog("Random - max. memory usage: %9d kB", - (s4) ((maxmemusage + 1023) / 1024)); - dolog("Dump - max. memory usage: %9d kB", - (s4) ((maxdumpsize + 1023) / 1024)); + Print current memory usage. + +*******************************************************************************/ + +void statistics_print_memory_usage(void) +{ + s4 sum; + + log_println("memory usage ----------------------"); + log_println(""); + log_println("code: %10d", count_code_len); + log_println("data: %10d", count_data_len); + log_println(" ----------"); + + sum = + count_code_len + + count_data_len; + + log_println(" %10d", sum); + + log_println(""); + + log_println("classinfo (%3d B): %10d", (int) sizeof(classinfo), size_classinfo); + log_println("fieldinfo (%3d B): %10d", (int) sizeof(fieldinfo), size_fieldinfo); + log_println("methodinfo (%3d B): %10d", (int) sizeof(methodinfo), size_methodinfo); + log_println("lineinfo (%3d B): %10d", (int) sizeof(lineinfo), size_lineinfo); + log_println("codeinfo (%3d B): %10d", (int) sizeof(codeinfo), size_codeinfo); + log_println(" ----------"); + + sum = + size_classinfo + + size_fieldinfo + + size_methodinfo + + size_lineinfo + + size_codeinfo; + + log_println(" %10d", sum); + + log_println(""); + + log_println("linenumber tables (%5d): %10d", count_linenumbertable, size_linenumbertable); + log_println("exception tables: %10d", count_extable_len); + log_println("patcher references: %10d", size_patchref); + log_println(" ----------"); + + sum = + size_linenumbertable + + count_extable_len + + size_patchref; + + log_println(" %10d", sum); + + log_println(""); + + log_println("constant pool: %10d", count_const_pool_len); + log_println("classref: %10d", count_classref_len); + log_println("parsed descriptors: %10d", count_parsed_desc_len); + log_println("vftbl: %10d", count_vftbl_len); + log_println("compiler stubs: %10d", count_cstub_len); + log_println("native stubs: %10d", size_stub_native); + log_println("utf: %10d", count_utf_len); + log_println("vmcode: %10d", count_vmcode_len); + log_println("stack map: %10d", size_stack_map); + log_println("string: %10d", size_string); + log_println("threadobject: %10d", size_threadobject); + log_println("thread index: %10d", size_thread_index_t); + log_println("stack size: %10d", size_stacksize); + log_println("lock record: %10d", size_lock_record); + log_println("lock hashtable: %10d", size_lock_hashtable); + log_println("lock waiter: %10d", size_lock_waiter); + log_println(" ----------"); + + sum = + count_const_pool_len + + count_classref_len + + count_parsed_desc_len + + count_vftbl_len + + count_cstub_len + + size_stub_native + + count_utf_len + + count_vmcode_len + + size_stack_map + + size_string + + size_threadobject + + size_thread_index_t + + size_stacksize + + size_lock_record + + size_lock_hashtable + + size_lock_waiter; + + log_println(" %10d", sum); + + log_println(""); + + log_println("max. code memory: %10d", maxcodememusage); + log_println("max. heap memory: %10d", maxmemusage); + log_println("max. dump memory: %10d", maxdumpsize); + log_println(""); + log_println("heap memory not freed: %10d", (int32_t) memoryusage); + log_println("dump memory not freed: %10d", (int32_t) globalallocateddumpsize); + + log_println(""); +} + + +/* statistics_print_gc_memory_usage ******************************************** + + Print current GC memory usage. + +*******************************************************************************/ + +void statistics_print_gc_memory_usage(void) +{ + static int64_t count = 0; + int64_t max; + int64_t size; + int64_t free; + int64_t used; + int64_t total; + + count++; + + max = gc_get_max_heap_size(); + size = gc_get_heap_size(); + free = gc_get_free_bytes(); + used = size - free; + total = gc_get_total_bytes(); + + if (opt_ProfileMemoryUsageGNUPlot) { + if (count == 1) + fprintf(opt_ProfileMemoryUsageGNUPlot, "plot \"profile.dat\" using 1:2 with lines title \"max. Java heap size\", \"profile.dat\" using 1:3 with lines title \"Java heap size\", \"profile.dat\" using 1:4 with lines title \"used\", \"profile.dat\" using 1:5 with lines title \"free\"\n"); + +#if SIZEOF_VOID_P == 8 + fprintf(opt_ProfileMemoryUsageGNUPlot, "%ld %ld %ld %ld %ld\n", count, max, size, used, free); +#else + fprintf(opt_ProfileMemoryUsageGNUPlot, "%lld %lld %lld %lld %lld\n", count, max, size, used, free); +#endif + + fflush(opt_ProfileMemoryUsageGNUPlot); + } + else { + log_println("GC memory usage -------------------"); + log_println(""); + log_println("max. Java heap size: %10lld", max); + log_println(""); + log_println("Java heap size: %10lld", size); + log_println("used: %10lld", used); + log_println("free: %10lld", free); + log_println("totally used: %10lld", total); + log_println(""); + } } @@ -735,4 +814,5 @@ void mem_usagelog(bool givewarnings) * c-basic-offset: 4 * tab-width: 4 * End: + * vim:noexpandtab:sw=4:ts=4: */