Lazy checkcast and instanceof.
[cacao.git] / src / vm / statistics.c
index feeabcd1ade7b881d138b5c68f2c592aaa0bdf4a..b7ef1183d2cdcb65292422566c083c8cfd212f0d 100644 (file)
@@ -1,10 +1,9 @@
-/* statistics.c - global varables for statistics
+/* src/vm/statistics.c - global varables for statistics
 
-   Copyright (C) 1996, 1997, 1998, 1999, 2000, 2001, 2002, 2003
-   Institut f. Computersprachen, TU Wien
-   R. Grafl, A. Krall, C. Kruegel, C. Oates, R. Obermaisser, M. Probst,
-   S. Ring, E. Steiner, C. Thalinger, D. Thuernbeck, P. Tomsich,
-   J. Wenninger
+   Copyright (C) 1996-2005 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
 
    This file is part of CACAO.
 
 
    Authors: Christian Thalinger
 
-   $Id: statistics.c 1418 2004-10-19 14:11:58Z carolyn $
+   $Id: statistics.c 2211 2005-04-04 10:39:36Z christian $
 
 */
 
 
 #include <sys/time.h>
 #include <sys/resource.h>
-#include "global.h"
-#include "statistics.h"
+
 #include "toolbox/logging.h"
-#include "options.h"
+#include "vm/global.h"
+#include "vm/options.h"
+#include "vm/statistics.h"
+#include <string.h> 
 
 
 /* global variables */
@@ -52,8 +53,17 @@ static s8 compilingstarttime = 0;
 static s8 compilingstoptime = 0;
 static s4 compilingtime_recursion = 0;
 
+s4 memoryusage = 0;
+s4 maxmemusage = 0;
+s4 maxdumpsize = 0;
+
+s4 globalallocateddumpsize = 0;
+s4 globaluseddumpsize = 0;
+
 int count_class_infos = 0;              /* variables for measurements         */
 int count_const_pool_len = 0;
+int count_classref_len = 0;
+int count_parsed_desc_len = 0;
 int count_vftbl_len = 0;
 int count_all_methods = 0;
 int count_methods_marked_used = 0;  /* RTA */
@@ -67,9 +77,26 @@ int count_utf_len = 0;                  /* size of utf hash                   */
 int count_utf_new = 0;                  /* calls of utf_new                   */
 int count_utf_new_found  = 0;           /* calls of utf_new with fast return  */
 
+int count_locals_conflicts = 0;         /* register allocator statistics */
+int count_locals_spilled = 0;
+int count_locals_register = 0;
+int count_ss_spilled = 0;
+int count_ss_register = 0;
+int count_methods_allocated_by_lsra = 0;
+int count_mem_move_bb = 0;
+int count_interface_size = 0;
+int count_argument_mem_ss = 0;
+int count_argument_reg_ss = 0;
+int count_method_in_register = 0;
+int count_mov_reg_reg = 0;
+int count_mov_mem_reg = 0;
+int count_mov_reg_mem = 0;
+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_pcmd_activ = 0;
 int count_pcmd_drop = 0;
 int count_pcmd_zero = 0;
