diff --git a/meshcore/agentcore.c b/meshcore/agentcore.c index 6a4716490..18a934921 100644 --- a/meshcore/agentcore.c +++ b/meshcore/agentcore.c @@ -91,6 +91,7 @@ int gRemoteMouseRenderDefault = 0; #define MSH_IDENTIFIER (unsigned int)778924904 #define SCRIPT_ENGINE_PIPE_BUFFER_SIZE 65535 #define SERVER_DISCOVERY_BUFFER_SIZE 1024 +#define CONTROL_CHANNEL_LOG_THROTTLE_MS 600000 //!< Steady-state control-channel dial/failure logging throttle (10 min); target changes still log immediately #define MESH_AGENT_PORT 16990 //!< Default Mesh Agent Port #define MESH_MCASTv4_GROUP "239.255.255.235" @@ -4208,12 +4209,18 @@ void MeshServer_OnResponse(ILibWebClient_StateObject WebStateObject, int Interru break; } case ILibWebClient_ReceiveStatus_Complete: // Disconnection - printf("Control channel disconnected [fd=%d, authState=%d]\n", - ILibWebClient_GetDescriptorValue_FromStateObject(WebStateObject), agent->serverAuthState); - if (agent->serverAuthState != 3) { - printf("Connection LOST: Disconnected before full authentication (fd=%d, authState=%d) - possible gateway/firewall issue\n", + // Throttle the offline-retry-loop spam: gate the per-cycle disconnect logs on the same flag as the dial/FAILED lines. + if (agent->controlChannelLogThisAttempt != 0) { + printf("Control channel disconnected [fd=%d, authState=%d]\n", ILibWebClient_GetDescriptorValue_FromStateObject(WebStateObject), agent->serverAuthState); + } + if (agent->serverAuthState != 3) { + if (agent->controlChannelLogThisAttempt != 0) { + printf("Connection LOST: Disconnected before full authentication (fd=%d, authState=%d) - possible gateway/firewall issue\n", + ILibWebClient_GetDescriptorValue_FromStateObject(WebStateObject), agent->serverAuthState); + } } else { + // Post-auth drop is a rare, meaningful state change (a healthy session closing) - always log it. printf("Connection LOST: Disconnected after authentication (fd=%d) - server closed connection\n", ILibWebClient_GetDescriptorValue_FromStateObject(WebStateObject)); } @@ -4309,7 +4316,7 @@ void MeshServer_OnResponse(ILibWebClient_StateObject WebStateObject, int Interru long long elapsedMs = ILibGetUptime() - agent->controlChannelDialTick; // tls is only meaningful for wss; the ConnectSink flag tracks plain TCP connect on ws. const char *tlsState = (strncmp("wss:", agent->serveruri, 4) != 0) ? "n/a" : (agent->controlChannelTlsUp != 0 ? "up" : "down"); - printf("Connection FAILED: No HTTP response (fd=%d, status=%s, authState=%d, connState=%d, tls=%s, elapsedMs=%lld, attempt=%s)\n", + printf("Connection FAILED (latest attempt): No HTTP response (fd=%d, status=%s, authState=%d, connState=%d, tls=%s, elapsedMs=%lld, attempt=%s)\n", ILibWebClient_GetDescriptorValue_FromStateObject(WebStateObject), recvStatusStr, agent->serverAuthState, agent->serverConnectionState, tlsState, elapsedMs, agent->connectAttemptId); @@ -4355,7 +4362,7 @@ void MeshServer_ConnectEx_NetworkError(void *j) long long elapsedMs = ILibGetUptime() - agent->controlChannelDialTick; // tls is only meaningful for wss; the ConnectSink flag tracks plain TCP connect on ws. const char *tlsState = (strncmp("wss:", agent->serveruri, 4) != 0) ? "n/a" : (agent->controlChannelTlsUp != 0 ? "up" : "down"); - printf("Connection FAILED: Network timeout - server unreachable or gateway blocking (tls=%s, elapsedMs=%lld, attempt=%s)\n", + printf("Connection FAILED (latest attempt): Network timeout - server unreachable or gateway blocking (tls=%s, elapsedMs=%lld, attempt=%s)\n", tlsState, elapsedMs, agent->connectAttemptId); } agent->serverConnectionState = 0; @@ -4621,7 +4628,20 @@ void MeshServer_ConnectEx(MeshAgentHostContainer *agent) { meshServer.sin6_family = AF_UNSPEC; ILibRemoteLogging_printf(ILibChainGetLogger(agent->chain), ILibRemoteLogging_Modules_Agent_GuardPost, ILibRemoteLogging_Flags_VerbosityLevel_1, "agentcore: Could not resolve: %s", ILibScratchPad); - printf("agentcore: Could not resolve: %s\n", host); + // The dial-path throttle below is skipped when resolution fails, so throttle this retry spam here on the same 10-min gate + // (using an "UNRESOLVED" signature so a resolved<->unresolved flap still logs immediately) and keep the flag fresh for the downstream AutoRetry log. + { + long long nowTick = ILibGetUptime(); + agent->controlChannelLogThisAttempt = (agent->controlChannelLastLogTick == 0 || strcmp("UNRESOLVED", agent->controlChannelDialSig) != 0 || (nowTick - agent->controlChannelLastLogTick) >= CONTROL_CHANNEL_LOG_THROTTLE_MS) ? 1 : 0; + if (agent->controlChannelLogThisAttempt != 0) + { + agent->controlChannelLastLogTick = nowTick; + strcpy_s(agent->controlChannelDialSig, sizeof(agent->controlChannelDialSig), "UNRESOLVED"); + printf("agentcore: Could not resolve (latest attempt): %s suppressed_since_last=%u\n", host, agent->controlChannelSuppressed); + agent->controlChannelSuppressed = 0; + } + else { agent->controlChannelSuppressed++; } + } } } else @@ -4698,24 +4718,6 @@ void MeshServer_ConnectEx(MeshAgentHostContainer *agent) memset(agent->meshId, 0, sizeof(agent->meshId)); // Clear the meshid first in case we copy SHA256 memcpy_s(agent->meshId, sizeof(agent->meshId), ILibScratchPad, len); // Copy the correct length - // Diagnostic: log the MeshID (device group) this agent presents, in the server's base64 form. Once per process. - { - static int orphanProofLogged = 0; - if (orphanProofLogged == 0) - { - unsigned char *b64mesh = NULL; - int b64len = ILibBase64Encode((unsigned char*)agent->meshId, (int)len, &b64mesh); - orphanProofLogged = 1; - if (b64mesh != NULL) - { - int _opi; - for (_opi = 0; _opi < b64len; ++_opi) { if (b64mesh[_opi] == '+') { b64mesh[_opi] = '@'; } else if (b64mesh[_opi] == '/') { b64mesh[_opi] = '$'; } } - printf("OrphanProof: presenting MeshID=%s (rawlen=%d) to server=%s\n", (char*)b64mesh, (int)len, agent->serveruri != NULL ? agent->serveruri : "?"); - free(b64mesh); - } - } - } - #ifndef MICROSTACK_NOTLS util_keyhash(agent->selfcert, agent->g_selfid); // Compute our own identifier using our certificate #endif @@ -4751,7 +4753,6 @@ void MeshServer_ConnectEx(MeshAgentHostContainer *agent) ILibAddHeaderLine(req, "Authorization", 13, openframeAuthorization, (int)strlen(openframeAuthorization)); free(openframeAuthorization); } - printf("Openframe JWT: %s\n", extracted_token); free(extracted_token); } } @@ -4787,15 +4788,15 @@ void MeshServer_ConnectEx(MeshAgentHostContainer *agent) } else { proxylog = webproxy; } } - // Throttle repeated identical attempts: log the dial/failure pair only on target change or once per 60s, counting the rest. + // Throttle repeated identical attempts: log the dial/failure pair only on target change or once per CONTROL_CHANNEL_LOG_THROTTLE_MS, counting the rest. char dialSig[160]; snprintf(dialSig, sizeof(dialSig), "%s|%s|%d", agent->serveruri, (useproxy == 0 ? agent->serverip : "proxy"), (int)useproxy); - agent->controlChannelLogThisAttempt = (agent->controlChannelLastLogTick == 0 || strcmp(dialSig, agent->controlChannelDialSig) != 0 || (agent->controlChannelDialTick - agent->controlChannelLastLogTick) >= 60000) ? 1 : 0; + agent->controlChannelLogThisAttempt = (agent->controlChannelLastLogTick == 0 || strcmp(dialSig, agent->controlChannelDialSig) != 0 || (agent->controlChannelDialTick - agent->controlChannelLastLogTick) >= CONTROL_CHANNEL_LOG_THROTTLE_MS) ? 1 : 0; if (agent->controlChannelLogThisAttempt != 0) { agent->controlChannelLastLogTick = agent->controlChannelDialTick; strcpy_s(agent->controlChannelDialSig, sizeof(agent->controlChannelDialSig), dialSig); - printf("Connection: dialing uri=%s host=%s port=%u family=%s ip=%s useproxy=%d proxy=%s attempt=%s suppressed=%u\n", + printf("Connection: dialing (latest attempt) uri=%s host=%s port=%u family=%s ip=%s useproxy=%d proxy=%s attempt=%s suppressed_since_last=%u\n", agent->serveruri, host, port, (meshServer.sin6_family == AF_INET6 ? "IPv6" : (meshServer.sin6_family == AF_INET ? "IPv4" : "UNSPEC")), (useproxy == 0 ? agent->serverip : "(via-proxy)"), @@ -5018,7 +5019,8 @@ void MeshServer_Connect(MeshAgentHostContainer *agent) { delay = agent->retryTime + (timeout % agent->retryTime); // Random value between current value and double the current value } - printf("AutoRetry Connect in %d milliseconds\n", delay); + // Throttle the offline-retry-loop spam: only log the retry schedule on cycles the throttle decided to log. + if (agent->controlChannelLogThisAttempt != 0) { printf("AutoRetry Connect in %d milliseconds\n", delay); } if (agent->timerLogging != 0) { agent->retryTimerSet = 1; } ILibLifeTime_AddEx(ILibGetBaseTimer(agent->chain), agent, delay, (ILibLifeTime_OnCallback)MeshServer_ConnectEx, NULL); agent->retryTime = delay; @@ -5125,30 +5127,6 @@ int importSettings(MeshAgentHostContainer *agent, char* fileName) if (val[valLen - 1] == 13) { --valLen; } valLen = ILibTrimString(&val, valLen); - // Diagnostic: log when an .msh import delivers a MeshID (INITIAL / UNCHANGED / ADOPTING NEW old->new), read before the Put below. - if (keyLen == 6 && strncmp("MeshID", key, 6) == 0 && valLen > 2 && - ntohs(((unsigned short*)val)[0]) == HEX_IDENTIFIER && - ((valLen - 2) == 64 || (valLen - 2) == 96)) - { - char opNewRaw[48]; char opOldRaw[64]; - int opNewLen = util_hexToBuf(val + 2, (int)(valLen - 2), opNewRaw); - int opOldLen = ILibSimpleDataStore_Get(agent->masterDb, "MeshID", opOldRaw, sizeof(opOldRaw)); - unsigned char *opB64New = NULL, *opB64Old = NULL; - int _opj, opNl = ILibBase64Encode((unsigned char*)opNewRaw, opNewLen, &opB64New); - if (opB64New != NULL) { for (_opj = 0; _opj < opNl; ++_opj) { if (opB64New[_opj] == '+') { opB64New[_opj] = '@'; } else if (opB64New[_opj] == '/') { opB64New[_opj] = '$'; } } } - if (opOldLen <= 0) { - printf("OrphanProof: importing INITIAL MeshID=%s from %s\n", opB64New != NULL ? (char*)opB64New : "?", fileName); - } else if ((opOldLen == opNewLen) && (memcmp(opOldRaw, opNewRaw, opNewLen) == 0)) { - printf("OrphanProof: importing MeshID=%s from %s (UNCHANGED)\n", opB64New != NULL ? (char*)opB64New : "?", fileName); - } else { - int opOl = ILibBase64Encode((unsigned char*)opOldRaw, opOldLen, &opB64Old); - if (opB64Old != NULL) { for (_opj = 0; _opj < opOl; ++_opj) { if (opB64Old[_opj] == '+') { opB64Old[_opj] = '@'; } else if (opB64Old[_opj] == '/') { opB64Old[_opj] = '$'; } } } - printf("OrphanProof: ADOPTING NEW MeshID old=%s new=%s from %s (re-key delivered a new device group)\n", opB64Old != NULL ? (char*)opB64Old : "?", opB64New != NULL ? (char*)opB64New : "?", fileName); - } - if (opB64New != NULL) { free(opB64New); } - if (opB64Old != NULL) { free(opB64Old); } - } - if (!(keyLen == 10 && strncmp("CoreModule", key, 10) == 0)) { if (valLen == 0) diff --git a/openframe/token_extractor.c b/openframe/token_extractor.c index f77e147eb..438195fe3 100644 --- a/openframe/token_extractor.c +++ b/openframe/token_extractor.c @@ -1,7 +1,6 @@ #include #include #include -#include #include #include #include @@ -55,20 +54,6 @@ char* extract_token(const char* secret, const char* token_path) { char* decrypted_token = decrypt_aes_gcm((const unsigned char*)encrypted_data, ciphertext_len, (const unsigned char*)secret, &plaintext_len); free(encrypted_data); - // Diag: log every JWT read+decrypted from disk with a UTC timestamp, to correlate token reads with connects and check iat/exp. - if (decrypted_token != NULL) { - time_t now = time(NULL); - struct tm tmv; - char ts[32] = ""; -#ifdef WIN32 - gmtime_s(&tmv, &now); -#else - gmtime_r(&now, &tmv); -#endif - strftime(ts, sizeof(ts), "%Y-%m-%dT%H:%M:%SZ", &tmv); - printf("%s INFO Openframe token: read JWT from %s: %s tool_id=meshcentral-agent\n", ts, filename, decrypted_token); - } - return decrypted_token; }