Add some IPC log

This commit is contained in:
fanlusky committed 2026-06-21 15:55:45 +08:00
1 parent a36fd5e13b
commit 9d9c6946a2
3 files changed
+84 -14

No files matched your search

+2 -1
View File
@@ -15,6 +15,7 @@ add_compile_options(/Zc:__cplusplus)
# add_definitions(
# /DFANY_DEBUG=1
# /DFANY_IPC_DEBUG=1
# )
# fmt
@@ -165,4 +166,4 @@ add_library(${PROJECT_NAME} SHARED
"./src/Server.cpp"
)
target_link_libraries(${PROJECT_NAME} PRIVATE fmt::fmt-header-only)
target_link_libraries(${PROJECT_NAME} PRIVATE fmt::fmt-header-only)
+16
View File
@@ -17,6 +17,14 @@
#include "Global/FanyDefines.h"
#include "Utils/FanyUtils.h"
#ifdef FANY_IPC_DEBUG
#define FANY_IPC_LOG_RAW(message) OutputDebugString(message)
#define FANY_IPC_LOGF(...) OutputDebugString(fmt::format(__VA_ARGS__).c_str())
#else
#define FANY_IPC_LOG_RAW(message) ((void)0)
#define FANY_IPC_LOGF(...) ((void)0)
#endif
#pragma comment(lib, "Shcore.lib")
namespace
@@ -693,6 +701,7 @@ LRESULT CALLBACK CMetasequoiaIME_WindowProc(HWND hWnd, UINT message, WPARAM wPar
#ifdef FANY_DEBUG
OutputDebugString(fmt::format(L"[msime]: Try to connect named pipe via WM_ConnectNamedpipe").c_str());
#endif
FANY_IPC_LOG_RAW(L"[msime]: [ipc] WM_ConnectNamedpipe: start reconnect-all sequence");
KillTimer(hWnd, TIMER_CONNECT_ALL_NAMEDPIPE);
g_connectAllNamedpipeRetryCount = 0;
SendToAuxNamedpipe(L"kill");
@@ -704,6 +713,7 @@ LRESULT CALLBACK CMetasequoiaIME_WindowProc(HWND hWnd, UINT message, WPARAM wPar
#ifdef FANY_DEBUG
OutputDebugString(fmt::format(L"[msime]: WM_DisconnectNamedpipe.").c_str());
#endif
FANY_IPC_LOG_RAW(L"[msime]: [ipc] WM_DisconnectNamedpipe: closing all client pipe handles");
KillTimer(hWnd, TIMER_CONNECT_ALL_NAMEDPIPE);
KillTimer(hWnd, TIMER_CONNECT_TO_TSF_NAMEDPIPE);
g_connectAllNamedpipeRetryCount = 0;
@@ -715,6 +725,7 @@ LRESULT CALLBACK CMetasequoiaIME_WindowProc(HWND hWnd, UINT message, WPARAM wPar
#ifdef FANY_DEBUG
OutputDebugString(fmt::format(L"[msime]: Try to Connect to TSF named pipe").c_str());
#endif
FANY_IPC_LOG_RAW(L"[msime]: [ipc] WM_ConnectToTsfNamedpipe: start reconnect-to-tsf sequence");
KillTimer(hWnd, TIMER_CONNECT_TO_TSF_NAMEDPIPE);
g_connectToTsfNamedpipeRetryCount = 0;
// Keep old behavior: wait once before first connect try, but do it asynchronously.
@@ -727,6 +738,7 @@ LRESULT CALLBACK CMetasequoiaIME_WindowProc(HWND hWnd, UINT message, WPARAM wPar
// 如果用户已经切换走了,就不用继续重试
if (!Global::g_connected)
{
FANY_IPC_LOG_RAW(L"[msime]: [ipc] reconnect-all aborted because threadmgr is disconnected");
KillTimer(hWnd, TIMER_CONNECT_ALL_NAMEDPIPE);
g_connectAllNamedpipeRetryCount = 0;
break;
@@ -740,6 +752,7 @@ LRESULT CALLBACK CMetasequoiaIME_WindowProc(HWND hWnd, UINT message, WPARAM wPar
{
KillTimer(hWnd, TIMER_CONNECT_ALL_NAMEDPIPE);
g_connectAllNamedpipeRetryCount = 0;
FANY_IPC_LOG_RAW(L"[msime]: [ipc] reconnect-all succeeded");
#ifdef FANY_DEBUG
OutputDebugString(fmt::format(L"[msime]: Yes Connected to named pipe :)").c_str());
#endif
@@ -749,6 +762,7 @@ LRESULT CALLBACK CMetasequoiaIME_WindowProc(HWND hWnd, UINT message, WPARAM wPar
g_connectAllNamedpipeRetryCount++;
if (g_connectAllNamedpipeRetryCount >= CONNECT_ALL_NAMEDPIPE_MAX_RETRY)
{
FANY_IPC_LOG_RAW(L"[msime]: [ipc] reconnect-all reached max retry count");
KillTimer(hWnd, TIMER_CONNECT_ALL_NAMEDPIPE);
g_connectAllNamedpipeRetryCount = 0;
}
@@ -766,12 +780,14 @@ LRESULT CALLBACK CMetasequoiaIME_WindowProc(HWND hWnd, UINT message, WPARAM wPar
{
KillTimer(hWnd, TIMER_CONNECT_TO_TSF_NAMEDPIPE);
g_connectToTsfNamedpipeRetryCount = 0;
FANY_IPC_LOG_RAW(L"[msime]: [ipc] reconnect-to-tsf succeeded");
break;
}
g_connectToTsfNamedpipeRetryCount++;
if (g_connectToTsfNamedpipeRetryCount >= CONNECT_TO_TSF_NAMEDPIPE_MAX_RETRY)
{
FANY_IPC_LOG_RAW(L"[msime]: [ipc] reconnect-to-tsf reached max retry count");
KillTimer(hWnd, TIMER_CONNECT_TO_TSF_NAMEDPIPE);
g_connectToTsfNamedpipeRetryCount = 0;
}
+66 -13
View File
@@ -10,6 +10,16 @@
#include "MetasequoiaIME.h"
#include <fmt/xchar.h>
#ifdef FANY_IPC_DEBUG
#define FANY_IPC_LOG_RAW(message) OutputDebugString(message)
#define FANY_IPC_LOGW(message) OutputDebugString((message).c_str())
#define FANY_IPC_LOGF(...) OutputDebugString(fmt::format(__VA_ARGS__).c_str())
#else
#define FANY_IPC_LOG_RAW(message) ((void)0)
#define FANY_IPC_LOGW(message) ((void)0)
#define FANY_IPC_LOGF(...) ((void)0)
#endif
static HANDLE hMapFile = nullptr;
static void *pBuf;
static FanyImeSharedMemoryData *sharedData;
@@ -31,6 +41,38 @@ inline bool IsValidPipeHandle(HANDLE hPipeHandle)
return hPipeHandle != nullptr && hPipeHandle != INVALID_HANDLE_VALUE;
}
void LogCreateFileFailure(const wchar_t *pipeName)
{
FANY_IPC_LOGF(L"[msime]: [ipc] CreateFile failed: pipe={}, gle={}", pipeName, GetLastError());
}
void LogCreateFileSuccess(const wchar_t *pipeName)
{
FANY_IPC_LOGF(L"[msime]: [ipc] CreateFile connected: pipe={}", pipeName);
}
void LogWriteFailure(const wchar_t *pipeName, DWORD bytesWritten, DWORD expectedBytes)
{
FANY_IPC_LOGF(L"[msime]: [ipc] WriteFile failed: pipe={}, gle={}, bytes_written={}, expected_bytes={}", pipeName,
GetLastError(), bytesWritten, expectedBytes);
}
void LogReadFailure(const wchar_t *pipeName, DWORD bytesRead)
{
FANY_IPC_LOGF(L"[msime]: [ipc] ReadFile failed or empty: pipe={}, gle={}, bytes_read={}", pipeName,
GetLastError(), bytesRead);
}
void LogPeekFailure(const wchar_t *pipeName)
{
FANY_IPC_LOGF(L"[msime]: [ipc] PeekNamedPipe failed: pipe={}, gle={}", pipeName, GetLastError());
}
void LogAuxMessage(const std::wstring &message)
{
FANY_IPC_LOGF(L"[msime]: [ipc] SendToAuxNamedpipe: {}", message);
}
void ClosePipeHandleIfValid(HANDLE &hPipeHandle)
{
if (IsValidPipeHandle(hPipeHandle))
@@ -59,10 +101,12 @@ bool TryOpenClientPipe(HANDLE &hPipeHandle, const wchar_t *pipeName)
if (openedPipe == INVALID_HANDLE_VALUE)
{
LogCreateFileFailure(pipeName);
return false;
}
hPipeHandle = openedPipe;
LogCreateFileSuccess(pipeName);
return true;
}
} // namespace
@@ -438,12 +482,12 @@ void SendToNamedpipe()
if (hPipe == INVALID_HANDLE_VALUE)
{
// TODO: Log
LogCreateFileFailure(FANY_IME_NAMED_PIPE);
return;
}
else
{
// TODO: Log
LogCreateFileSuccess(FANY_IME_NAMED_PIPE);
}
}
@@ -459,6 +503,7 @@ void SendToNamedpipe()
{
/* Error handling: 必须将 hPipe 置为无效,否则将留下脏句柄,导致有些情况下无法再次连接 */
DWORD err = GetLastError();
LogWriteFailure(FANY_IME_NAMED_PIPE, bytesWritten, sizeof(namedpipeData));
// if (err == ERROR_BROKEN_PIPE || err == ERROR_NO_DATA)
// {
/* 将两个方向的管道同时置为无效 */
@@ -499,7 +544,7 @@ void SendToNamedpipe()
if (hPipe == INVALID_HANDLE_VALUE)
{
// TODO: Log
LogCreateFileFailure(FANY_IME_NAMED_PIPE);
#ifdef FANY_DEBUG
OutputDebugString(fmt::format(L"[msime]: SendToNamedpipe failed eventually02.").c_str());
#endif
@@ -507,7 +552,7 @@ void SendToNamedpipe()
}
else
{
// TODO: Log
LogCreateFileSuccess(FANY_IME_NAMED_PIPE);
}
DWORD bytesWritten = 0;
@@ -521,7 +566,7 @@ void SendToNamedpipe()
if (!ret || bytesWritten != sizeof(namedpipeData))
{
// TODO: Error handling
LogWriteFailure(FANY_IME_NAMED_PIPE, bytesWritten, sizeof(namedpipeData));
#ifdef FANY_DEBUG
OutputDebugString(fmt::format(L"[msime]: SendToNamedpipe failed eventually03.").c_str());
#endif
@@ -560,12 +605,12 @@ void ClearNamedpipeDataIfExists()
);
if (hFromServerPipe == INVALID_HANDLE_VALUE)
{
// TODO: Log
LogCreateFileFailure(FANY_IME_TO_TSF_NAMED_PIPE);
return;
}
else
{
// TODO: Log
LogCreateFileSuccess(FANY_IME_TO_TSF_NAMED_PIPE);
}
}
@@ -584,6 +629,10 @@ void ClearNamedpipeDataIfExists()
if (!peekOk || bytesAvailable == 0)
{
if (!peekOk)
{
LogPeekFailure(FANY_IME_TO_TSF_NAMED_PIPE);
}
break; // no more data or pipe error
}
@@ -597,6 +646,7 @@ void ClearNamedpipeDataIfExists()
if (!readOk || bytesRead == 0)
{
LogReadFailure(FANY_IME_TO_TSF_NAMED_PIPE, bytesRead);
break;
}
}
@@ -626,7 +676,7 @@ struct FanyImeNamedpipeDataToTsf *TryReadDataFromServerPipeWithTimeout()
);
if (hFromServerPipe == INVALID_HANDLE_VALUE)
{
// TODO: Log
LogCreateFileFailure(FANY_IME_TO_TSF_NAMED_PIPE);
namedpipeDataFromServer.msg_type = Global::DataFromServerMsgType::Normal;
// wcscpy_s(namedpipeDataFromServer.candidate_string, L"PipeOpenError");
wcscpy_s(namedpipeDataFromServer.candidate_string, L"X");
@@ -634,7 +684,7 @@ struct FanyImeNamedpipeDataToTsf *TryReadDataFromServerPipeWithTimeout()
}
else
{
// TODO: Log
LogCreateFileSuccess(FANY_IME_TO_TSF_NAMED_PIPE);
}
}
@@ -661,6 +711,7 @@ struct FanyImeNamedpipeDataToTsf *TryReadDataFromServerPipeWithTimeout()
/* Error handling: 必须将 hFromServerPipe 置为无效,否则将留下脏句柄,导致有些情况下无法再次连接 */
CloseHandle(hFromServerPipe);
hFromServerPipe = INVALID_HANDLE_VALUE;
FANY_IPC_LOGF(L"[msime]: [ipc] TryReadDataFromServerPipeWithTimeout timeout after {} ms", timeoutMs);
namedpipeDataFromServer.msg_type = Global::DataFromServerMsgType::Normal;
// Pipe timeout error
@@ -690,7 +741,7 @@ struct FanyImeNamedpipeDataToTsf *ReadDataFromServerViaNamedPipe()
);
if (hFromServerPipe == INVALID_HANDLE_VALUE)
{
// TODO: Log
LogCreateFileFailure(FANY_IME_TO_TSF_NAMED_PIPE);
namedpipeDataFromServer.msg_type = 0;
// wcscpy_s(namedpipeDataFromServer.candidate_string, L"PipeOpenError");
wcscpy_s(namedpipeDataFromServer.candidate_string, L"X");
@@ -698,7 +749,7 @@ struct FanyImeNamedpipeDataToTsf *ReadDataFromServerViaNamedPipe()
}
else
{
// TODO: Log
LogCreateFileSuccess(FANY_IME_TO_TSF_NAMED_PIPE);
}
}
@@ -712,7 +763,7 @@ struct FanyImeNamedpipeDataToTsf *ReadDataFromServerViaNamedPipe()
);
if (!readResult || bytesRead == 0) // Disconnected or error
{
// TODO: Log
LogReadFailure(FANY_IME_TO_TSF_NAMED_PIPE, bytesRead);
}
else
{
@@ -764,8 +815,10 @@ void SendToAuxNamedpipe(std::wstring pipeData)
#ifdef FANY_DEBUG
OutputDebugString(fmt::format(L"[msime]: SendToAuxNamedpipe: PipeOpenError: {}", pipeData).c_str());
#endif
LogCreateFileFailure(FANY_IME_AUX_NAMED_PIPE);
return;
}
LogAuxMessage(pipeData);
DWORD bytesWritten = 0;
BOOL ret = WriteFile( //
hAuxPipe, //
@@ -776,7 +829,7 @@ void SendToAuxNamedpipe(std::wstring pipeData)
);
if (!ret || bytesWritten != pipeData.length() * sizeof(wchar_t))
{
// TODO: Error handling
LogWriteFailure(FANY_IME_AUX_NAMED_PIPE, bytesWritten, pipeData.length() * sizeof(wchar_t));
}
CloseHandle(hAuxPipe);
}