1 /* src/vm/statistics.c - global varables for statistics
3 Copyright (C) 1996-2005 R. Grafl, A. Krall, C. Kruegel, C. Oates,
4 R. Obermaisser, M. Platter, M. Probst, S. Ring, E. Steiner,
5 C. Thalinger, D. Thuernbeck, P. Tomsich, C. Ullrich, J. Wenninger,
6 Institut f. Computersprachen - TU Wien
8 This file is part of CACAO.
10 This program is free software; you can redistribute it and/or
11 modify it under the terms of the GNU General Public License as
12 published by the Free Software Foundation; either version 2, or (at
13 your option) any later version.
15 This program is distributed in the hope that it will be useful, but
16 WITHOUT ANY WARRANTY; without even the implied warranty of
17 MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU
18 General Public License for more details.
20 You should have received a copy of the GNU General Public License
21 along with this program; if not, write to the Free Software
22 Foundation, Inc., 59 Temple Place - Suite 330, Boston, MA
25 Contact: cacao@complang.tuwien.ac.at
27 Authors: Christian Thalinger
29 $Id: statistics.c 2503 2005-05-23 08:22:03Z twisti $
36 #include <sys/resource.h>
38 #include "toolbox/logging.h"
39 #include "vm/global.h"
40 #include "vm/options.h"
41 #include "vm/statistics.h"
44 /* global variables */
46 static s8 loadingtime = 0; /* accumulated loading time */
47 static s8 loadingstarttime = 0;
48 static s8 loadingstoptime = 0;
49 static s4 loadingtime_recursion = 0;
51 static s8 compilingtime = 0; /* accumulated compile time */
52 static s8 compilingstarttime = 0;
53 static s8 compilingstoptime = 0;
54 static s4 compilingtime_recursion = 0;
60 s4 globalallocateddumpsize = 0;
61 s4 globaluseddumpsize = 0;
63 int count_class_infos = 0; /* variables for measurements */
64 int count_const_pool_len = 0;
65 int count_classref_len = 0;
66 int count_parsed_desc_len = 0;
67 int count_vftbl_len = 0;
68 int count_all_methods = 0;
69 int count_methods_marked_used = 0; /* RTA */
71 int count_vmcode_len = 0;
72 int count_extable_len = 0;
73 int count_class_loads = 0;
74 int count_class_inits = 0;
76 int count_utf_len = 0; /* size of utf hash */
77 int count_utf_new = 0; /* calls of utf_new */
78 int count_utf_new_found = 0; /* calls of utf_new with fast return */
80 int count_locals_conflicts = 0; /* register allocator statistics */
81 int count_locals_spilled = 0;
82 int count_locals_register = 0;
83 int count_ss_spilled = 0;
84 int count_ss_register = 0;
85 int count_methods_allocated_by_lsra = 0;
86 int count_mem_move_bb = 0;
87 int count_interface_size = 0;
88 int count_argument_mem_ss = 0;
89 int count_argument_reg_ss = 0;
90 int count_method_in_register = 0;
91 int count_mov_reg_reg = 0;
92 int count_mov_mem_reg = 0;
93 int count_mov_reg_mem = 0;
94 int count_mov_mem_mem = 0;
96 int count_jit_calls = 0;
97 int count_methods = 0;
99 int count_spills_read = 0;
100 int count_pcmd_activ = 0;
101 int count_pcmd_drop = 0;
102 int count_pcmd_zero = 0;
103 int count_pcmd_const_store = 0;
104 int count_pcmd_const_alu = 0;
105 int count_pcmd_const_bra = 0;
106 int count_pcmd_load = 0;
107 int count_pcmd_move = 0;
108 int count_load_instruction = 0;
109 int count_pcmd_store = 0;
110 int count_pcmd_store_comb = 0;
111 int count_dup_instruction = 0;
112 int count_pcmd_op = 0;
113 int count_pcmd_mem = 0;
114 int count_pcmd_met = 0;
115 int count_pcmd_bra = 0;
116 int count_pcmd_table = 0;
117 int count_pcmd_return = 0;
118 int count_pcmd_returnx = 0;
119 int count_check_null = 0;
120 int count_check_bound = 0;
121 int count_max_basic_blocks = 0;
122 int count_basic_blocks = 0;
123 int count_javainstr = 0;
124 int count_max_javainstr = 0;
125 int count_javacodesize = 0;
126 int count_javaexcsize = 0;
128 int count_tryblocks = 0;
129 int count_code_len = 0;
130 int count_data_len = 0;
131 int count_cstub_len = 0;
132 int count_nstub_len = 0;
133 int count_max_new_stack = 0;
134 int count_upper_bound_new_stack = 0;
135 /* in_ inline statistics */
137 int count_in_uniqVirt = 0;
138 int count_in_uniqIntf = 0;
139 int count_in_rejected = 0;
140 int count_in_rejected_mult = 0;
141 int count_in_outsiders = 0;
142 int count_in_uniqueVirt_not_inlined = 0;
143 int count_in_uniqueInterface_not_inlined = 0;
144 int count_in_maxDepth = 0;
145 int count_in_maxMethods = 0;
147 u8 count_native_function_calls=0;
148 u8 count_compiled_function_calls=0;
149 u8 count_jni_callXmethod_calls=0;
150 u8 count_jni_calls=0;
152 u2 count_in_not [512];
154 int count_no_in[12] = {0,0,0,0, 0,0,0,0, 0,0,0,0};
159 static int count_block_stack_init[11] = {
164 int *count_block_stack = count_block_stack_init;
165 static int count_analyse_iterations_init[5] = {
168 int *count_analyse_iterations = count_analyse_iterations_init;
169 static int count_method_bb_distribution_init[9] = {
173 int *count_method_bb_distribution = count_method_bb_distribution_init;
174 static int count_block_size_distribution_init[18] = {
180 int *count_block_size_distribution = count_block_size_distribution_init;
181 static int count_store_length_init[21] = {
188 int *count_store_length = count_store_length_init;
189 static int count_store_depth_init[11] = {
194 int *count_store_depth = count_store_depth_init;
197 /* instruction scheduler statistics *******************************************/
199 s4 count_schedule_basic_blocks = 0;
200 s4 count_schedule_nodes = 0;
201 s4 count_schedule_leaders = 0;
202 s4 count_schedule_max_leaders = 0;
203 s4 count_schedule_critical_path = 0;
207 /* nativeinvokation ***********************************************************
209 increments the native invokation count by one
211 *******************************************************************************/
212 void nativeinvokation() {
214 count_native_function_calls++;
217 /* compiledinvokation *********************************************************
219 increments the compiled invokation count by one
221 *******************************************************************************/
222 void compiledinvokation() {
224 count_compiled_function_calls++;
228 /* jnicallXmethodinvokation ***************************************************
230 increments the jni CallXMethod invokation count by one
232 *******************************************************************************/
233 void jnicallXmethodnvokation() {
235 count_jni_callXmethod_calls++;
238 /* jniinvokation *************************************************************
240 increments the jni overall invokation count by one
242 *******************************************************************************/
243 void jniinvokation() {
249 /* getcputime *********************************** ******************************
251 Returns the used CPU time in microseconds
253 *******************************************************************************/
260 getrusage(RUSAGE_SELF, &ru);
261 sec = ru.ru_utime.tv_sec + ru.ru_stime.tv_sec;
262 usec = ru.ru_utime.tv_usec + ru.ru_stime.tv_usec;
264 return sec * 1000000 + usec;
268 /* loadingtime_stop ************************************************************
272 *******************************************************************************/
274 void loadingtime_start(void)
276 loadingtime_recursion++;
278 if (loadingtime_recursion == 1)
279 loadingstarttime = getcputime();
283 /* loadingtime_stop ************************************************************
287 *******************************************************************************/
289 void loadingtime_stop(void)
291 if (loadingtime_recursion == 1) {
292 loadingstoptime = getcputime();
293 loadingtime += (loadingstoptime - loadingstarttime);
296 loadingtime_recursion--;
300 /* compilingtime_stop **********************************************************
304 *******************************************************************************/
306 void compilingtime_start(void)
308 compilingtime_recursion++;
310 if (compilingtime_recursion == 1)
311 compilingstarttime = getcputime();
315 /* compilingtime_stop **********************************************************
319 *******************************************************************************/
321 void compilingtime_stop(void)
323 if (compilingtime_recursion == 1) {
324 compilingstoptime = getcputime();
325 compilingtime += (compilingstoptime - compilingstarttime);
328 compilingtime_recursion--;
332 /* print_times *****************************************************************
334 Prints a summary of CPU time usage.
336 *******************************************************************************/
338 void print_times(void)
343 totaltime = getcputime();
344 runtime = totaltime - loadingtime - compilingtime;
346 #if defined(__I386__) || defined(__POWERPC__)
347 dolog("Time for loading classes: %lld secs, %lld millis",
349 dolog("Time for loading classes: %ld secs, %ld millis",
351 loadingtime / 1000000, (loadingtime % 1000000) / 1000);
353 #if defined(__I386__) || defined(__POWERPC__)
354 dolog("Time for compiling code: %lld secs, %lld millis",
356 dolog("Time for compiling code: %ld secs, %ld millis",
358 compilingtime / 1000000, (compilingtime % 1000000) / 1000);
360 #if defined(__I386__) || defined(__POWERPC__)
361 dolog("Time for running program: %lld secs, %lld millis",
363 dolog("Time for running program: %ld secs, %ld millis",
365 runtime / 1000000, (runtime % 1000000) / 1000);
367 #if defined(__I386__) || defined(__POWERPC__)
368 dolog("Total time: %lld secs, %lld millis",
370 dolog("Total time: %ld secs, %ld millis",
372 totaltime / 1000000, (totaltime % 1000000) / 1000);
376 /* print_stats *****************************************************************
378 outputs detailed compiler statistics
380 *******************************************************************************/
382 void print_stats(void)
384 dolog("Number of JitCompiler Calls: %d", count_jit_calls);
385 dolog("Number of compiled Methods: %d", count_methods);
388 dolog("Number of Methods marked Used: %d", count_methods_marked_used);
390 dolog("Number of max basic blocks per method: %d", count_max_basic_blocks);
391 dolog("Number of compiled basic blocks: %d", count_basic_blocks);
392 dolog("Number of max JavaVM-Instructions per method: %d",
393 count_max_javainstr);
394 dolog("Number of compiled JavaVM-Instructions: %d", count_javainstr);
395 dolog("Size of compiled JavaVM-Instructions: %d(%d)",
396 count_javacodesize, count_javacodesize - count_methods * 18);
397 dolog("Size of compiled Exception Tables: %d", count_javaexcsize);
398 dolog("Number of Machine-Instructions: %d", count_code_len >> 2);
399 dolog("Number of Spills (write to memory): %d", count_spills);
400 dolog("Number of Spills (read from memory): %d", count_spills_read);
401 dolog("Number of Activ Pseudocommands: %6d", count_pcmd_activ);
402 dolog("Number of Drop Pseudocommands: %6d", count_pcmd_drop);
403 dolog("Number of Const Pseudocommands: %6d (zero:%5d)",
404 count_pcmd_load, count_pcmd_zero);
405 dolog("Number of ConstAlu Pseudocommands: %6d (cmp: %5d, store:%5d)",
406 count_pcmd_const_alu, count_pcmd_const_bra, count_pcmd_const_store);
407 dolog("Number of Move Pseudocommands: %6d", count_pcmd_move);
408 dolog("Number of Load Pseudocommands: %6d", count_load_instruction);
409 dolog("Number of Store Pseudocommands: %6d (combined: %5d)",
410 count_pcmd_store, count_pcmd_store - count_pcmd_store_comb);
411 dolog("Number of OP Pseudocommands: %6d", count_pcmd_op);
412 dolog("Number of DUP Pseudocommands: %6d", count_dup_instruction);
413 dolog("Number of Mem Pseudocommands: %6d", count_pcmd_mem);
414 dolog("Number of Method Pseudocommands: %6d", count_pcmd_met);
415 dolog("Number of Branch Pseudocommands: %6d (rets:%5d, Xrets: %5d)",
416 count_pcmd_bra, count_pcmd_return, count_pcmd_returnx);
417 dolog("Number of Table Pseudocommands: %6d", count_pcmd_table);
418 dolog("Number of Useful Pseudocommands: %6d", count_pcmd_table +
419 count_pcmd_bra + count_pcmd_load + count_pcmd_mem + count_pcmd_op);
420 dolog("Number of Null Pointer Checks: %6d", count_check_null);
421 dolog("Number of Array Bound Checks: %6d", count_check_bound);
422 dolog("Number of Try-Blocks: %d", count_tryblocks);
423 dolog("Maximal count of stack elements: %d", count_max_new_stack);
424 dolog("Upper bound of max stack elements: %d", count_upper_bound_new_stack);
425 dolog("Distribution of stack sizes at block boundary");
426 dolog(" 0 1 2 3 4 5 6 7 8 9 >=10");
427 dolog("%6d%6d%6d%6d%6d%6d%6d%6d%6d%6d%6d",
428 count_block_stack[0], count_block_stack[1], count_block_stack[2],
429 count_block_stack[3], count_block_stack[4], count_block_stack[5],
430 count_block_stack[6], count_block_stack[7], count_block_stack[8],
431 count_block_stack[9], count_block_stack[10]);
432 dolog("Distribution of store stack depth");
433 dolog(" 0 1 2 3 4 5 6 7 8 9 >=10");
434 dolog("%6d%6d%6d%6d%6d%6d%6d%6d%6d%6d%6d",
435 count_store_depth[0], count_store_depth[1], count_store_depth[2],
436 count_store_depth[3], count_store_depth[4], count_store_depth[5],
437 count_store_depth[6], count_store_depth[7], count_store_depth[8],
438 count_store_depth[9], count_store_depth[10]);
439 dolog("Distribution of store creator chains first part");
440 dolog(" 0 1 2 3 4 5 6 7 8 9");
441 dolog("%6d%6d%6d%6d%6d%6d%6d%6d%6d%6d",
442 count_store_length[0], count_store_length[1], count_store_length[2],
443 count_store_length[3], count_store_length[4], count_store_length[5],
444 count_store_length[6], count_store_length[7], count_store_length[8],
445 count_store_length[9]);
446 dolog("Distribution of store creator chains second part");
447 dolog(" 10 11 12 13 14 15 16 17 18 19 >=20");
448 dolog("%6d%6d%6d%6d%6d%6d%6d%6d%6d%6d%6d",
449 count_store_length[10], count_store_length[11],
450 count_store_length[12], count_store_length[13],
451 count_store_length[14], count_store_length[15],
452 count_store_length[16], count_store_length[17],
453 count_store_length[18], count_store_length[19],
454 count_store_length[20]);
455 dolog("Distribution of analysis iterations");
456 dolog(" 1 2 3 4 >=5");
457 dolog("%6d%6d%6d%6d%6d",
458 count_analyse_iterations[0], count_analyse_iterations[1],
459 count_analyse_iterations[2], count_analyse_iterations[3],
460 count_analyse_iterations[4]);
461 dolog("Distribution of basic blocks per method");
462 dolog(" <=5 <=10 <=15 <=20 <=30 <=40 <=50 <=75 >75");
463 dolog("%6d%6d%6d%6d%6d%6d%6d%6d%6d",
464 count_method_bb_distribution[0], count_method_bb_distribution[1],
465 count_method_bb_distribution[2], count_method_bb_distribution[3],
466 count_method_bb_distribution[4], count_method_bb_distribution[5],
467 count_method_bb_distribution[6], count_method_bb_distribution[7],
468 count_method_bb_distribution[8]);
469 dolog("Distribution of basic block sizes");
470 dolog(" 0 1 2 3 4 5 6 7 8 9 <13 <15 <17 <19 <21 <26 <31 >30");
471 dolog("%6d%6d%6d%6d%6d%5d%5d%5d%5d%5d%5d%5d%5d%5d%5d%5d%5d%5d",
472 count_block_size_distribution[0], count_block_size_distribution[1],
473 count_block_size_distribution[2], count_block_size_distribution[3],
474 count_block_size_distribution[4], count_block_size_distribution[5],
475 count_block_size_distribution[6], count_block_size_distribution[7],
476 count_block_size_distribution[8], count_block_size_distribution[9],
477 count_block_size_distribution[10], count_block_size_distribution[11],
478 count_block_size_distribution[12], count_block_size_distribution[13],
479 count_block_size_distribution[14], count_block_size_distribution[15],
480 count_block_size_distribution[16], count_block_size_distribution[17]);
481 dolog("Size of Code Area (Kb): %10.3f", (float) count_code_len / 1024);
482 dolog("Size of data Area (Kb): %10.3f", (float) count_data_len / 1024);
483 dolog("Size of Class Infos (Kb):%10.3f", (float) count_class_infos / 1024);
484 dolog("Size of Const Pool (Kb): %10.3f",
485 (float) (count_const_pool_len + count_utf_len) / 1024);
486 dolog("Size of Class refs (Kb): %10.3f", (float) count_classref_len / 1024);
487 dolog("Size of descriptors(Kb): %10.3f",
488 (float) count_parsed_desc_len / 1024);
489 dolog("Size of Vftbl (Kb): %10.3f", (float) count_vftbl_len / 1024);
490 dolog("Size of comp stub (Kb): %10.3f", (float) count_cstub_len / 1024);
491 dolog("Size of native stub (Kb):%10.3f", (float) count_nstub_len / 1024);
492 dolog("Size of Utf (Kb): %10.3f", (float) count_utf_len / 1024);
493 dolog("Size of VMCode (Kb): %10.3f(%d)",
494 (float) count_vmcode_len / 1024,
495 count_vmcode_len - 18 * count_all_methods);
496 dolog("Size of ExTable (Kb): %10.3f", (float) count_extable_len / 1024);
497 dolog("Number of class loads: %d", count_class_loads);
498 dolog("Number of class inits: %d", count_class_inits);
499 dolog("Number of loaded Methods: %d\n", count_all_methods);
501 dolog("Calls of utf_new: %22d", count_utf_new);
502 dolog("Calls of utf_new (element found): %6d\n", count_utf_new_found);
505 /* LSRA statistics ********************************************************/
507 dolog("Moves reg -> reg: %6d", count_mov_reg_reg);
508 dolog("Moves mem -> reg: %6d", count_mov_mem_reg);
509 dolog("Moves reg -> mem: %6d", count_mov_reg_mem);
510 dolog("Moves mem -> mem: %6d", count_mov_mem_mem);
512 dolog("Methods allocated by LSRA: %6d",
513 count_methods_allocated_by_lsra);
514 dolog("Conflicts between local Variables: %6d", count_locals_conflicts);
515 dolog("Local Variables held in Memory: %6d", count_locals_spilled);
516 dolog("Local Variables held in Registers: %6d", count_locals_register);
517 dolog("Stackslots held in Memory: %6d", count_ss_spilled);
518 dolog("Stackslots held in Registers: %6d", count_ss_register);
519 dolog("Memory moves at BB Boundaries: %6d", count_mem_move_bb);
520 dolog("Number of interface slots: %6d\n", count_interface_size);
521 dolog("Number of Argument stack slots in register: %6d",
522 count_argument_reg_ss);
523 dolog("Number of Argument stack slots in memory: %6d\n",
524 count_argument_mem_ss);
525 dolog("Number of Methods kept in registers: %6d\n",
526 count_method_in_register);
529 /****if (useinlining) ***/
532 char * in_not_reasons[IN_MAX] = {
544 dolog("Number of Methods Inlined : \t%6d",
547 if (inlinevirtuals) {
548 dolog("Number of Unique Virtual Methods inlined: \t%6d",
550 dolog("Number of Unique Implemented Interface Methods inlined: %6d",
554 dolog("Number of Methods Inlines (total) rejected: \t%6d",
556 dolog("Number of Methods Inlined rejected for multiple reasons: \t%6d",
557 count_in_rejected_mult);
558 dolog("Number of Methods where Inline max depth hit: \t%6d",
560 dolog("Number of Methods Inlined rejected for max methods \t%6d\n",
561 count_in_maxMethods);
562 dolog("Number of Methods calls fom Outsider Class not inlined: \t%6d",
565 dolog("Number of Unique Virtual Methods not inlined: \t%6d",
566 count_in_uniqueVirt_not_inlined);
567 dolog("Number of Unique Implemented Interface Methods not inlined:%6d\n",
568 count_in_uniqueInterface_not_inlined);
570 #define INLINEDETAILS
572 dolog("Details about Not Inlined Reasons:");
574 for (i = 0; i < 512; i++) {
575 if (count_in_not[i] > 0) {
576 /* XXX Please reimplement me! I'm ugly and insecure! */
577 char logtext2[1024]="\t";
579 if (inlinevirtuals) {
580 if (i & IN_UNIQUEVIRT)
581 strcat(logtext2, in_not_reasons[N_UNIQUEVIRT]);
583 if (i & IN_UNIQUE_INTERFACE)
584 strcat(logtext2, in_not_reasons[N_UNIQUE_INTERFACE]);
586 if (i & IN_NOT_UNIQUE_VIRT)
587 strcat(logtext2, in_not_reasons[N_NOT_UNIQUE_VIRT]);
589 if (i & IN_NOT_UNIQUE_INTERFACE)
590 strcat(logtext2, in_not_reasons[N_NOT_UNIQUE_INTERFACE]);
593 if (i & IN_OUTSIDERS)
594 strcat(logtext2, in_not_reasons[N_OUTSIDERS]);
597 strcat(logtext2, in_not_reasons[N_MAXDEPTH]);
600 strcat(logtext2, in_not_reasons[N_MAXCODE]);
602 if (i & IN_JCODELENGTH)
603 strcat(logtext2, in_not_reasons[N_JCODELENGTH]);
605 if (i & IN_EXCEPTION)
606 strcat(logtext2, in_not_reasons[N_EXCEPTION]);
608 dolog(" [%X]=%6d %s", i, count_in_not[i], logtext2);
615 /* instruction scheduler statistics **************************************/
617 #if defined(USE_SCHEDULER)
618 dolog("Instruction scheduler statistics:");
619 dolog("Number of basic blocks: %7d", count_schedule_basic_blocks);
620 dolog("Number of nodes: %7d", count_schedule_nodes);
621 dolog("Number of leaders nodes: %7d", count_schedule_leaders);
622 dolog("Number of max. leaders nodes: %7d", count_schedule_max_leaders);
623 dolog("Length of critical path: %7d\n", count_schedule_critical_path);
627 /* call statistics ********************************************************/
629 dolog("Function call statistics:");
630 dolog("Number of native function invokations: %ld",
631 count_native_function_calls);
632 dolog("Number of compiled function invokations: %ld",
633 count_compiled_function_calls);
634 dolog("Number of jni->CallXMethod function invokations: %ld",
635 count_jni_callXmethod_calls);
636 dolog("Overall number of jni invokations: %ld",
641 /* mem_usagelog ****************************************************************
643 prints some memory related infos
645 *******************************************************************************/
647 void mem_usagelog(bool givewarnings)
649 if ((memoryusage != 0) && givewarnings) {
650 dolog("Allocated memory not returned: %d", (s4) memoryusage);
653 if ((globalallocateddumpsize != 0) && givewarnings) {
654 dolog("Dump memory not returned: %d", (s4) globalallocateddumpsize);
657 dolog("Random/Dump - max. memory usage: %dkB/%dkB",
658 (s4) ((maxmemusage + 1023) / 1024),
659 (s4) ((maxdumpsize + 1023) / 1024));
664 * These are local overrides for various environment variables in Emacs.
665 * Please do not remove this and leave it at the end of the file, where
666 * Emacs will automagically detect them.
667 * ---------------------------------------------------------------------
670 * indent-tabs-mode: t