@@ -105,6 +132,25 @@ 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;
+
+u2 count_in_not   [512];
+/***
+int count_no_in[12] = {0,0,0,0, 0,0,0,0, 0,0,0,0};
+***/
+
+
+
 static int count_block_stack_init[11] = {
        0, 0, 0, 0, 0, 
        0, 0, 0, 0, 0, 
@@ -143,6 +189,15 @@ static int count_store_depth_init[11] = {
 int *count_store_depth = count_store_depth_init;
 
 
+/* instruction scheduler statistics *******************************************/
+
+s4 count_schedule_basic_blocks = 0;
+s4 count_schedule_nodes = 0;
+s4 count_schedule_leaders = 0;
+s4 count_schedule_max_leaders = 0;
+s4 count_schedule_critical_path = 0;
+
+
 /* getcputime *********************************** ******************************
 
    Returns the used CPU time in microseconds
@@ -305,41 +360,43 @@ void print_stats()
        log_text(logtext);
        sprintf(logtext, "Number of Machine-Instructions: %d", count_code_len >> 2);
        log_text(logtext);
-       sprintf(logtext, "Number of Spills: %d", count_spills);
+       sprintf(logtext, "Number of Spills (write to memory): %d", count_spills);
        log_text(logtext);
-       sprintf(logtext, "Number of Activ    Pseudocommands: %5d", count_pcmd_activ);
+       sprintf(logtext, "Number of Spills (read from memory): %d", count_spills_read);
        log_text(logtext);
-       sprintf(logtext, "Number of Drop     Pseudocommands: %5d", count_pcmd_drop);
+       sprintf(logtext, "Number of Activ    Pseudocommands: %6d", count_pcmd_activ);
        log_text(logtext);
-       sprintf(logtext, "Number of Const    Pseudocommands: %5d (zero:%5d)", count_pcmd_load, count_pcmd_zero);
+       sprintf(logtext, "Number of Drop     Pseudocommands: %6d", count_pcmd_drop);
        log_text(logtext);
-       sprintf(logtext, "Number of ConstAlu Pseudocommands: %5d (cmp: %5d, store:%5d)", count_pcmd_const_alu, count_pcmd_const_bra, count_pcmd_const_store);
+       sprintf(logtext, "Number of Const    Pseudocommands: %6d (zero:%5d)", count_pcmd_load, count_pcmd_zero);
        log_text(logtext);
-       sprintf(logtext, "Number of Move     Pseudocommands: %5d", count_pcmd_move);
+       sprintf(logtext, "Number of ConstAlu Pseudocommands: %6d (cmp: %5d, store:%5d)", count_pcmd_const_alu, count_pcmd_const_bra, count_pcmd_const_store);
        log_text(logtext);
-       sprintf(logtext, "Number of Load     Pseudocommands: %5d", count_load_instruction);
+       sprintf(logtext, "Number of Move     Pseudocommands: %6d", count_pcmd_move);
        log_text(logtext);
-       sprintf(logtext, "Number of Store    Pseudocommands: %5d (combined: %5d)", count_pcmd_store, count_pcmd_store - count_pcmd_store_comb);
+       sprintf(logtext, "Number of Load     Pseudocommands: %6d", count_load_instruction);
        log_text(logtext);
-       sprintf(logtext, "Number of OP       Pseudocommands: %5d", count_pcmd_op);
+       sprintf(logtext, "Number of Store    Pseudocommands: %6d (combined: %5d)", count_pcmd_store, count_pcmd_store - count_pcmd_store_comb);
        log_text(logtext);
-       sprintf(logtext, "Number of DUP      Pseudocommands: %5d", count_dup_instruction);
+       sprintf(logtext, "Number of OP       Pseudocommands: %6d", count_pcmd_op);
        log_text(logtext);
-       sprintf(logtext, "Number of Mem      Pseudocommands: %5d", count_pcmd_mem);
+       sprintf(logtext, "Number of DUP      Pseudocommands: %6d", count_dup_instruction);
        log_text(logtext);
-       sprintf(logtext, "Number of Method   Pseudocommands: %5d", count_pcmd_met);
+       sprintf(logtext, "Number of Mem      Pseudocommands: %6d", count_pcmd_mem);
        log_text(logtext);
-       sprintf(logtext, "Number of Branch   Pseudocommands: %5d (rets:%5d, Xrets: %5d)",
+       sprintf(logtext, "Number of Method   Pseudocommands: %6d", count_pcmd_met);
+       log_text(logtext);
+       sprintf(logtext, "Number of Branch   Pseudocommands: %6d (rets:%5d, Xrets: %5d)",
                        count_pcmd_bra, count_pcmd_return, count_pcmd_returnx);
        log_text(logtext);
-       sprintf(logtext, "Number of Table    Pseudocommands: %5d", count_pcmd_table);
+       sprintf(logtext, "Number of Table    Pseudocommands: %6d", count_pcmd_table);
        log_text(logtext);
-       sprintf(logtext, "Number of Useful   Pseudocommands: %5d", count_pcmd_table +
+       sprintf(logtext, "Number of Useful   Pseudocommands: %6d", count_pcmd_table +
                        count_pcmd_bra + count_pcmd_load + count_pcmd_mem + count_pcmd_op);
        log_text(logtext);
-       sprintf(logtext, "Number of Null Pointer Checks:     %5d", count_check_null);
+       sprintf(logtext, "Number of Null Pointer Checks:     %6d", count_check_null);
        log_text(logtext);
-       sprintf(logtext, "Number of Array Bound Checks:      %5d", count_check_bound);
+       sprintf(logtext, "Number of Array Bound Checks:      %6d", count_check_bound);
        log_text(logtext);
        sprintf(logtext, "Number of Try-Blocks: %d", count_tryblocks);
        log_text(logtext);
@@ -349,62 +406,61 @@ void print_stats()
        log_text(logtext);
        sprintf(logtext, "Distribution of stack sizes at block boundary");
        log_text(logtext);
-       sprintf(logtext, "    0    1    2    3    4    5    6    7    8    9    >=10");
+       sprintf(logtext, "     0     1     2     3     4     5     6     7     8     9  >=10");
        log_text(logtext);
-       sprintf(logtext, "%5d%5d%5d%5d%5d%5d%5d%5d%5d%5d%5d", count_block_stack[0],
+       sprintf(logtext, "%6d%6d%6d%6d%6d%6d%6d%6d%6d%6d%6d", count_block_stack[0],
                        count_block_stack[1], count_block_stack[2], count_block_stack[3], count_block_stack[4],
                        count_block_stack[5], count_block_stack[6], count_block_stack[7], count_block_stack[8],
                        count_block_stack[9], count_block_stack[10]);
        log_text(logtext);
        sprintf(logtext, "Distribution of store stack depth");
        log_text(logtext);
-       sprintf(logtext, "    0    1    2    3    4    5    6    7    8    9    >=10");
+       sprintf(logtext, "     0     1     2     3     4     5     6     7     8     9  >=10");
        log_text(logtext);
-       sprintf(logtext, "%5d%5d%5d%5d%5d%5d%5d%5d%5d%5d%5d", count_store_depth[0],
+       sprintf(logtext, "%6d%6d%6d%6d%6d%6d%6d%6d%6d%6d%6d", count_store_depth[0],
                        count_store_depth[1], count_store_depth[2], count_store_depth[3], count_store_depth[4],
                        count_store_depth[5], count_store_depth[6], count_store_depth[7], count_store_depth[8],
                        count_store_depth[9], count_store_depth[10]);
        log_text(logtext);
        sprintf(logtext, "Distribution of store creator chains first part");
        log_text(logtext);
-       sprintf(logtext, "    0    1    2    3    4    5    6    7    8    9  ");
+       sprintf(logtext, "     0     1     2     3     4     5     6     7     8     9");
        log_text(logtext);
-       sprintf(logtext, "%5d%5d%5d%5d%5d%5d%5d%5d%5d%5d", count_store_length[0],
+       sprintf(logtext, "%6d%6d%6d%6d%6d%6d%6d%6d%6d%6d", count_store_length[0],
                        count_store_length[1], count_store_length[2], count_store_length[3], count_store_length[4],
                        count_store_length[5], count_store_length[6], count_store_length[7], count_store_length[8],
                        count_store_length[9]);
        log_text(logtext);
        sprintf(logtext, "Distribution of store creator chains second part");
        log_text(logtext);
-       sprintf(logtext, "   10   11   12   13   14   15   16   17   18   19  >=20");
+       sprintf(logtext, "    10    11    12    13    14    15    16    17    18    19  >=20");
        log_text(logtext);
-       sprintf(logtext, "%5d%5d%5d%5d%5d%5d%5d%5d%5d%5d%5d", count_store_length[10],
+       sprintf(logtext, "%6d%6d%6d%6d%6d%6d%6d%6d%6d%6d%6d", count_store_length[10],
                        count_store_length[11], count_store_length[12], count_store_length[13], count_store_length[14],
                        count_store_length[15], count_store_length[16], count_store_length[17], count_store_length[18],
                        count_store_length[19], count_store_length[20]);
        log_text(logtext);
        sprintf(logtext, "Distribution of analysis iterations");
        log_text(logtext);
-       sprintf(logtext, "    1    2    3    4    >=5");
+       sprintf(logtext, "     1     2     3     4   >=5");
        log_text(logtext);
-       sprintf(logtext, "%5d%5d%5d%5d%5d", count_analyse_iterations[0], count_analyse_iterations[1],
+       sprintf(logtext, "%6d%6d%6d%6d%6d", count_analyse_iterations[0], count_analyse_iterations[1],
                        count_analyse_iterations[2], count_analyse_iterations[3], count_analyse_iterations[4]);
        log_text(logtext);
        sprintf(logtext, "Distribution of basic blocks per method");
        log_text(logtext);
-       sprintf(logtext, " <= 5 <=10 <=15 <=20 <=30 <=40 <=50 <=75  >75");
+       sprintf(logtext, "   <=5  <=10  <=15  <=20  <=30  <=40  <=50  <=75   >75");
        log_text(logtext);
-       sprintf(logtext, "%5d%5d%5d%5d%5d%5d%5d%5d%5d", count_method_bb_distribution[0],
+       sprintf(logtext, "%6d%6d%6d%6d%6d%6d%6d%6d%6d", count_method_bb_distribution[0],
                        count_method_bb_distribution[1], count_method_bb_distribution[2], count_method_bb_distribution[3],
                        count_method_bb_distribution[4], count_method_bb_distribution[5], count_method_bb_distribution[6],
                        count_method_bb_distribution[7], count_method_bb_distribution[8]);
        log_text(logtext);
        sprintf(logtext, "Distribution of basic block sizes");
        log_text(logtext);
-       sprintf(logtext,
-                        "  0    1    2    3    4   5   6   7   8   9 <13 <15 <17 <19 <21 <26 <31 >30");
+       sprintf(logtext, "     0     1     2     3     4    5    6    7    8    9  <13  <15  <17  <19  <21  <26  <31  >30");
        log_text(logtext);
-       sprintf(logtext, "%3d%5d%5d%5d%4d%4d%4d%4d%4d%4d%4d%4d%4d%4d%4d%4d%4d%4d",
+       sprintf(logtext, "%6d%6d%6d%6d%6d%5d%5d%5d%5d%5d%5d%5d%5d%5d%5d%5d%5d%5d",
                        count_block_size_distribution[0], count_block_size_distribution[1], count_block_size_distribution[2],
                        count_block_size_distribution[3], count_block_size_distribution[4], count_block_size_distribution[5],
                        count_block_size_distribution[6], count_block_size_distribution[7], count_block_size_distribution[8],
@@ -420,6 +476,10 @@ void print_stats()
        log_text(logtext);
        sprintf(logtext, "Size of Const Pool (Kb): %10.3f", (float) (count_const_pool_len + count_utf_len) / 1024);
        log_text(logtext);
+       sprintf(logtext, "Size of Class refs (Kb): %10.3f", (float) (count_classref_len) / 1024);
+       log_text(logtext);
+       sprintf(logtext, "Size of descriptors(Kb): %10.3f", (float) (count_parsed_desc_len) / 1024);
+       log_text(logtext);
        sprintf(logtext, "Size of Vftbl (Kb):      %10.3f", (float) count_vftbl_len / 1024);
        log_text(logtext);
        sprintf(logtext, "Size of comp stub (Kb):  %10.3f", (float) count_cstub_len / 1024);
@@ -437,13 +497,149 @@ void print_stats()
        log_text(logtext);
        sprintf(logtext, "Number of class inits:   %d", count_class_inits);
        log_text(logtext);
-       sprintf(logtext, "Number of loaded Methods: %d\n\n", count_all_methods);
+       sprintf(logtext, "Number of loaded Methods: %d\n", count_all_methods);
        log_text(logtext);
 
        sprintf(logtext, "Calls of utf_new: %22d", count_utf_new);
        log_text(logtext);
-       sprintf(logtext, "Calls of utf_new (element found): %6d\n\n", count_utf_new_found);
-       log_text(logtext);
+       sprintf(logtext, "Calls of utf_new (element found): %6d\n", count_utf_new_found);
+       log_text(logtext);
+
+
+       /* LSRA statistics ********************************************************/
+       sprintf(logtext, "Moves reg -> reg:     %6d",count_mov_reg_reg );
+       log_text(logtext);
+       sprintf(logtext, "Moves mem -> reg:     %6d",count_mov_mem_reg );
+       log_text(logtext);
+       sprintf(logtext, "Moves reg -> mem:     %6d",count_mov_reg_mem );
+       log_text(logtext);
+       sprintf(logtext, "Moves mem -> mem:     %6d",count_mov_mem_mem );
+       log_text(logtext);
+
+       sprintf(logtext, "Methods allocated by LSRA:         %6d", count_methods_allocated_by_lsra);
+       log_text(logtext);
+       sprintf(logtext, "Conflicts between local Variables: %6d", count_locals_conflicts);
+       log_text(logtext);
+       sprintf(logtext, "Local Variables held in Memory:    %6d", count_locals_spilled);
+       log_text(logtext);
+       sprintf(logtext, "Local Variables held in Registers: %6d", count_locals_register);
+       log_text(logtext);
+       sprintf(logtext, "Stackslots held in Memory:         %6d", count_ss_spilled);
+       log_text(logtext);
+       sprintf(logtext, "Stackslots held in Registers:      %6d",count_ss_register );
+       log_text(logtext);
+       sprintf(logtext, "Memory moves at BB Boundaries:     %6d",count_mem_move_bb );
+       log_text(logtext);
+       sprintf(logtext, "Number of interface slots:         %6d\n",count_interface_size );
+       log_text(logtext);
+       sprintf(logtext, "Number of Argument stack slots in register:  %6d",count_argument_reg_ss );
+       log_text(logtext);
+       sprintf(logtext, "Number of Argument stack slots in memory:    %6d\n",count_argument_mem_ss );
+       log_text(logtext);
+       sprintf(logtext, "Number of Methods kept in registers:         %6d\n",count_method_in_register );
+       log_text(logtext);
+               
+       /****if (useinlining)  ***/
+        {
+               u2 ii;
+               char * in_not_reasons[IN_MAX] = {
+                                               "unqVirt    | ",
+                                               "unqIntf    | ",
+                                               "outsider   | ",
+                                               "maxDepth   | ",
+                                               "maxcode    | ",
+                                               "maxlen     | ",
+                                               "exception  | ",
+                                               "notUnqVirt | ",
+                                               "notUnqIntf |"
+                                               };
+
+               sprintf(logtext, "Number of Methods Inlined :                              \t%6d",count_in );
+               log_text(logtext);
+               if (inlinevirtuals) {
+                 sprintf(logtext, "Number of Unique Virtual Methods inlined:                \t%6d",count_in_uniqVirt);
+                 log_text(logtext);
+                 sprintf(logtext, "Number of Unique Implemented Interface Methods inlined:    %6d",count_in_uniqIntf);
+                 log_text(logtext);
+                 }
+               sprintf(logtext, "Number of Methods Inlines (total) rejected:              \t%6d",count_in_rejected);
+               log_text(logtext);
+               sprintf(logtext, "Number of Methods Inlined rejected for multiple reasons: \t%6d",count_in_rejected_mult);
+               log_text(logtext);
+               sprintf(logtext, "Number of Methods where Inline max depth hit:            \t%6d",count_in_maxDepth);
+               log_text(logtext);
+               sprintf(logtext, "Number of Methods Inlined rejected for max methods       \t%6d\n",count_in_maxMethods);
+               log_text(logtext);
+               sprintf(logtext, "Number of Methods calls fom Outsider Class not inlined:  \t%6d",count_in_outsiders);
+               log_text(logtext);
+
+               sprintf(logtext, "Number of Unique Virtual Methods not inlined:            \t%6d",count_in_uniqueVirt_not_inlined);
+               log_text(logtext);
+               sprintf(logtext, "Number of Unique Implemented Interface Methods not inlined:%6d",count_in_uniqueInterface_not_inlined);
+               log_text(logtext);
+#define INLINEDETAILS
+#ifdef  INLINEDETAILS
+               sprintf(logtext, "\nDetails about Not Inlined Reasons :");
+               log_text(logtext);
+               for (ii=0;ii<512;ii++) {
+                       if (count_in_not[ii]>0) {
+                               char logtext2[MAXLOGTEXT]="\t";
+
+                               if (inlinevirtuals) {
+                                 if (ii & IN_UNIQUEVIRT) strcat(logtext2, in_not_reasons[N_UNIQUEVIRT]); 
+                                 if (ii & IN_UNIQUE_INTERFACE) strcat(logtext2,  in_not_reasons[N_UNIQUE_INTERFACE]);
+                                 if (ii & IN_NOT_UNIQUE_VIRT) strcat(logtext2,  in_not_reasons[N_NOT_UNIQUE_VIRT]);
+                                 if (ii & IN_NOT_UNIQUE_INTERFACE) strcat(logtext2,  in_not_reasons[N_NOT_UNIQUE_INTERFACE]);
+                                 }
+                               if (ii & IN_OUTSIDERS) strcat(logtext2,  in_not_reasons[N_OUTSIDERS]);
+                               if (ii & IN_MAXDEPTH) strcat(logtext2,  in_not_reasons[N_MAXDEPTH]);
+                               if (ii & IN_MAXCODE) strcat(logtext2,  in_not_reasons[N_MAXCODE]);
+                               if (ii & IN_JCODELENGTH) strcat(logtext2,  in_not_reasons[N_JCODELENGTH]);
+                               if (ii & IN_EXCEPTION) strcat(logtext2,  in_not_reasons[N_EXCEPTION]);
+                               sprintf(logtext, "  [%X]=%6d    %s",ii, count_in_not[ii], logtext2 );
+                               log_text(logtext);
+                               }
+                       }       
+#endif
+               }
+
+
+        /* instruction scheduler statistics **************************************/
+
+        sprintf(logtext, "Instruction scheduler statistics:");
+        log_text(logtext);
+        sprintf(logtext, "Number of basic blocks:       %7d", count_schedule_basic_blocks);
+        log_text(logtext);
+        sprintf(logtext, "Number of nodes:              %7d", count_schedule_nodes);
+        log_text(logtext);
+        sprintf(logtext, "Number of leaders nodes:      %7d", count_schedule_leaders);
+        log_text(logtext);
+        sprintf(logtext, "Number of max. leaders nodes: %7d", count_schedule_max_leaders);
+        log_text(logtext);
+        sprintf(logtext, "Length of critical path:      %7d\n", count_schedule_critical_path);
+        log_text(logtext);
+}
+
+
+/* mem_usagelog ****************************************************************
+
+   prints some memory related infos
+
+*******************************************************************************/
+
+void mem_usagelog(bool givewarnings)
+{
+       if ((memoryusage != 0) && givewarnings) {
+               dolog("Allocated memory not returned: %d", (s4) memoryusage);
+       }
+
+       if ((globalallocateddumpsize != 0) && givewarnings) {
+               dolog("Dump memory not returned: %d", (s4) globalallocateddumpsize);
+       }
+
+       dolog("Random/Dump - max. memory usage: %dkB/%dkB", 
+                 (s4) ((maxmemusage + 1023) / 1024),
+                 (s4) ((maxdumpsize + 1023) / 1024));
 }