添加调试日志

This commit is contained in:
xsl
2026-04-23 11:29:18 +08:00
parent 7ab4274e4f
commit fb434f09b8
8 changed files with 477 additions and 3 deletions
+98
View File
@@ -0,0 +1,98 @@
#include "DebugLog.h"
#include <android/log.h>
#include <sys/stat.h>
#include <sys/syscall.h>
#include <unistd.h>
#include <cstdarg>
#include <cstdio>
#include <ctime>
#include <mutex>
namespace {
std::mutex g_mtx;
FILE* g_fp = nullptr;
std::string g_path;
constexpr size_t kMaxSize = 2 * 1024 * 1024; // 2 MB before rotation
pid_t currentTid() {
return static_cast<pid_t>(syscall(SYS_gettid));
}
} // namespace
namespace DebugLog {
void init(const char* internalDataPath) {
std::lock_guard<std::mutex> lk(g_mtx);
if (g_fp) {
return; // already initialized
}
const char* base = (internalDataPath && *internalDataPath) ? internalDataPath : "/data/local/tmp";
g_path = std::string(base) + "/face_sdk_debug.log";
// Rotate once if current file is too large.
struct stat st{};
if (stat(g_path.c_str(), &st) == 0 && static_cast<size_t>(st.st_size) > kMaxSize) {
std::string backup = g_path + ".old";
std::remove(backup.c_str());
std::rename(g_path.c_str(), backup.c_str());
}
g_fp = std::fopen(g_path.c_str(), "a");
if (g_fp) {
time_t now = time(nullptr);
struct tm tm_info{};
localtime_r(&now, &tm_info);
char tbuf[64];
strftime(tbuf, sizeof(tbuf), "%Y-%m-%d %H:%M:%S", &tm_info);
std::fprintf(g_fp,
"\n========== DebugLog opened @ %s (pid=%d) ==========\n",
tbuf, getpid());
std::fflush(g_fp);
}
__android_log_print(ANDROID_LOG_INFO, "FACE_DBG",
"DebugLog file path: %s", g_path.c_str());
}
void log(const char* fmt, ...) {
char buf[1024];
va_list ap;
va_start(ap, fmt);
int n = std::vsnprintf(buf, sizeof(buf), fmt, ap);
va_end(ap);
if (n < 0) return;
pid_t tid = currentTid();
timespec ts{};
clock_gettime(CLOCK_REALTIME, &ts);
struct tm tm_info{};
localtime_r(&ts.tv_sec, &tm_info);
char timebuf[32];
strftime(timebuf, sizeof(timebuf), "%H:%M:%S", &tm_info);
std::lock_guard<std::mutex> lk(g_mtx);
if (g_fp) {
std::fprintf(g_fp, "[%s.%03ld][tid=%d] %s\n",
timebuf, ts.tv_nsec / 1000000, tid, buf);
std::fflush(g_fp);
}
__android_log_print(ANDROID_LOG_INFO, "FACE_DBG", "[tid=%d] %s", tid, buf);
}
void flush() {
std::lock_guard<std::mutex> lk(g_mtx);
if (g_fp) std::fflush(g_fp);
}
std::string getLogPath() {
std::lock_guard<std::mutex> lk(g_mtx);
return g_path;
}
} // namespace DebugLog
+25
View File
@@ -0,0 +1,25 @@
#ifndef FACE_SDK_DEBUGLOG_H
#define FACE_SDK_DEBUGLOG_H
#include <string>
namespace DebugLog {
// Call once (e.g. in android_main) with android_app->activity->internalDataPath.
// Safe to call multiple times; subsequent calls are no-ops.
void init(const char* internalDataPath);
// Thread-safe. Also mirrored to logcat with tag "FACE_DBG".
// Every line is prefixed with timestamp + thread id and flushed to disk immediately,
// so even a hard crash will preserve the tail.
void log(const char* fmt, ...) __attribute__((format(printf, 1, 2)));
// Force flush to disk.
void flush();
// Absolute path of the log file (valid after init()).
std::string getLogPath();
} // namespace DebugLog
#endif // FACE_SDK_DEBUGLOG_H
+84 -1
View File
@@ -3,12 +3,43 @@
#include <game-activity/native_app_glue/android_native_app_glue.h>
#include <game-activity/GameActivity.h>
#include "AndroidOut.h"
#include "DebugLog.h"
#include "FaceApp.h"
#include <android/asset_manager.h>
#include <sys/syscall.h>
#include <unistd.h>
#include <atomic>
#include <chrono>
#include <thread>
using namespace std;
static inline pid_t dbg_tid() {
return static_cast<pid_t>(syscall(SYS_gettid));
}
static const char* appCmdName(int32_t cmd) {
switch (cmd) {
case APP_CMD_INPUT_CHANGED: return "APP_CMD_INPUT_CHANGED";
case APP_CMD_INIT_WINDOW: return "APP_CMD_INIT_WINDOW";
case APP_CMD_TERM_WINDOW: return "APP_CMD_TERM_WINDOW";
case APP_CMD_WINDOW_RESIZED: return "APP_CMD_WINDOW_RESIZED";
case APP_CMD_WINDOW_REDRAW_NEEDED: return "APP_CMD_WINDOW_REDRAW_NEEDED";
case APP_CMD_CONTENT_RECT_CHANGED: return "APP_CMD_CONTENT_RECT_CHANGED";
case APP_CMD_GAINED_FOCUS: return "APP_CMD_GAINED_FOCUS";
case APP_CMD_LOST_FOCUS: return "APP_CMD_LOST_FOCUS";
case APP_CMD_CONFIG_CHANGED: return "APP_CMD_CONFIG_CHANGED";
case APP_CMD_LOW_MEMORY: return "APP_CMD_LOW_MEMORY";
case APP_CMD_START: return "APP_CMD_START";
case APP_CMD_RESUME: return "APP_CMD_RESUME";
case APP_CMD_SAVE_STATE: return "APP_CMD_SAVE_STATE";
case APP_CMD_PAUSE: return "APP_CMD_PAUSE";
case APP_CMD_STOP: return "APP_CMD_STOP";
case APP_CMD_DESTROY: return "APP_CMD_DESTROY";
default: return "APP_CMD_???";
}
}
extern "C" {
android_app* g_android_app = nullptr;
@@ -19,23 +50,32 @@ jobject g_callback = nullptr;
jobject g_callbackAnimationFinished = nullptr;
void handle_cmd(android_app *pApp, int32_t cmd) {
DebugLog::log(">> handle_cmd %s(%d) tid=%d", appCmdName(cmd), (int)cmd, dbg_tid());
switch (cmd) {
case APP_CMD_INIT_WINDOW:
aout << "APP_CMD_INIT_WINDOW" << std::endl;
DebugLog::log("handle_cmd APP_CMD_INIT_WINDOW: calling initVulkan()");
g_Application->initVulkan();
DebugLog::log("handle_cmd APP_CMD_INIT_WINDOW: initVulkan() returned, isInited=%d",
(int)g_Application->isInited());
break;
case APP_CMD_TERM_WINDOW:
aout << "APP_CMD_TERM_WINDOW" << std::endl;
DebugLog::log("handle_cmd APP_CMD_TERM_WINDOW: (no handler yet, swapChain/surface still point to dead ANativeWindow)");
break;
default:
break;
}
DebugLog::log("<< handle_cmd %s done", appCmdName(cmd));
}
const int ArgLen = 128*1024;
char g_InitArgString[ArgLen] = {0};
void android_main(struct android_app *pApp) {
DebugLog::init(pApp->activity->internalDataPath);
DebugLog::log("android_main start, pid=%d tid=%d, logPath=%s",
getpid(), dbg_tid(), DebugLog::getLogPath().c_str());
aout << "Welcome to android_main" << std::endl;
g_android_app = pApp;
g_assetManager = pApp->activity->assetManager;
@@ -80,7 +120,38 @@ void android_main(struct android_app *pApp) {
{
auto frameTime = (start_time - _lastDrawFrameTime);
_lastDrawFrameTime = chrono::duration_cast<chrono::milliseconds>(chrono::system_clock::now().time_since_epoch()).count();
g_Application->drawFrame(frameTime);
static uint64_t s_frameIdx = 0;
static uint64_t s_excCount = 0;
static uint64_t s_lastLoggedExc = 0;
++s_frameIdx;
if (s_frameIdx % 600 == 0) {
DebugLog::log("heartbeat: frame=%llu exceptions_so_far=%llu",
(unsigned long long)s_frameIdx,
(unsigned long long)s_excCount);
}
try {
g_Application->drawFrame(frameTime);
} catch (const std::exception& e) {
++s_excCount;
// Log first 10 exceptions verbosely, then at most one per 120 swallowed.
if (s_excCount <= 10 || (s_excCount - s_lastLoggedExc) >= 120) {
DebugLog::log("!!! drawFrame std::exception (frame=%llu count=%llu): %s",
(unsigned long long)s_frameIdx,
(unsigned long long)s_excCount,
e.what());
s_lastLoggedExc = s_excCount;
}
} catch (...) {
++s_excCount;
if (s_excCount <= 10 || (s_excCount - s_lastLoggedExc) >= 120) {
DebugLog::log("!!! drawFrame unknown exception (frame=%llu count=%llu)",
(unsigned long long)s_frameIdx,
(unsigned long long)s_excCount);
s_lastLoggedExc = s_excCount;
}
}
}
auto end_time = chrono::duration_cast<chrono::milliseconds>(chrono::system_clock::now().time_since_epoch()).count();
auto frameTime = end_time - last_update_time;
@@ -114,6 +185,12 @@ Java_com_hmwl_face_1sdk_FaceActivity_processImageNative(JNIEnv *env, jobject thi
jint width, jint height, jint format,
jint row_stride, jint pixel_stride,
jint rotation) {
static std::atomic<uint64_t> s_imgCount{0};
uint64_t n = s_imgCount.fetch_add(1) + 1;
if (n == 1 || n % 300 == 0) {
DebugLog::log("processImageNative #%llu tid=%d w=%d h=%d",
(unsigned long long)n, dbg_tid(), width, height);
}
// TODO: implement processImageNative()
uint8_t* imageData = static_cast<uint8_t*>(env->GetDirectBufferAddress(buffer));
jlong capacity = env->GetDirectBufferCapacity(buffer);
@@ -130,6 +207,12 @@ extern "C"
JNIEXPORT void JNICALL
Java_com_hmwl_face_1sdk_FaceActivity_passDataToNative(JNIEnv *env, jobject thiz, jobject buffer,
jint point_count, jint width, jint height) {
static std::atomic<uint64_t> s_ptCount{0};
uint64_t n = s_ptCount.fetch_add(1) + 1;
if (n == 1 || n % 300 == 0) {
DebugLog::log("passDataToNative #%llu tid=%d point_count=%d w=%d h=%d",
(unsigned long long)n, dbg_tid(), point_count, width, height);
}
// TODO: implement passDataToNative()
float* pos = static_cast<float*>(env->GetDirectBufferAddress(buffer));