Add profiler for native dictionary code

Change-Id: I2569756c9ef4fa677ae52f2ccfcb90d2115d129f
diff --git a/native/src/defines.h b/native/src/defines.h
index 73394ce..59eaa41 100644
--- a/native/src/defines.h
+++ b/native/src/defines.h
@@ -24,10 +24,56 @@
 #define LOG_TAG "LatinIME: "
 #endif
 #define DEBUG_DICT true
-#define DEBUG_DICT_FULL true
+#define DEBUG_DICT_FULL false
 #define DEBUG_SHOW_FOUND_WORD DEBUG_DICT_FULL
 #define DEBUG_NODE DEBUG_DICT_FULL
 #define DEBUG_TRACE DEBUG_DICT_FULL
+
+// Profiler
+#include <time.h>
+#define PROF_BUF_SIZE 100
+static double profile_buf[PROF_BUF_SIZE];
+static double profile_old[PROF_BUF_SIZE];
+static unsigned int profile_counter[PROF_BUF_SIZE];
+
+#define PROF_RESET prof_reset();
+#define PROF_COUNT(prof_buf_id) ++profile_counter[prof_buf_id];
+#define PROF_OPEN PROF_RESET;PROF_START(PROF_BUF_SIZE - 1);
+#define PROF_START(prof_buf_id) PROF_COUNT(prof_buf_id);profile_old[prof_buf_id] = (clock());
+#define PROF_CLOSE PROF_END(PROF_BUF_SIZE - 1);PROF_OUTALL;
+#define PROF_END(prof_buf_id) profile_buf[prof_buf_id] += ((clock()) - profile_old[prof_buf_id]);
+#define PROF_CLOCKOUT(prof_buf_id) LOGI("%s : clock is %f", __FUNCTION__,\
+        (clock() - profile_old[prof_buf_id]));
+#define PROF_OUTALL LOGI("--- %s ---", __FUNCTION__); prof_out();
+
+static void prof_reset(void){
+    for(int i = 0;i < PROF_BUF_SIZE;++i){
+        profile_buf[i] = 0;
+        profile_old[i] = 0;
+        profile_counter[i] = 0;
+    }
+}
+
+static void prof_out(void){
+    if (profile_counter[PROF_BUF_SIZE - 1] != 1) {
+        LOGI("Error: You must call PROF_OPEN before PROF_CLOSE.");
+    }
+    LOGI("Total time is %6.3f ms.",
+            profile_buf[PROF_BUF_SIZE - 1] * 1000 / (double) CLOCKS_PER_SEC);
+    double all = 0;
+    for(int i = 0; i < PROF_BUF_SIZE - 1; ++i){
+        all += profile_buf[i];
+    }
+    if(all == 0) all = 1;
+    for(int i = 0; i < PROF_BUF_SIZE - 1; ++i){
+        if(profile_buf[i] != 0) {
+            LOGI("(%d): Used %4.2f%%, %8.4f ms. Called %d times.",
+                    i, (profile_buf[i] * 100 /all),
+                    profile_buf[i] * 1000 / (double) CLOCKS_PER_SEC, profile_counter[i]);
+         }
+    }
+}
+
 #else // FLAG_DBG
 #define LOGI
 #define DEBUG_DICT false
@@ -35,6 +81,18 @@
 #define DEBUG_SHOW_FOUND_WORD false
 #define DEBUG_NODE false
 #define DEBUG_TRACE false
+
+#define PROF_BUF_SIZE 0
+#define PROF_RESET
+#define PROF_COUNT(prof_buf_id)
+#define PROF_OPEN
+#define PROF_START(prof_buf_id)
+#define PROF_CLOSE
+#define PROF_END(prof_buf_id)
+#define PROF_CLOCK_OUT(prof_buf_id)
+#define PROF_CLOCKOUT(prof_buf_id)
+#define PROF_OUTALL
+
 #endif // FLAG_DBG
 
 #ifndef U_SHORT_MAX
diff --git a/native/src/unigram_dictionary.cpp b/native/src/unigram_dictionary.cpp
index f679001..5e1212a 100644
--- a/native/src/unigram_dictionary.cpp
+++ b/native/src/unigram_dictionary.cpp
@@ -42,14 +42,20 @@
 UnigramDictionary::~UnigramDictionary() {}
 
 int UnigramDictionary::getSuggestions(int *codes, int codesSize, unsigned short *outWords,
-        int *frequencies, int *nextLetters, int nextLettersSize)
-{
+        int *frequencies, int *nextLetters, int nextLettersSize) {
+    PROF_OPEN;
+    PROF_START(0);
     initSuggestions(codes, codesSize, outWords, frequencies);
     if (DEBUG_DICT) assert(codesSize == mInputLength);
 
     const int MAX_DEPTH = min(mInputLength * MAX_DEPTH_MULTIPLIER, MAX_WORD_LENGTH);
-    getSuggestionCandidates(-1, -1, -1, nextLetters, nextLettersSize, MAX_DEPTH);
+    PROF_END(0);
 
+    PROF_START(1);
+    getSuggestionCandidates(-1, -1, -1, nextLetters, nextLettersSize, MAX_DEPTH);
+    PROF_END(1);
+
+    PROF_START(2);
     // Suggestion with missing character
     if (SUGGEST_WORDS_WITH_MISSING_CHARACTER) {
         for (int i = 0; i < codesSize; ++i) {
@@ -57,7 +63,9 @@
             getSuggestionCandidates(i, -1, -1, NULL, 0, MAX_DEPTH);
         }
     }
+    PROF_END(2);
 
+    PROF_START(3);
     // Suggestion with excessive character
     if (SUGGEST_WORDS_WITH_EXCESSIVE_CHARACTER
             && mInputLength >= MIN_USER_TYPED_LENGTH_FOR_EXCESSIVE_CHARACTER_SUGGESTION) {
@@ -66,7 +74,9 @@
             getSuggestionCandidates(-1, i, -1, NULL, 0, MAX_DEPTH);
         }
     }
+    PROF_END(3);
 
+    PROF_START(4);
     // Suggestion with transposed characters
     // Only suggest words that length is mInputLength
     if (SUGGEST_WORDS_WITH_TRANSPOSED_CHARACTERS) {
@@ -75,7 +85,9 @@
             getSuggestionCandidates(-1, -1, i, NULL, 0, mInputLength - 1);
         }
     }
+    PROF_END(4);
 
+    PROF_START(5);
     // Suggestions with missing space
     if (SUGGEST_WORDS_WITH_MISSING_SPACE_CHARACTER
             && mInputLength >= MIN_USER_TYPED_LENGTH_FOR_MISSING_SPACE_SUGGESTION) {
@@ -84,7 +96,9 @@
             getMissingSpaceWords(mInputLength, i);
         }
     }
+    PROF_END(5);
 
+    PROF_START(6);
     // Get the word count
     int suggestedWordsCount = 0;
     while (suggestedWordsCount < MAX_WORDS && mFrequencies[suggestedWordsCount] > 0) {
@@ -101,7 +115,8 @@
         }
         LOGI("\n");
     }
-
+    PROF_END(6);
+    PROF_CLOSE;
     return suggestedWordsCount;
 }