Merge "Make profiler use getTimeInMicroSec()."
This commit is contained in:
commit
91bdbcfc72
4 changed files with 100 additions and 77 deletions
|
@ -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 @@ class ProximityInfo;
|
|||
|
||||
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 @@ static jlong latinime_BinaryDictionary_open(JNIEnv *env, jclass clazz, jstring s
|
|||
|
||||
Dictionary *const dictionary =
|
||||
new Dictionary(env, std::move(dictionaryStructureWithBufferPolicy));
|
||||
PROF_END(66);
|
||||
PROF_CLOSE;
|
||||
PROF_TIMER_END(66);
|
||||
return reinterpret_cast<jlong>(dictionary);
|
||||
}
|
||||
|
||||
|
|
|
@ -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 @@ static inline void showStackTrace() {
|
|||
#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
|
||||
|
|
|
@ -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 @@ void Suggest::getSuggestions(ProximityInfo *pInfo, void *traverseSession,
|
|||
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 @@ void Suggest::getSuggestions(ProximityInfo *pInfo, void *traverseSession,
|
|||
// 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 @@ void Suggest::getSuggestions(ProximityInfo *pInfo, void *traverseSession,
|
|||
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);
|
||||
}
|
||||
|
||||
/**
|
||||
|
|
86
native/jni/src/utils/profiler.h
Normal file
86
native/jni/src/utils/profiler.h
Normal file
|
@ -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 */
|
Loading…
Reference in a new issue