diff --git a/meshcore/KVM/Windows/kvm.c b/meshcore/KVM/Windows/kvm.c index 3cc3409..6e4f35a 100644 --- a/meshcore/KVM/Windows/kvm.c +++ b/meshcore/KVM/Windows/kvm.c @@ -36,7 +36,7 @@ limitations under the License. #include #endif -// #define KVMDEBUGENABLED 1 +//#define KVMDEBUGENABLED 1 ILibProcessPipe_SpawnTypes gProcessSpawnType = ILibProcessPipe_SpawnTypes_USER; int gProcessTSID = -1; extern int gRemoteMouseRenderDefault; @@ -77,8 +77,10 @@ void KvmCriticalLog(const char* msg, const char* file, int line, int user1, int if (DontDestroy == 0) CloseHandle(h); } #define KVMDEBUG(m,u) { KvmCriticalLog(m, __FILE__, __LINE__, u, GetLastError()); printf("KVMMSG: %s (%d,%d).\r\n", m, (int)u, (int)GetLastError()); } +#define KVMDEBUG2 ILIBLOGMESSAGEX #else #define KVMDEBUG(m, u) +#define KVMDEBUG2(...) #endif int TILE_WIDTH = 0; @@ -157,7 +159,7 @@ void kvm_setupSasPermissions() DWORD WINAPI kvm_ctrlaltdel(LPVOID Param) { UNREFERENCED_PARAMETER( Param ); - KVMDEBUG("kvm_ctrlaltdel", (int)Param); + KVMDEBUG("kvm_ctrlaltdel", (int)(uintptr_t)Param); typedef VOID(WINAPI *SendSas)(BOOL asUser); SendSas sas; @@ -667,10 +669,12 @@ void kvm_pause(int pause) { if (pause == 0) { + KVMDEBUG2("RESUME: KVM"); ILibProcessPipe_Pipe_Resume(ILibProcessPipe_Process_GetStdOut(gChildProcess)); } else { + KVMDEBUG2("PAUSE: KVM"); ILibProcessPipe_Pipe_Pause(ILibProcessPipe_Process_GetStdOut(gChildProcess)); } } @@ -999,16 +1003,19 @@ DWORD WINAPI kvm_server_mainloop_ex(LPVOID parm) } if (buf && !g_shutdown) { + KVMDEBUG2("Writing JPEG: %llu bytes", tilesize); switch (writeHandler((char*)buf, (int)tilesize, reserved)) { case ILibTransport_DoneState_INCOMPLETE: g_pause = 1; ILibRemoteLogging_printf(ILibChainGetLogger(gILibChain), ILibRemoteLogging_Modules_Agent_KVM, ILibRemoteLogging_Flags_VerbosityLevel_2, "Agent KVM: KVM PAUSE"); + KVMDEBUG2("JPEG WRITE resulted in PAUSE"); break; case ILibTransport_DoneState_ERROR: g_shutdown = 1; height = SCALED_HEIGHT; width = SCALED_WIDTH; + KVMDEBUG2("JPEG WRITE resulted in ERROR"); break; } free(buf); @@ -1125,6 +1132,10 @@ void kvm_relay_StdOutHandler(ILibProcessPipe_Process sender, char *buffer, size_ if (bufferLen > 4) { + if (ntohs(((unsigned short*)(buffer))[0]) > 1000) + { + KVMDEBUG2("Invalid KVM Command received: %u", ntohs(((unsigned short*)(buffer))[0])); + } if (ntohs(((unsigned short*)(buffer))[0]) == (unsigned short)MNG_JUMBO) { if (bufferLen > 8) @@ -1132,20 +1143,25 @@ void kvm_relay_StdOutHandler(ILibProcessPipe_Process sender, char *buffer, size_ if (bufferLen >= (size_t)(8 + (int)ntohl(((unsigned int*)(buffer))[1]))) { *bytesConsumed = 8 + (int)ntohl(((unsigned int*)(buffer))[1]); + KVMDEBUG2("Jumbo Packet received of size: %llu (bufferLen=%llu)", *bytesConsumed, bufferLen); + writeHandler(buffer, (int)*bytesConsumed, reserved); return; } } + KVMDEBUG2("Accumulate => JUMBO: [%llu bytes] bufferLen=%llu ", (size_t)(8 + (int)ntohl(((unsigned int*)(buffer))[1])), bufferLen); } else { size = ntohs(((unsigned short*)(buffer))[1]); if (size <= bufferLen) { + KVMDEBUG2("KVM Command: [%u: %llu bytes]", ntohs(((unsigned short*)(buffer))[0]), size); *bytesConsumed = size; writeHandler(buffer, size, reserved); return; } + KVMDEBUG2("Accumulate => KVM Command: [%u: %d bytes] bufferLen=%llu ", ntohs(((unsigned short*)(buffer))[0]), bufferLen); } } *bytesConsumed = 0; @@ -1207,7 +1223,7 @@ int kvm_relay_restart(int paused, void *pipeMgr, char *exePath, ILibKVM_WriteHan // Run the relay g_shutdown = 0; - KVMDEBUG("kvm_relay_restart / end", (int)kvmthread); + KVMDEBUG("kvm_relay_restart / end", (int)(uintptr_t)kvmthread); return 1; } diff --git a/microscript/ILibDuktape_Polyfills.c b/microscript/ILibDuktape_Polyfills.c index f7f827d..8f8387a 100644 --- a/microscript/ILibDuktape_Polyfills.c +++ b/microscript/ILibDuktape_Polyfills.c @@ -839,6 +839,11 @@ duk_ret_t ILibDuktape_Polyfills_Console_setInfoLevel(duk_context *ctx) return(0); } +duk_ret_t ILibDuktape_Polyfills_Console_setInfoMask(duk_context *ctx) +{ + ILIBLOGMESSAGEX2_SetMask(duk_require_uint(ctx, 0)); + return(0); +} duk_ret_t ILibDuktape_Polyfills_Console_rawLog(duk_context *ctx) { char *val = (char*)duk_require_string(ctx, 0); @@ -878,6 +883,7 @@ void ILibDuktape_Polyfills_Console(duk_context *ctx) ILibDuktape_CreateInstanceMethod(ctx, "setDestination", ILibDuktape_Polyfills_Console_setDestination, DUK_VARARGS); ILibDuktape_CreateInstanceMethod(ctx, "setInfoLevel", ILibDuktape_Polyfills_Console_setInfoLevel, 1); + ILibDuktape_CreateInstanceMethod(ctx, "setInfoMask", ILibDuktape_Polyfills_Console_setInfoMask, 1); duk_push_object(ctx); duk_push_int(ctx, ILibDuktape_Console_DestinationFlags_DISABLED); duk_put_prop_string(ctx, -2, "DISABLED"); diff --git a/microstack/ILibParsers.c b/microstack/ILibParsers.c index ab7c27a..72e8c12 100644 --- a/microstack/ILibParsers.c +++ b/microstack/ILibParsers.c @@ -134,6 +134,7 @@ void* gILibChain = NULL; // Global Chain Instance used for Remote Logging when ILibSemaphoreTrack_Handler ILibSemaphoreTrack_func = NULL; void* ILibSemaphoreTrack_user = NULL; +uint32_t _g_logMessageX = 0; #define ILibChain_SIGMAX 32 ILibLinkedList g_signalHandlers[ILibChain_SIGMAX] = { NULL }; @@ -2192,8 +2193,13 @@ int ILibChain_WindowsSelect(void *chain, fd_set *readset, fd_set *writeset, fd_s // FALSE means to remove tha HANDLE if (((ILibBaseChain*)chain)->currentHandle != NULL && ILibMemory_CanaryOK(info)) { + ILIBLOGMESSAGEX2(LOGEX_OVERLAPPED_IO, " * ILibChain_WindowsSelect(%p) [REMOVED]", ((ILibBaseChain*)chain)->currentHandle); ILibLinkedList_Remove(info->node); } + else + { + ILIBLOGMESSAGEX2(LOGEX_OVERLAPPED_IO, " * ILibChain_WindowsSelect(%p) [???] => %p, ", ((ILibBaseChain*)chain)->currentHandle); + } } } ((ILibBaseChain*)chain)->currentHandle = NULL; @@ -3548,14 +3554,17 @@ BOOL ILibChain_ReadEx_Sink(void *chain, HANDLE h, ILibWaitHandle_ErrorStatus sta DWORD bytesRead = 0; DWORD err; + if (status == ILibWaitHandle_ErrorStatus_REMOVED) { + ILIBLOGMESSAGEX2(LOGEX_OVERLAPPED_IO, "ILibChain_ReadEx_Sink(%p) [REMOVED]", h); ILibMemory_Free(data); return(FALSE); } if (GetOverlappedResult(data->fileHandle, data->p, &bytesRead, FALSE) && bytesRead > 0) { + ILIBLOGMESSAGEX2(LOGEX_OVERLAPPED_IO, "ILibChain_ReadEx_Sink(%p) [bytesRead: %lu]", h, bytesRead); if (data->handler != NULL) { data->handler(chain, data->fileHandle, ILibWaitHandle_ErrorStatus_NONE, data->buffer, bytesRead, data->user); } ILibMemory_Free(data); return(FALSE); @@ -3564,12 +3573,14 @@ BOOL ILibChain_ReadEx_Sink(void *chain, HANDLE h, ILibWaitHandle_ErrorStatus sta { if ((err=GetLastError()) == ERROR_IO_PENDING) { + ILIBLOGMESSAGEX2(LOGEX_OVERLAPPED_IO, "ILibChain_ReadEx_Sink(%p) [PENDING]", h); // Still pending, so wait for another callback return(TRUE); } else { // ERROR + ILIBLOGMESSAGEX2(LOGEX_OVERLAPPED_IO, "ILibChain_ReadEx_Sink(%p) [ERROR]", h); if (data->handler != NULL) { data->handler(chain, data->fileHandle, ILibWaitHandle_ErrorStatus_IO_ERROR, data->buffer, 0, data->user); } ILibMemory_Free(data); return(FALSE); @@ -3614,8 +3625,25 @@ ILibTransport_DoneState ILibChain_WriteEx2(void *chain, HANDLE h, OVERLAPPED *p, void ILibChain_ReadEx2_UnwindHandler(void *chain, void *user) { ILibChain_ReadEx_data *state = (ILibChain_ReadEx_data*)user; - state->handler(chain, state->fileHandle, ILibWaitHandle_ErrorStatus_NONE, state->buffer, (int)(uintptr_t)state->p, state->user); + ILIBLOGMESSAGEX2(LOGEX_OVERLAPPED_IO, " + ILibChain_ReadEx2_UnwindHandler(%p)", state->reserved); + + if (state->handler(chain, state->fileHandle, ILibWaitHandle_ErrorStatus_NONE, state->buffer, (int)(uintptr_t)state->p, state->user) == FALSE) + { + ILIBLOGMESSAGEX2(LOGEX_OVERLAPPED_IO, " -> ILibChain_ReadEx2_UnwindHandler() [Try Remove: %p]", state->reserved); + + // Need to remove HANDLE from list + void *node = ILibLinkedList_GetNode_Search(((ILibBaseChain*)chain)->auxSelectHandles, NULL, state->reserved); + if (node != NULL) + { + ILIBLOGMESSAGEX2(LOGEX_OVERLAPPED_IO, " -> Removing Handle [%p]", state->reserved); + ILibChain_WaitHandleInfo *info = (ILibChain_WaitHandleInfo*)ILibMemory_Extra(node); + ILibChain_ReadEx_data *data = (ILibChain_ReadEx_data*)info->user; + ILibMemory_Free(data); + ILibLinkedList_Remove(node); + } + } free(state); + ILIBLOGMESSAGEX2(LOGEX_OVERLAPPED_IO, " -> ILibChain_ReadEx2_UnwindHandler() [END]"); } void ILibChain_ReadEx2(void *chain, HANDLE h, OVERLAPPED *p, char *buffer, DWORD bufferLen, ILibChain_ReadEx_Handler handler, void *user, char *metadata) { @@ -3654,7 +3682,7 @@ void ILibChain_ReadEx2(void *chain, HANDLE h, OVERLAPPED *p, char *buffer, DWORD state->fileHandle = h; state->user = user; state->p = (void*)(uintptr_t)bytesRead; - + state->reserved = p != NULL ? p->hEvent : NULL; ILibChain_RunOnMicrostackThreadEx2(chain, ILibChain_ReadEx2_UnwindHandler, state, 1); } } @@ -3790,6 +3818,8 @@ void ILibChain_AddWaitHandleEx(void *chain, HANDLE h, int msTIMEOUT, ILibChain_W if (((ILibBaseChain*)chain)->currentHandle != h) { + ILIBLOGMESSAGEX2(LOGEX_OVERLAPPED_IO, "-- ILibChain_AddWaitHandlesEx(): %p", h); + void *node = ILibLinkedList_AddTailEx(((ILibBaseChain*)chain)->auxSelectHandles, h, metadata==NULL?1:1+strnlen_s(metadata, 1024)); info = (ILibChain_WaitHandleInfo*)ILibMemory_Extra(node); info->node = node; @@ -10745,6 +10775,25 @@ void ILIBLOGMESSAGEX(char *format, ...) ILIBLOGMESSSAGE(dest); } +void ILIBLOGMESSAGEX2(uint32_t mask, char *format, ...) +{ + if ((_g_logMessageX & mask) == mask) + { + char dest[4096]; + int len = 0; + va_list argptr; + + va_start(argptr, format); + len += vsnprintf(dest + len, sizeof(dest) - len, format, argptr); + va_end(argptr); + + ILIBLOGMESSSAGE(dest); + } +} +void ILIBLOGMESSAGEX2_SetMask(uint32_t m) +{ + _g_logMessageX = m; +} #if defined(__APPLE__) || defined(ILIB_NO_TIMEDJOIN) typedef struct ILibThread_AppleThread diff --git a/microstack/ILibParsers.h b/microstack/ILibParsers.h index 2fc683b..0c5967f 100644 --- a/microstack/ILibParsers.h +++ b/microstack/ILibParsers.h @@ -52,6 +52,10 @@ extern "C" { extern char* ILibCriticalLogFilename; +#define LOGEX_OVERLAPPED_IO 0x01 +#define LOGEX_PROCESSPIPE 0x02 + + #ifdef _WIN32_WCE #define REQUIRES_MEMORY_ALIGNMENT #define errno 0 @@ -1081,6 +1085,7 @@ int ILibIsRunningOnChainThread(void* chain); HANDLE fileHandle; OVERLAPPED *p; void *user; + void *reserved; }ILibChain_ReadEx_data; typedef struct ILibChain_WriteEx_data { @@ -1592,6 +1597,8 @@ int ILibIsRunningOnChainThread(void* chain); #define ILIBCRITICALEXITMSG(code, msg) {printf("%s", ILibCriticalLog(msg, __FILE__, __LINE__, 0, 0)); exit(code);} #define ILIBLOGMESSSAGE(msg) ILibCriticalLog(msg, __FILE__, __LINE__, 0, 0) void ILIBLOGMESSAGEX(char *format, ...); + void ILIBLOGMESSAGEX2(uint32_t m, char *format, ...); + void ILIBLOGMESSAGEX2_SetMask(uint32_t m); #if defined(WIN32) #define ILIBCRITICALERREXIT(ex) { ILibCriticalLog(NULL, __FILE__, __LINE__, GetLastError(), 0); exit(ex); } diff --git a/microstack/ILibProcessPipe.c b/microstack/ILibProcessPipe.c index 58d4962..f57eb74 100644 --- a/microstack/ILibProcessPipe.c +++ b/microstack/ILibProcessPipe.c @@ -1173,14 +1173,15 @@ void ILibProcessPipe_Pipe_ResumeEx(ILibProcessPipe_PipeObject* p) ILibChain_AddWaitHandle(p->manager->ChainLink.ParentChain, p->mOverlapped->hEvent, -1, ILibProcessPipe_Process_ReadHandler, p); p->PAUSED = 0; return; -#endif - +#else ILibProcessPipe_Pipe_ResumeEx_ContinueProcessing(p); if (p->PAUSED == 0) { ILibLifeTime_Add(ILibGetBaseTimer(p->manager->ChainLink.ParentChain), p, 0, &ILibProcessPipe_Process_StartPipeReaderWriterEx, NULL); // Need to context switch to Chain Thread } +#endif } + #ifdef WIN32 BOOL ILibProcessPipe_Process_Pipe_ReadExHandler(void *chain, HANDLE h, ILibWaitHandle_ErrorStatus status, char *buffer, DWORD bytesRead, void* user); #endif @@ -1273,13 +1274,20 @@ BOOL ILibProcessPipe_Process_Pipe_ReadExHandler(void *chain, HANDLE h, ILibWaitH size_t consumed = 0; if (status == ILibWaitHandle_ErrorStatus_NONE) { + ILIBLOGMESSAGEX2(LOGEX_PROCESSPIPE, "ReadExHandler[%p](%p) -> TotalRead: %llu, bytesRead: %llu", h, buffer, pipeObject->totalRead, bytesRead); pipeObject->totalRead += bytesRead; do { - handler(pipeObject->buffer + pipeObject->readOffset, pipeObject->totalRead, &consumed, pipeObject->user1, pipeObject->user2); - pipeObject->readOffset += consumed; - pipeObject->totalRead -= consumed; + if (pipeObject->PAUSED == 0) + { + ILIBLOGMESSAGEX2(LOGEX_PROCESSPIPE, " ReadExHandler(%p, %llu, %llu); [%llu]", pipeObject->buffer + pipeObject->readOffset, pipeObject->totalRead, consumed, pipeObject->readOffset); + handler(pipeObject->buffer + pipeObject->readOffset, pipeObject->totalRead, &consumed, pipeObject->user1, pipeObject->user2); + pipeObject->readOffset += consumed; + pipeObject->totalRead -= consumed; + ILIBLOGMESSAGEX2(LOGEX_PROCESSPIPE, " -> readOffset: %llu, totalRead: %llu, consumed: %llu, PAUSE: %d", pipeObject->readOffset, pipeObject->totalRead, consumed, pipeObject->PAUSED); + } } while (pipeObject->PAUSED == 0 && consumed != 0 && pipeObject->totalRead > 0); + if (pipeObject->totalRead == 0) { pipeObject->readOffset = 0; } if (pipeObject->PAUSED == 0) { @@ -1293,11 +1301,13 @@ BOOL ILibProcessPipe_Process_Pipe_ReadExHandler(void *chain, HANDLE h, ILibWaitH ILibMemory_ReallocateRaw(&(pipeObject->buffer), pipeObject->bufferSize * 2); pipeObject->bufferSize = pipeObject->bufferSize * 2; } + ILIBLOGMESSAGEX2(LOGEX_PROCESSPIPE, "ILibChain_ReadEx2() => (%p, %llu, %llu)", pipeObject->buffer, pipeObject->readOffset + pipeObject->totalRead, pipeObject->bufferSize - pipeObject->totalRead); ILibChain_ReadEx2(chain, h, pipeObject->mOverlapped, pipeObject->buffer + pipeObject->readOffset + pipeObject->totalRead, (DWORD)(pipeObject->bufferSize - pipeObject->totalRead), ILibProcessPipe_Process_Pipe_ReadExHandler, pipeObject, pipeObject->metadata); return(TRUE); } else { + ILIBLOGMESSAGEX2(LOGEX_PROCESSPIPE, "HANDLE will get removed"); return(FALSE); } }