Make profiler use getTimeInMicroSec().
Bug: 17797064
Change-Id: Ie992c9454edfc3bf93d5ea367c3a4427b513a205
diff --git a/native/jni/com_android_inputmethod_latin_BinaryDictionary.cpp b/native/jni/com_android_inputmethod_latin_BinaryDictionary.cpp
index 118f600..697ebca 100644
--- a/native/jni/com_android_inputmethod_latin_BinaryDictionary.cpp
+++ b/native/jni/com_android_inputmethod_latin_BinaryDictionary.cpp
@@ -35,6 +35,7 @@
#include "utils/int_array_view.h"
#include "utils/jni_data_utils.h"
#include "utils/log_utils.h"
+#include "utils/profiler.h"
#include "utils/time_keeper.h"
namespace latinime {
@@ -43,8 +44,8 @@
static jlong latinime_BinaryDictionary_open(JNIEnv *env, jclass clazz, jstring sourceDir,
jlong dictOffset, jlong dictSize, jboolean isUpdatable) {
- PROF_OPEN;
- PROF_START(66);
+ PROF_INIT;
+ PROF_TIMER_START(66);
const jsize sourceDirUtf8Length = env->GetStringUTFLength(sourceDir);
if (sourceDirUtf8Length <= 0) {
AKLOGE("DICT: Can't get sourceDir string");
@@ -63,8 +64,7 @@
Dictionary *const dictionary =
new Dictionary(env, std::move(dictionaryStructureWithBufferPolicy));
- PROF_END(66);
- PROF_CLOSE;
+ PROF_TIMER_END(66);
return reinterpret_cast<jlong>(dictionary);
}
diff --git a/native/jni/src/defines.h b/native/jni/src/defines.h
index 8851185..0e67b4d 100644
--- a/native/jni/src/defines.h
+++ b/native/jni/src/defines.h
@@ -23,10 +23,10 @@
#define AK_FORCE_INLINE inline
#endif // __GNUC__
-#if defined(FLAG_DO_PROFILE) || defined(FLAG_DBG)
+#if defined(FLAG_DBG)
#undef AK_FORCE_INLINE
#define AK_FORCE_INLINE inline
-#endif // defined(FLAG_DO_PROFILE) || defined(FLAG_DBG)
+#endif // defined(FLAG_DBG)
// Must be equal to Constants.Dictionary.MAX_WORD_LENGTH in Java
#define MAX_WORD_LENGTH 48
@@ -172,69 +172,6 @@
#define INTS_TO_CHARS(input, length, output)
#endif // defined(FLAG_DO_PROFILE) || defined(FLAG_DBG)
-#ifdef FLAG_DO_PROFILE
-// Profiler
-#include <time.h>
-
-#define PROF_BUF_SIZE 100
-static float profile_buf[PROF_BUF_SIZE];
-static float 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 do { PROF_RESET; PROF_START(PROF_BUF_SIZE - 1); } while (0)
-#define PROF_START(prof_buf_id) do { \
- PROF_COUNT(prof_buf_id); profile_old[prof_buf_id] = (clock()); } while (0)
-#define PROF_CLOSE do { PROF_END(PROF_BUF_SIZE - 1); PROF_OUTALL; } while (0)
-#define PROF_END(prof_buf_id) profile_buf[prof_buf_id] += ((clock()) - profile_old[prof_buf_id])
-#define PROF_CLOCKOUT(prof_buf_id) \
- AKLOGI("%s : clock is %f", __FUNCTION__, (clock() - profile_old[prof_buf_id]))
-#define PROF_OUTALL do { AKLOGI("--- %s ---", __FUNCTION__); prof_out(); } while (0)
-
-static inline 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 inline void prof_out(void) {
- if (profile_counter[PROF_BUF_SIZE - 1] != 1) {
- AKLOGI("Error: You must call PROF_OPEN before PROF_CLOSE.");
- }
- AKLOGI("Total time is %6.3f ms.",
- profile_buf[PROF_BUF_SIZE - 1] * 1000.0f / static_cast<float>(CLOCKS_PER_SEC));
- float all = 0.0f;
- for (int i = 0; i < PROF_BUF_SIZE - 1; ++i) {
- all += profile_buf[i];
- }
- if (all < 1.0f) all = 1.0f;
- for (int i = 0; i < PROF_BUF_SIZE - 1; ++i) {
- if (profile_buf[i] > 0.0f) {
- AKLOGI("(%d): Used %4.2f%%, %8.4f ms. Called %d times.",
- i, (profile_buf[i] * 100.0f / all),
- profile_buf[i] * 1000.0f / static_cast<float>(CLOCKS_PER_SEC),
- profile_counter[i]);
- }
- }
-}
-
-#else // FLAG_DO_PROFILE
-#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_DO_PROFILE
-
#ifdef FLAG_DBG
#define DEBUG_DICT true
#define DEBUG_DICT_FULL false
diff --git a/native/jni/src/suggest/core/suggest.cpp b/native/jni/src/suggest/core/suggest.cpp
index c372d66..e5e9b46 100644
--- a/native/jni/src/suggest/core/suggest.cpp
+++ b/native/jni/src/suggest/core/suggest.cpp
@@ -29,6 +29,7 @@
#include "suggest/core/result/suggestions_output_utils.h"
#include "suggest/core/session/dic_traverse_session.h"
#include "suggest/core/suggest_options.h"
+#include "utils/profiler.h"
namespace latinime {
@@ -48,8 +49,8 @@
int *inputXs, int *inputYs, int *times, int *pointerIds, int *inputCodePoints,
int inputSize, const float weightOfLangModelVsSpatialModel,
SuggestionResults *const outSuggestionResults) const {
- PROF_OPEN;
- PROF_START(0);
+ PROF_INIT;
+ PROF_TIMER_START(0);
const float maxSpatialDistance = TRAVERSAL->getMaxSpatialDistance();
DicTraverseSession *tSession = static_cast<DicTraverseSession *>(traverseSession);
tSession->setupForGetSuggestions(pInfo, inputCodePoints, inputSize, inputXs, inputYs, times,
@@ -57,8 +58,8 @@
// TODO: Add the way to evaluate cache
initializeSearch(tSession);
- PROF_END(0);
- PROF_START(1);
+ PROF_TIMER_END(0);
+ PROF_TIMER_START(1);
// keep expanding search dicNodes until all have terminated.
while (tSession->getDicTraverseCache()->activeSize() > 0) {
@@ -66,12 +67,11 @@
tSession->getDicTraverseCache()->advanceActiveDicNodes();
tSession->getDicTraverseCache()->advanceInputIndex(inputSize);
}
- PROF_END(1);
- PROF_START(2);
+ PROF_TIMER_END(1);
+ PROF_TIMER_START(2);
SuggestionsOutputUtils::outputSuggestions(
SCORING, tSession, weightOfLangModelVsSpatialModel, outSuggestionResults);
- PROF_END(2);
- PROF_CLOSE;
+ PROF_TIMER_END(2);
}
/**
diff --git a/native/jni/src/utils/profiler.h b/native/jni/src/utils/profiler.h
new file mode 100644
index 0000000..5f107fe
--- /dev/null
+++ b/native/jni/src/utils/profiler.h
@@ -0,0 +1,86 @@
+/*
+ * Copyright (C) 2014, The Android Open Source Project
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+#ifndef LATINIME_PROFILER_H
+#define LATINIME_PROFILER_H
+
+#ifdef FLAG_DO_PROFILE
+
+#include "defines.h"
+
+#include <ctime>
+#include <unordered_map>
+
+namespace latinime {
+
+class Profiler final {
+ public:
+ Profiler(const clockid_t clockId)
+ : mClockId(clockId), mStartTime(getTimeInMicroSec()), mStartTimes(), mTimes(),
+ mCounters() {}
+
+ ~Profiler() {
+ const float totalTime =
+ static_cast<float>(getTimeInMicroSec() - mStartTime) / 1000.f;
+ AKLOGI("Total time is %6.3f ms.", totalTime);
+ for (const auto &time : mTimes) {
+ AKLOGI("(%d): Used %4.2f%%, %8.4f ms. Called %d times.", time.first,
+ time.second / totalTime * 100.0f, time.second, mCounters[time.first]);
+ }
+ }
+
+ void startTimer(const int id) {
+ mStartTimes[id] = getTimeInMicroSec();
+ }
+
+ void endTimer(const int id) {
+ mTimes[id] += static_cast<float>(getTimeInMicroSec() - mStartTimes[id]) / 1000.0f;
+ mCounters[id]++;
+ }
+
+ operator bool() const { return false; }
+
+ private:
+ DISALLOW_IMPLICIT_CONSTRUCTORS(Profiler);
+
+ const clockid_t mClockId;
+ int64_t mStartTime;
+ std::unordered_map<int, int64_t> mStartTimes;
+ std::unordered_map<int, float> mTimes;
+ std::unordered_map<int, int> mCounters;
+
+ int64_t getTimeInMicroSec() {
+ timespec time;
+ clock_gettime(mClockId, &time);
+ return static_cast<int64_t>(time.tv_sec) * 1000000
+ + static_cast<int64_t>(time.tv_nsec) / 1000;
+ }
+};
+} // namespace latinime
+
+#define PROF_INIT Profiler __LATINIME__PROFILER__(CLOCK_THREAD_CPUTIME_ID)
+#define PROF_TIMER_START(timer_id) __LATINIME__PROFILER__.startTimer(timer_id)
+#define PROF_TIMER_END(timer_id) __LATINIME__PROFILER__.endTimer(timer_id)
+
+#else // FLAG_DO_PROFILE
+
+#define PROF_INIT
+#define PROF_TIMER_START(timer_id)
+#define PROF_TIMER_END(timer_id)
+
+#endif // FLAG_DO_PROFILE
+
+#endif /* LATINIME_PROFILER_H */