private void sinkOnNewTraceFile(object sender, FileSystemEventArgs e) { TheCDEKPIs.IncrementKPI(eKPINames.IISRejectedClientConnections); // Log any other necessary KPIs here if (!DisableWriteToSYSLOG) { var failedReqInfo = ReadIISFailedReqTrace(e.FullPath); string errorMsg = "IIS Failed Request: "; errorMsg += failedReqInfo.Verb != null ? $"{failedReqInfo.Verb} request " : "Request "; errorMsg += failedReqInfo.RequestURL != null ? $"on {failedReqInfo.RequestURL} " : ""; errorMsg += failedReqInfo.ClientIP != null ? $"by {failedReqInfo.ClientIP} " : ""; errorMsg += failedReqInfo.StatusCode != null ? $"returned code {failedReqInfo.StatusCode} " : "returned "; errorMsg += failedReqInfo.TimeTaken != null ? $"in {failedReqInfo.TimeTaken} ms " : ""; errorMsg += failedReqInfo.ErrorCode != null ? $"- {failedReqInfo.ErrorCode}" : ""; try { // For now, just discard any messages if queue has hit its capacity if (queuedErrorMessages.Count < queuedErrorMessages.BoundedCapacity) { TheCommonUtils.cdeRunTaskAsync("QueueIISError" + errorCount, (o) => { queuedErrorMessages.TryAdd(errorMsg, bcTimeOutSeconds * 1000, TheBaseAssets.MasterSwitchCancelationToken); }); } } catch (Exception) { } } }
void sinkUploadDataCompleted(TheRequestData eResult) { if (eResult != null && eResult.ResponseBuffer != null && eResult.ResponseBuffer.Length > 0) { try { TheCDEKPIs.IncrementKPI(eKPINames.QSReceivedTSM); TheCDEKPIs.IncrementKPI(eKPINames.QKBReceived, eResult.ResponseBuffer.Length); if (eResult.StatusCode != 200) { TheBaseAssets.MySYSLOG.WriteToLog(243, TSM.L(eDEBUG_LEVELS.OFF) ? null : new TSM("QueuedSender", $"Server responded with not-ok ...Code: {eResult.StatusCode} error: {TheCommonUtils.CArray2UTF8String(eResult.ResponseBuffer)}", eMsgLevel.l2_Warning), true); FireSenderProblem(new TheRequestData() { ErrorDescription = $"{eResult.StatusCode}:Server responded with not-ok ...Code: {eResult.StatusCode}" }); return; } List <TheDeviceMessage> tDevList = null; if (eResult.ResponseMimeType.Contains("zip")) { tDevList = TheDeviceMessage.DeserializeJSONToObject(TheCommonUtils.cdeDecompressToString(eResult.ResponseBuffer)); } else { tDevList = TheDeviceMessage.DeserializeJSONToObject(TheCommonUtils.CArray2UTF8String(eResult.ResponseBuffer)); } if (tDevList != null && tDevList.Count > 0) { eResult.StatusCode = 0; TheCorePubSub.ProcessClientDeviceMessage(this, eResult, tDevList); } } catch (Exception ee) { TheBaseAssets.MySYSLOG.WriteToLog(243, TSM.L(eDEBUG_LEVELS.ESSENTIALS) ? null : new TSM("QueuedSender", $"Error in {MyTargetNodeChannel?.ToMLString()}", eMsgLevel.l1_Error, ee.ToString())); } } else { if (MyTargetNodeChannel.SenderType != cdeSenderType.CDE_SERVICE) { TheBaseAssets.MySYSLOG.WriteToLog(243, TSM.L(eDEBUG_LEVELS.VERBOSE) ? null : new TSM("QueuedSender", $"Did not receive any data from {MyTargetNodeChannel?.ToMLString()}", eMsgLevel.l6_Debug)); } } }
public void ProcessHttpRequest(HttpListenerContext mContext) { TheRequestData tRequestData = new TheRequestData(); try { tRequestData.RequestUri = mContext.Request.Url; // TheSystemMessageLog.ToCo(tRequestData.RequestUri.ToString(), true); tRequestData.UserAgent = mContext.Request.UserAgent; tRequestData.ServerTags = null; tRequestData.HttpMethod = mContext.Request.HttpMethod; //NEW 3.200 tRequestData.Header = TheCommonUtils.cdeNameValueToDirectory(mContext.Request.Headers); tRequestData.ResponseMimeType = mContext.Request.ContentType; tRequestData.ClientCert = mContext.Request.GetClientCertificate(); if (TheCommCore.MyHttpService != null && TheBaseAssets.MyServiceHostInfo.ClientCertificateUsage > 1) //If CDE requires a certificate, terminate all incoming requests before any processing { var err = TheCommCore.MyHttpService.ValidateCertificateRoot(tRequestData); if (TheBaseAssets.MyServiceHostInfo.DisableNMI && !string.IsNullOrEmpty(err)) { mContext.Response.StatusCode = (int)eHttpStatusCode.NotAcceptable; mContext.Response.OutputStream.Close(); return; } } if (mContext.Request.InputStream != null) { #if CDE_NET4 || CDE_NET45 using (MemoryStream ms = new MemoryStream()) { mContext.Request.InputStream.CopyTo(ms); tRequestData.PostData = ms.ToArray(); } #else byte[] buffer = new byte[TheBaseAssets.MAX_MessageSize[0]]; using (MemoryStream ms = new MemoryStream()) { int read; while ((read = mContext.Request.InputStream.Read(buffer, 0, buffer.Length)) > 0) { ms.Write(buffer, 0, read); } tRequestData.PostData = ms.ToArray(); } #endif tRequestData.PostDataLength = tRequestData.PostData.Length; } if (TheCommCore.MyHttpService != null) { TheCommCore.MyHttpService.cdeProcessPost(tRequestData); } } catch (Exception e) { TheBaseAssets.MySYSLOG.WriteToLog(4350, TSM.L(eDEBUG_LEVELS.ESSENTIALS) ? null : new TSM("HttpMidiServer", "ProcessRequest Error:" + firstRequestLine, eMsgLevel.l1_Error, e.ToString())); tRequestData.ResponseBuffer = TheCommonUtils.CUTF8String2Array(e.ToString()); tRequestData.StatusCode = (int)eHttpStatusCode.ServerError; } if ((tRequestData.ResponseBuffer == null && tRequestData.StatusCode != 200) || tRequestData.StatusCode == 404) //NEW:UPNP { tRequestData.ResponseBufferStr = "<html><head><meta http-equiv=\"Expires\" content=\"0\" /><meta http-equiv=\"Cache-Control\" content=\"no-cache\" /><meta http-equiv=\"Pragma\" content=\"no-cache\" /></html><body style=\"background-color: " + TheBaseAssets.MyServiceHostInfo.BaseBackgroundColor + ";\"><table width=\"100%\" style=\"height:100%;\" border=\"0\" cellspacing=\"0\" cellpadding=\"0\"><tr><td style=\"text-align:center;\"><p style=\"color: " + TheBaseAssets.MyServiceHostInfo.BaseForegroundColor + "; font-family: Arial; font-size: 36px\">"; tRequestData.ResponseBufferStr += string.Format("Resource {0} not found", tRequestData.RequestUri); tRequestData.ResponseBufferStr += "</p></td></tr></table></body></HTML>"; tRequestData.ResponseMimeType = "text/html"; tRequestData.ResponseBuffer = TheCommonUtils.CUTF8String2Array(tRequestData.ResponseBufferStr); tRequestData.StatusCode = (int)eHttpStatusCode.NotFound; } try { if (tRequestData.AllowStatePush && tRequestData.ResponseBuffer != null && (tRequestData.StatusCode == (int)eHttpStatusCode.OK || tRequestData.StatusCode == (int)eHttpStatusCode.PermanentMoved)) { if (tRequestData.SessionState != null && tRequestData.SessionState.StateCookies != null && tRequestData.SessionState.StateCookies.Count > 0) { string tCookie = ""; foreach (string nam in tRequestData.SessionState.StateCookies.Keys) { try { if (tCookie.Length > 0) { tCookie += ";"; } string[] cp = tRequestData.SessionState.StateCookies[nam].Split(';'); tCookie = ""; tCookie += $"{nam}={cp[0]}; SameSite=none; Secure"; mContext.Response.Headers.Add(HttpResponseHeader.SetCookie, tCookie); } catch { //ignored } } } } else { if (!string.IsNullOrEmpty(tRequestData.cdeRealPage) && tRequestData.cdeRealPage.StartsWith("/cdeClean", StringComparison.OrdinalIgnoreCase) && tRequestData.Header != null && tRequestData.Header.ContainsKey("Cookie")) { string cookieDate = DateTime.UtcNow.AddMilliseconds(100).ToString("ddd, dd-MMM-yyyy H:mm:ss"); //Offset not needed string cookieHeader = tRequestData.Header.cdeSafeGetValue("Cookie"); if (!string.IsNullOrEmpty(cookieHeader)) { string tCookie = ""; List <string> tCookies = TheCommonUtils.CStringToList(cookieHeader, ';'); foreach (string t in tCookies) { if (tCookie.Length > 0) { tCookie += ";"; } string[] tc = t.Split('='); tCookie += string.Format("{0}=;Path=/;Expires={1} GMT", tc[0], cookieDate); } mContext.Response.Headers.Add(HttpResponseHeader.SetCookie, tCookie); } } } if (!tRequestData.DontCompress) { if (tRequestData.AllowCaching && !TheBaseAssets.MyServiceHostInfo.DisableCache) { mContext.Response.AddHeader("Cache-Control", $"max-age={TheBaseAssets.MyServiceHostInfo.CacheMaxAge}, public"); } else { mContext.Response.AddHeader("Cache-Control", "no-cache"); } mContext.Response.AddHeader("cdeDeviceID", TheBaseAssets.MyServiceHostInfo.MyDeviceInfo.DeviceID.ToString()); if (tRequestData.StatusCode > 300 && tRequestData.StatusCode < 400 && tRequestData.Header != null) { mContext.Response.AddHeader("Location", tRequestData.Header.cdeSafeGetValue("Location")); } } else { mContext.Response.Headers.Clear(); } mContext.Response.Headers.Set(HttpResponseHeader.Server, "C-DEngine V4"); if (TheBaseAssets.MyServiceHostInfo.IsSSLEnforced) { mContext.Response.Headers.Set("Strict-Transport-Security", "max-age=298000; includeSubDomains; preload"); //HSTS Header for SSL sites...test still required mContext.Response.Headers.Set("X-Frame-Options", "sameorigin"); //iFrame protection Header for SSL sites...test still required } var tCors = TheBaseAssets.MySettings.GetSetting("Access-Control-Allow-Origin"); if (!string.IsNullOrEmpty(tCors)) { mContext.Response.AppendHeader("Access-Control-Allow-Origin", tCors); } if (!string.IsNullOrEmpty(tRequestData.AllowedMethods)) { mContext.Response.AppendHeader("Access-Control-Allow-Methods", tRequestData.AllowedMethods); } if (!string.IsNullOrEmpty(tRequestData.AllowedMethods)) { mContext.Response.AppendHeader("Access-Control-Allow-Headers", tRequestData.AllowedHeaders); } mContext.Response.StatusCode = tRequestData.StatusCode; if (tRequestData.StatusCode != 200) { TheCDEKPIs.IncrementKPI(eKPINames.BruteDelay); //Security Fix: ID#770 - wait 200 ms before returning anything with error code to limit BruteForce TheCommonUtils.SleepOneEye(200, 100); } mContext.Response.ContentType = tRequestData.ResponseMimeType; if (tRequestData.ResponseBuffer != null) { if (!tRequestData.DontCompress && (TheBaseAssets.MyServiceHostInfo.IsOutputCompressed || (tRequestData.Header != null && tRequestData.Header.ContainsKey("Accept-Encoding") && tRequestData.Header["Accept-Encoding"].Contains("gzip")))) { byte[] bBuffer = TheCommonUtils.cdeCompressBuffer(tRequestData.ResponseBuffer, 0, tRequestData.ResponseBuffer.Length); mContext.Response.AddHeader("Content-Encoding", "gzip"); mContext.Response.ContentLength64 = bBuffer.Length; mContext.Response.OutputStream.Write(bBuffer, 0, bBuffer.Length); } else { if (!string.IsNullOrEmpty(tRequestData.ResponseEncoding)) { mContext.Response.AddHeader("Content-Encoding", tRequestData.ResponseEncoding); } mContext.Response.ContentLength64 = tRequestData.ResponseBuffer.Length; mContext.Response.OutputStream.Write(tRequestData.ResponseBuffer, 0, tRequestData.ResponseBuffer.Length); } } if (tRequestData.DisableChunking) { mContext.Response.SendChunked = false; } if (tRequestData.DisableKeepAlive) { mContext.Response.KeepAlive = false; } mContext.Response.OutputStream.Close(); } catch (Exception ee) { TheBaseAssets.MySYSLOG.WriteToLog(4351, TSM.L(eDEBUG_LEVELS.VERBOSE) ? null : new TSM("HttpMidiServer", "HttpWriteResponse Error", eMsgLevel.l1_Error, ee.ToString())); } }
internal void ProcessIncomingData(string pPostString, byte[] pPostData, int pPostDataLength) { if (!IsActive) { return; } if (MySessionRequestData == null || MySessionRequestData?.SessionState?.HasExpired == true) { TheBaseAssets.MySYSLOG.WriteToLog(4360, TSM.L(eDEBUG_LEVELS.ESSENTIALS) ? null : new TSM("TheWSProcessor", $"Incoming Data on expired session ({MySessionRequestData?.SessionState?.HasExpired}) detected - shutting down websockets", eMsgLevel.l6_Debug)); Shutdown(false, "1600:Incoming Data on expired session detected - shutting down websockets"); return; } TheRequestData tRequestData = TheRequestData.CloneForWS(MySessionRequestData); TheCDEKPIs.IncrementKPI(eKPINames.QSReceivedTSM); tRequestData.PostData = pPostData; tRequestData.PostDataIdx = 0; if (pPostData == null) { tRequestData.PostDataLength = 0; } else { tRequestData.PostDataLength = pPostDataLength > 0 ? pPostDataLength : pPostData.Length; TheCDEKPIs.IncrementKPI(eKPINames.QKBReceived, tRequestData.PostDataLength); } if (IsClient) { string cmdString = ""; try { List <TheDeviceMessage> tDevList; if (tRequestData.PostData == null && !string.IsNullOrEmpty(pPostString)) { if (pPostString[0] != '[') { return; } tDevList = TheDeviceMessage.DeserializeJSONToObject(pPostString); } else { if (tRequestData.PostData == null) { return; //Edge Case but could happen - all what follows required ProcessClientDeviceMsg } cmdString = tRequestData.PostData[0] == (byte)'[' ? TheCommonUtils.CArray2UTF8String(tRequestData.PostData, 0, tRequestData.PostDataLength) : TheCommonUtils.cdeDecompressToString(tRequestData.PostData, 0, tRequestData.PostDataLength); tDevList = TheDeviceMessage.DeserializeJSONToObject(cmdString); } TheCorePubSub.ProcessClientDeviceMessage(MyQSender, tRequestData, tDevList); } catch (Exception e) { TheBaseAssets.MySYSLOG.WriteToLog(4361, new TSM("WSClient", "Message-Received Processing Error", eMsgLevel.l1_Error, e.ToString())); } } else { try { if (tRequestData.PostData == null && !string.IsNullOrEmpty(pPostString)) { tRequestData.PostData = TheCommonUtils.CUTF8String2Array(pPostString); tRequestData.PostDataLength = tRequestData.PostData.Length; } if (TheCommCore.MyHttpService != null) { TheCommCore.MyHttpService.cdeProcessPost(tRequestData); } } catch (Exception e) { TheBaseAssets.MySYSLOG.WriteToLog(4362, TSM.L(eDEBUG_LEVELS.ESSENTIALS) ? null : new TSM("TheWSServer", "WebSocketServer-ProcessRequest Error", eMsgLevel.l1_Error, e.ToString())); } } if (MySessionRequestData.SessionState == null) { MySessionRequestData.SessionState = tRequestData.SessionState; } if (MySessionRequestData.DeviceID == Guid.Empty) { MySessionRequestData.DeviceID = tRequestData.DeviceID; } if (tRequestData.SessionState != null && MyQSender != null) { if (MyQSender.IsConnecting) { MyQSender.IsConnected = true; if (MyQSender.eventConnected != null) { TheCommonUtils.cdeRunAsync("QueueConnected", true, (p) => { MyQSender?.eventConnected?.Invoke(MyQSender, MyQSender.MyTargetNodeChannel); }); } MyQSender.MyISBlock?.FireEvent("Connected"); } //NEW3.124: Reset Heartbeat on Ws Post MyQSender.ResetHeartbeatTimer(false, tRequestData.SessionState); } else { TheBaseAssets.MySYSLOG.WriteToLog(4361, TSM.L(eDEBUG_LEVELS.ESSENTIALS)?null: new TSM("WSClient", $"No Request Session {tRequestData.SessionState!=null} or no QSender Found {MyQSender!=null}) IsClient={IsClient}", eMsgLevel.l2_Warning)); } try { if (tRequestData.ResponseBuffer != null) { PostToSocket(null, tRequestData.ResponseBuffer, IsClient, false); } } catch (Exception ex) // For debugging { //if (eventClosed != null) // eventClosed("Connection Error: " + ex.ToString()); Shutdown(true, "1601:PostToSocket Error: " + ex); } }
private void TheWSSenderThread() { if (IsSenderThreadRunning /*|| MyTargetNodeChannel==null*/) { return; } if (MyTargetNodeChannel == null) { TheBaseAssets.MySYSLOG.WriteToLog(2371, TSM.L(eDEBUG_LEVELS.OFF) ? null : new TSM("WSQueuedSender", $"WSSender Thread could not be started because MTNC is null", eMsgLevel.l4_Message)); return; } TheDiagnostics.SetThreadName($"QSender:{MyTargetNodeChannel} WSSenderThread", true); IsSenderThreadRunning = true; mre = new ManualResetEvent(false); CloudCounter++; StringBuilder tSendBufferStr = new StringBuilder(TheBaseAssets.MyServiceHostInfo?.IsMemoryOptimized == true ? 1024 : TheBaseAssets.MAX_MessageSize[(int)MyTargetNodeChannel.SenderType] * 2); int QDelay = TheCommonUtils.CInt(TheBaseAssets.MySettings.GetSetting("ThrottleWS")); if (QDelay < 2) { QDelay = 2; } if (MyTargetNodeChannel.SenderType == cdeSenderType.CDE_JAVAJASON && TheBaseAssets.MyServiceHostInfo.WsJsThrottle > QDelay) { QDelay = TheBaseAssets.MyServiceHostInfo.WsJsThrottle; } if (eventSenderThreadRunning != null) { TheCommonUtils.cdeRunAsync("EventSenderThreadRunning", true, (p) => { eventSenderThreadRunning(this); }); } MyISBlock?.FireEvent("SenderThreadCreated"); try { while (TheBaseAssets.MasterSwitch && IsAlive && MyWebSocketProcessor.IsActive && IsSenderThreadRunning) { while (TheBaseAssets.MasterSwitch && IsAlive && MyWebSocketProcessor.IsActive && IsSenderThreadRunning && (MyTargetNodeChannel.MySessionState == null || IsConnecting || IsInWSPost || !MyWebSocketProcessor.ProcessingAllowed || MyCoreQueue.Count == 0)) { if (IsInWSPost && MyCoreQueue.Count > 200) { TheBaseAssets.MySYSLOG.WriteToLog(235, new TSM("WSQueuedSender", $"IsInWSPost was still on and has been reset for {MyTargetNodeChannel?.ToMLString()}", eMsgLevel.l2_Warning)); IsInWSPost = false; } if (MyTargetNodeChannel.MySessionState == null && !IsConnecting && MyCoreQueue.Count > 0) { break; } mre.WaitOne(QDelay); // System.Diagnostics.Debug.WriteLine($"Waiting :{IsAlive} {MyCoreQueue.Count} {IsConnected} {IsConnecting} {IsInWSPost} {MyWebSocketProcessor.ProcessingAllowed}"); } if (!TheBaseAssets.MasterSwitch || !IsAlive || !MyWebSocketProcessor.IsActive || MyTargetNodeChannel.MySessionState == null) { TheBaseAssets.MySYSLOG.WriteToLog(235, TSM.L(eDEBUG_LEVELS.ESSENTIALS) ? null : new TSM("WSQueuedSender", $"WSSender Thread Condition failed - Ending SenderThread IsAlive:{IsAlive} MyWSProccAlive:{(MyWebSocketProcessor == null ? false : MyWebSocketProcessor.IsActive)},SessionState:{(MyTargetNodeChannel?.MySessionState != null)} IsConnecting:{IsConnecting} IsConnected:{IsConnected}", eMsgLevel.l2_Warning)); break; } IsInWSPost = true; int MCQCount = 0; int IsBatchOn = 0; int FinalCnt = 0; #if CDE_NET35 tSendBufferStr = new StringBuilder(TheBaseAssets.MAX_MessageSize[(int)MyTargetNodeChannel.SenderType] * 2); #else tSendBufferStr.Clear(); #endif tSendBufferStr.Append("["); do { TheCoreQueueContent tQueued = GetNextMessage(out MCQCount); if (tQueued != null) { TheDeviceMessage tDev = new TheDeviceMessage(); if (tQueued.OrgMessage != null) { if (tQueued.OrgMessage.ToCloudOnly() && MyTargetNodeChannel.SenderType == cdeSenderType.CDE_CLOUDROUTE) { tQueued.OrgMessage.SetToCloudOnly(false); } tQueued.OrgMessage.GetNextSerial(tQueued.SubMsgCnt); tDev.MSG = tQueued.OrgMessage; } var tCurSessState = MyTargetNodeChannel.MySessionState; if (MyTargetNodeChannel.SenderType == cdeSenderType.CDE_JAVAJASON) { if (tDev.MSG == null) { // we have a pickup: never send to browser if (IsBatchOn > 0) { continue; //ignore HB as other messages are already in the queue } else { IsInWSPost = false; continue; //dont sent empty Message to Browser - HB not necessary } } else { tDev.MSG.SEID = null; //SECURITY: Don't send SEID to Browser tDev.MSG.UID = null; //SECURITY: Don't send SEID to Browser tDev.MSG.SID = null; //SECURITY: Don't send SID to Browser } tDev.DID = MyTargetNodeChannel.cdeMID.ToString(); } else { if (tDev.MSG == null) // CODE REVIEW: DO we also need to detect other simple topics with response message and ensure they get into their own batch? { // we have a pickup (only to be sent if nothing else is being sent) if (IsBatchOn > 0) { // Ignore pickups if another message is already being sent (can happen with race condition between check before pickup enqueue and dequeue here - another TSM could be enqueue in that time) continue; } else { // Close the batch here so that no other TSM gets into the same batch // Possible optimization: check if other TSMs are available and skip the pickup here as well IsBatchOn = -1; // IsInWSPost = false; } } tDev.DID = TheBaseAssets.MyServiceHostInfo.MyDeviceInfo.DeviceID.ToString(); if (!string.IsNullOrEmpty(tQueued?.OrgMessage?.SID)) { tDev.SID = tQueued.OrgMessage.SID; } else { if (TheBaseAssets.MyServiceHostInfo.EnableFastSecurity) { tDev.SID = tCurSessState.SScopeID; //SECURITY: All tDevs will have same Session Scrambled ScopeID - 4.209: SID from TSM if set. } else { tDev.SID = TheBaseAssets.MyScopeManager.GetScrambledScopeID(tCurSessState.SScopeID, false); //GRSI: high frequency } } } TheCDEKPIs.IncrementKPI(eKPINames.QSSent); tDev.TOP = tQueued.Topic; tDev.FID = tCurSessState.GetNextSerial().ToString(); if (TheCommonUtils.IsDeviceSenderType(MyTargetNodeChannel.SenderType)) //IDST-OK: Must create RSA for Devices { TheCommonUtils.CreateRSAKeys(tCurSessState); if (TheBaseAssets.MyServiceHostInfo.SecurityLevel > 3) { tDev.RSA = tCurSessState.RSAPublic; //TODO: Make depending on switch (HighSecurity=RSAGeneration every three seconds } } if (MyTargetNodeChannel.SenderType != cdeSenderType.CDE_CLOUDROUTE) //CODE-REVIEW: 4.0113 is this still valid: Must not reset HB if talking to cloud due to Cloud-Disconnect issue { ResetHeartbeatTimer(false, tCurSessState); } if (!cdeSenderType.CDE_JAVAJASON.Equals(MyTargetNodeChannel.SenderType)) { tDev.NPA = TheBaseAssets.MyScopeManager.GetISBPath(TheBaseAssets.MyServiceHostInfo.RootDir, MyTargetNodeChannel.SenderType, TheBaseAssets.MyServiceHostInfo.MyDeviceInfo.SenderType, tCurSessState.FID, tCurSessState.cdeMID, true); } if (MyTargetNodeChannel.MySessionState == null || MyTargetNodeChannel.MySessionState.HasExpired) { throw new Exception($"Session was deleted or has expired ({MyTargetNodeChannel?.MySessionState?.HasExpired})"); } #region Batch Serialization IsBatchOn++; FinalCnt++; var tToAdd = TheCommonUtils.SerializeObjectToJSONString(tDev); if (MCQCount == 0 || tQueued.IsChunked || IsBatchOn > TheBaseAssets.MyServiceHostInfo.MaxBatchedTelegrams) { if (MCQCount != 0) { tDev.CNT = MCQCount; } IsBatchOn = 0; } else { if (tSendBufferStr.Length + tToAdd.Length > TheBaseAssets.MAX_MessageSize[(int)MyTargetNodeChannel.SenderType]) { tDev.CNT = MCQCount; IsBatchOn = 0; } } if (tSendBufferStr.Length > 1) { tSendBufferStr.Append(","); } tSendBufferStr.Append(tToAdd); #endregion } else { IsBatchOn = 0; } } while (IsBatchOn > 0 && IsInWSPost && TheBaseAssets.MasterSwitch); if (!IsInWSPost || tSendBufferStr.Length < 2) { IsInWSPost = false; continue; } tSendBufferStr.Append("]"); if (FinalCnt > 1) { TheBaseAssets.MySYSLOG.WriteToLog(235, TSM.L(eDEBUG_LEVELS.FULLVERBOSE) ? null : new TSM("WSQueuedSender", $"Batched:{FinalCnt}", eMsgLevel.l3_ImportantMessage)); } if (!cdeSenderType.CDE_JAVAJASON.Equals(MyTargetNodeChannel.SenderType)) { MyWebSocketProcessor.PostToSocket(null, TheCommonUtils.cdeCompressString(tSendBufferStr.ToString()), true, false); } else { MyWebSocketProcessor.PostToSocket(null, TheCommonUtils.CUTF8String2Array(tSendBufferStr.ToString()), false, false); } IsInWSPost = false; } TheBaseAssets.MySYSLOG.WriteToLog(235, TSM.L(eDEBUG_LEVELS.ESSENTIALS) ? null : new TSM("WSQueuedSender", $"WSQSenderThread was closed for {MyTargetNodeChannel?.ToMLString()} IsAlive:{IsAlive} MyWSProccAlive:{(MyWebSocketProcessor == null ? "Is Null" : MyWebSocketProcessor?.IsActive.ToString())},SessionState:{(MyTargetNodeChannel?.MySessionState != null)} IsConnecting:{IsConnecting} IsConnected:{IsConnected}", eMsgLevel.l1_Error)); } catch (Exception e) { TheBaseAssets.MySYSLOG.WriteToLog(235, TSM.L(eDEBUG_LEVELS.OFF) ? null : new TSM("WSQueuedSender", "Exception in WSSenderThread.", eMsgLevel.l1_Error, "Error:" + e)); } finally { IsInWSPost = false; IsSenderThreadRunning = false; StopHeartBeat(); } if (IsAlive || (MyWebSocketProcessor != null && MyWebSocketProcessor.IsActive)) { IsAlive = false; if (MyWebSocketProcessor != null) { MyWebSocketProcessor.Shutdown(true, "1310:SenderThread Closed"); } } CloudCounter--; }
internal static void DoExecuteCommand(string pInTopicBatch, TheQueuedSender pQSender, bool DoSendBackBuffer, TheRequestData pRequestData, List <TheDeviceMessage> pDevMessageList) { bool SendPulse = false; if (pDevMessageList != null && pDevMessageList.Count > 0) { foreach (TheDeviceMessage pDevMessage in pDevMessageList) { TSM recvMessage = null; string tTopic = ""; try { var tTargetNodeChannel = pQSender?.MyTargetNodeChannel; string pInTopic = pInTopicBatch; if (string.IsNullOrEmpty(pInTopic)) { pInTopic = pDevMessage.TOP; } recvMessage = pDevMessage.MSG; if (pQSender != null && tTargetNodeChannel != null && tTargetNodeChannel.SenderType == cdeSenderType.CDE_JAVAJASON && recvMessage != null && string.IsNullOrEmpty(recvMessage.ORG)) { recvMessage.ORG = tTargetNodeChannel.cdeMID.ToString(); } #region ChunkResassembly string[] CommandParts = null; if (!string.IsNullOrEmpty(pInTopic)) { CommandParts = TheCommonUtils.cdeSplit(pInTopic, ":,:", false, false); tTopic = CommandParts[0]; } TheCDEKPIs.IncrementKPI(eKPINames.CCTSMsReceived); if (CommandParts != null && CommandParts.Length == 4 && !CommandParts[2].Equals("1")) { if (!TheCommonUtils.ProcessChunkedMessage(CommandParts, recvMessage)) { SendPulse = true; continue; } } #endregion if (recvMessage != null) { if (((TheBaseAssets.MyServiceHostInfo.RejectIncomingSETP && recvMessage.TXT?.StartsWith("SETP:") == true) || TheBaseAssets.MyServiceHostInfo.DisableNMIMessages) && recvMessage.ENG?.StartsWith(eEngineName.NMIService) == true) { TheCDEKPIs.IncrementKPI(eKPINames.QSSETPRejected); continue; } var tTopicSens = tTopic.Split('@')[0]; //only topic - no ScopeID var tTopicParts = tTopic.Split(';'); if (tTargetNodeChannel.SenderType == cdeSenderType.CDE_JAVAJASON) { //4.209: JavaJason does no longer get the scope ID - hence telegrams coming from the browser have to be ammmended with SID here if (string.IsNullOrEmpty(recvMessage.SID) && !string.IsNullOrEmpty(pRequestData?.SessionState?.SScopeID)) { recvMessage.SID = pRequestData?.SessionState?.SScopeID; //Set the ScopeID in the SID of the message if (tTopic.StartsWith("CDE_SYSTEMWIDE")) { tTopic = $"{tTopicParts[0]}@{recvMessage.SID}"; if (tTopicParts.Length > 1) { tTopic += $";{tTopicParts[1]}"; //if a direct address is added use this too } } else if (!tTopic.Contains('@')) { tTopic += $"@{recvMessage.SID}"; } if (recvMessage.TXT == "CDE_SUBSCRIBE" || recvMessage.TXT == "CDE_INITIALIZE") { string MsgNoSID = null; recvMessage.PLS = TheBaseAssets.MyScopeManager.AddScopeID(recvMessage.PLS, recvMessage.SID, ref MsgNoSID, false, false); } } } if (tTopicParts.Length > 1) { tTopicSens += $";{tTopicParts[1]}"; //if a direct address is added use this too } if (TheQueuedSenderRegistry.WasTSMSeenBefore(recvMessage, pRequestData.SessionState.cdeMID, tTopicSens, tTargetNodeChannel?.RealScopeID)) //ATTENTION: RScope should come from pDevMessage { TheBaseAssets.MySYSLOG.WriteToLog(285, TSM.L(eDEBUG_LEVELS.VERBOSE) ? null : new TSM("CoreComm", $"EnterExecuteCommand: Message was seen before ORG:{TheCommonUtils.GetDeviceIDML(recvMessage?.ORG)} Topic:{tTopicSens}", eMsgLevel.l2_Warning)); //ORG-OK TheCDEKPIs.IncrementKPI(eKPINames.QSRejected); continue; } if (tTargetNodeChannel.cdeMID == Guid.Empty) { tTargetNodeChannel.cdeMID = recvMessage.GetLastRelay(); } if (tTargetNodeChannel.SenderType == cdeSenderType.NOTSET) { TheBaseAssets.MySYSLOG.WriteToLog(285, TSM.L(eDEBUG_LEVELS.ESSENTIALS) ? null : new TSM("CoreComm", "Sender Type for the QSender is not set! WE SHOULD NEVER GET HERE", eMsgLevel.l1_Error));//ORG-OK //3.218: Processing no longer allowed!!! return; } // Enable upper layers to do RSA decryption. Force overwrite for Browser even if SEID already set (may have been initialized to some other value) if (tTargetNodeChannel.SenderType == cdeSenderType.CDE_JAVAJASON || String.IsNullOrEmpty(recvMessage.SEID)) { recvMessage.SEID = pRequestData.SessionState.cdeMID.ToString(); } if (pRequestData.SessionState != null && string.IsNullOrEmpty(pRequestData.SessionState.RemoteAddress)) { pRequestData.SessionState.RemoteAddress = tTargetNodeChannel.cdeMID.ToString(); } //NEW: User ID Management in Message after first node if (string.IsNullOrEmpty(recvMessage.UID) && pRequestData.SessionState != null && pRequestData.SessionState.CID != Guid.Empty) { recvMessage.UID = TheCommonUtils.cdeEncrypt(pRequestData.SessionState.CID.ToByteArray(), TheBaseAssets.MySecrets.GetAI()); //3.083: Must be cdeAI } } } catch (Exception ee) { TheBaseAssets.MySYSLOG.WriteToLog(319, TSM.L(eDEBUG_LEVELS.OFF) ? null : new TSM("CoreComm", "Execute Command Pre-Parsing Error", eMsgLevel.l1_Error, ee.ToString())); } if (recvMessage == null) { TheBaseAssets.MySYSLOG.WriteToLog(286, TSM.L(eDEBUG_LEVELS.FULLVERBOSE) ? null : new TSM("CoreComm", $"No Message for Parsing: Topic:{tTopic} - {pRequestData.ResponseBufferStr}", eMsgLevel.l7_HostDebugMessage)); } else { if (recvMessage.PLB != null && recvMessage.PLB.Length > 0 && string.IsNullOrEmpty(recvMessage.PLS)) { try { recvMessage.PLS = TheCommonUtils.cdeDecompressToString(recvMessage.PLB); recvMessage.PLB = null; } catch (Exception) { TheBaseAssets.MySYSLOG.WriteToLog(286, TSM.L(eDEBUG_LEVELS.VERBOSE) ? null : new TSM("CoreComm", $"PLB to PLS decompress failed - Topic:{tTopic} Node:{pQSender?.MyTargetNodeChannel?.ToMLString()} ORG:{TheCommonUtils.GetDeviceIDML(recvMessage?.ORG)}", eMsgLevel.l7_HostDebugMessage, $"TXT:{recvMessage.TXT}"));//ORG-OK } } TheBaseAssets.MySYSLOG.WriteToLog(286, TSM.L(eDEBUG_LEVELS.FULLVERBOSE) ? null : new TSM("CoreComm", $"PLB to PLS parsing done - Topic:{tTopic} Node:{pQSender?.MyTargetNodeChannel?.ToMLString()} ORG:{TheCommonUtils.GetDeviceIDML(recvMessage?.ORG)}", eMsgLevel.l7_HostDebugMessage, $"TXT:{recvMessage.TXT}"));//ORG-OK if (!SendPulse) { SendPulse = recvMessage.SendPulse(); } TheCDEKPIs.IncrementKPI(eKPINames.CCTSMsEvaluated); } try { if (recvMessage != null && !string.IsNullOrEmpty(tTopic)) // tTopic != null) { if (!ParseSimplex(tTopic, recvMessage, pQSender)) //NEW:2.06 - No More Local Host processing here { if (TheBaseAssets.MyServiceHostInfo.MaximumHops == 0 || recvMessage.HobCount() < TheBaseAssets.MyServiceHostInfo.MaximumHops) { if (!tTopic.StartsWith("CDE_CONNECT") || !TheBaseAssets.MyServiceHostInfo.AllowMessagesInConnect) // Should never get here if AllowMessagesInConnect is false, but avoid global publish just in case... { TheCDEKPIs.IncrementKPI(eKPINames.CCTSMsRelayed); TheCommCore.PublishCentral(tTopic, recvMessage, false, null, false, pQSender?.MyTargetNodeChannel?.IsTrustedSender ?? false); } else { // Message is part of a CDE_CONNECT: Republish it to enable single-post message sending (i.e. MSB/Service Gateway scenario) TheCDEKPIs.IncrementKPI(eKPINames.CCTSMsRelayed); // TODO SHould we have a separate KPI for this TheCommCore.PublishCentral(recvMessage, true, pQSender.MyTargetNodeChannel.IsTrustedSender); } } } else { if (pQSender?.MyTargetNodeChannel != null && pQSender?.MyTargetNodeChannel?.SenderType != cdeSenderType.CDE_JAVAJASON) { SendPulse = true; } } } } catch (Exception ee) { TheBaseAssets.MySYSLOG.WriteToLog(319, TSM.L(eDEBUG_LEVELS.OFF) ? null : new TSM("CoreComm", "Execute Command Parsing Error", eMsgLevel.l1_Error, ee.ToString())); } TheBaseAssets.MySYSLOG.WriteToLog(286, TSM.L(eDEBUG_LEVELS.FULLVERBOSE) ? null : new TSM("CoreComm", $"Done with Do Execute Command for Topic:{tTopic}", eMsgLevel.l7_HostDebugMessage)); } } if (pRequestData.WebSocket == null) { if (DoSendBackBuffer) { SetResponseBuffer(pRequestData, pQSender.MyTargetNodeChannel, SendPulse, ""); } else if (SendPulse) { pQSender.SendPickupMessage(); //Pickup next message right away if pulse mode is on } } TheBaseAssets.MySYSLOG.WriteToLog(286, TSM.L(eDEBUG_LEVELS.FULLVERBOSE) ? null : new TSM("CoreComm", "Leave Do Execute Command", eMsgLevel.l7_HostDebugMessage)); }
public void TheRESTSenderThread() { if (IsSenderThreadRunning) { return; } try { TheDiagnostics.SetThreadName($"QSender:{MyTargetNodeChannel} SenderThread", true); MyREST = new TheREST(); IsSenderThreadRunning = true; StringBuilder tSendBufferStr = new StringBuilder(TheBaseAssets.MyServiceHostInfo?.IsMemoryOptimized == true ? 1024 : TheBaseAssets.MAX_MessageSize[(int)MyTargetNodeChannel.SenderType] * 2); TargetUri = TheCommonUtils.CUri(MyTargetNodeChannel.TargetUrl, true); TargetUriPath = TargetUri.AbsolutePath; int QDelay = TheCommonUtils.CInt(TheBaseAssets.MySettings.GetSetting("ThrottleWS")); if (QDelay < 2) { QDelay = 2; } if (MyTargetNodeChannel.SenderType == cdeSenderType.CDE_JAVAJASON && TheBaseAssets.MyServiceHostInfo.WsJsThrottle > QDelay) { QDelay = TheBaseAssets.MyServiceHostInfo.WsJsThrottle; } mre = new ManualResetEvent(false); if (eventSenderThreadRunning != null) { TheCommonUtils.cdeRunAsync("EventSenderThreadRunning", true, (p) => { eventSenderThreadRunning(this); }); } MyISBlock?.FireEvent("SenderThreadCreated"); while (TheBaseAssets.MasterSwitch && IsAlive && IsSenderThreadRunning) { if (QDelay > 2) { mre.WaitOne(QDelay); //Throtteling should be here not in the wait loop } int WaitCounter = 0; while (TheBaseAssets.MasterSwitch && IsAlive && IsSenderThreadRunning && ((MyCoreQueue.Count == 0 && IsConnected) || IsConnecting || IsInPost || MyREST.IsPosting > (IsConnected?TheBaseAssets.MyServiceHostInfo.ParallelPosts:0))) { // CODE REVIEW: This was seen looping after service route to local node was closed (due to node shutdown): IsCOnnecting/IsConnected/IsInPost were false; ISAlive true. MyREST.IsPosting was 8. Queue count ~345 // This should be fixed now with IsSenderThreadRunning in the loop (I was wrong :) this happens only with cloud connections where POST fails and the IsPosting was not reset properly). // Update: If found the same problem. Sometime IsPosting is not reduced properly when a Timeout or other error occured during Posting if (IsInPost && MyCoreQueue.Count > 100) { TheBaseAssets.MySYSLOG.WriteToLog(235, new TSM("QueuedSender", $"IsInPost was still on and has been reset for {MyTargetNodeChannel?.ToMLString()}", eMsgLevel.l2_Warning)); IsInPost = false; } if (!IsConnected) { if (IsConnecting && MyREST.IsPosting == 0) { TheBaseAssets.MySYSLOG.WriteToLog(235, new TSM("QueuedSender", $"IsConnecting is set but no Pending Post {MyTargetNodeChannel?.ToMLString()} - resetting IsConnecting", eMsgLevel.l2_Warning)); IsConnecting = false; } if (!IsConnecting && MyREST.IsPosting > (IsConnected ? 10 : 0)) { WaitCounter++; if (WaitCounter > (10000 / QDelay)) { TheBaseAssets.MySYSLOG.WriteToLog(235, new TSM("QueuedSender", $"MyREST.IsPosting ({MyREST.IsPosting}) was higher then expected...possible POST problem. Resetting POST Counter for {MyTargetNodeChannel?.ToMLString()}", eMsgLevel.l2_Warning)); MyREST.IsPosting = 0; } } } mre.WaitOne(QDelay); } if (!TheBaseAssets.MasterSwitch || !IsAlive || !IsSenderThreadRunning) { IsInPost = false; break; } IsInPost = true; if (MyTargetNodeChannel.SenderType == cdeSenderType.CDE_BACKCHANNEL || MyTargetNodeChannel.SenderType == cdeSenderType.CDE_PHONE || MyTargetNodeChannel.SenderType == cdeSenderType.CDE_DEVICE || MyTargetNodeChannel.SenderType == cdeSenderType.CDE_JAVAJASON) { TheBaseAssets.MySYSLOG.WriteToLog(235, new TSM("QueuedSender", $"QSender Should NEVER GO HERE because SenderType is {MyTargetNodeChannel?.ToMLString()}", eMsgLevel.l1_Error)); IsInPost = false; IsSenderThreadRunning = false; return; } //NEW3.124: Sender Loop has to terminate if Cloud was Disabled. if (MyTargetNodeChannel.SenderType == cdeSenderType.CDE_CLOUDROUTE && (TheBaseAssets.MyServiceHostInfo.IsCloudDisabled || string.IsNullOrEmpty(TheBaseAssets.MyServiceHostInfo.ServiceRoute) || !TheBaseAssets.MyServiceHostInfo.HasServiceRoute(TargetUri))) //ServiceRoute can contain multiple routes... { break; } TheCoreQueueContent tQueued = null; int MCQCount = 0; int IsBatchOn = 0; #if CDE_NET35 tSendBufferStr = new StringBuilder(TheBaseAssets.MAX_MessageSize[(int)MyTargetNodeChannel.SenderType] * 2); #else tSendBufferStr.Clear(); #endif tSendBufferStr.Append("["); byte[] BinSendBuffer = null; do { if (!IsConnected) { tQueued = new TheCoreQueueContent(); IsConnecting = true; ConnectRetries = 0; if (CloudInRetry) { var count = Interlocked.Increment(ref CloudRetryCount); if (count > 10) { int delaySeconds = TheBaseAssets.MyServiceHostInfo.HeartbeatDelay * TheBaseAssets.MyServiceHostInfo.TO.HeartBeatRate; TheBaseAssets.MySYSLOG.WriteToLog(235, TSM.L(eDEBUG_LEVELS.ESSENTIALS) ? null : new TSM("QueuedSender", $"Too many retries for {MyTargetNodeChannel?.ToMLString()}: {count}. Waiting {delaySeconds} seconds.", eMsgLevel.l2_Warning)); TheCommonUtils.SleepOneEye((uint)delaySeconds * 1000, 100); Interlocked.Exchange(ref CloudRetryCount, 0); } if (!TheBaseAssets.MasterSwitch || !IsAlive || !IsSenderThreadRunning || (MyTargetNodeChannel.SenderType == cdeSenderType.CDE_CLOUDROUTE && (TheBaseAssets.MyServiceHostInfo.IsCloudDisabled || string.IsNullOrEmpty(TheBaseAssets.MyServiceHostInfo.ServiceRoute) || !TheBaseAssets.MyServiceHostInfo.HasServiceRoute(TargetUri)))) { //Very rare but required after Sleep throw new Exception("QSender had to be terminated in Cloud Retry due to disabling of ServiceRoute or C-DEngine Shutdown"); } }//NEW3.124: Sender Loop has to terminate if Cloud was Disabled. if (MyTargetNodeChannel.SenderType == cdeSenderType.CDE_CLOUDROUTE && (TheBaseAssets.MyServiceHostInfo.IsCloudDisabled || string.IsNullOrEmpty(TheBaseAssets.MyServiceHostInfo.ServiceRoute) || !TheBaseAssets.MyServiceHostInfo.HasServiceRoute(TargetUri))) { break; } } else { if (CloudInRetry) { CloudInRetry = false; IsInPost = false; continue; } tQueued = GetNextMessage(out MCQCount); } if (tQueued != null) { TheCDEKPIs.IncrementKPI(eKPINames.QSSent); if (tQueued.OrgMessage == null && !IsConnecting) { if (MySubscriptions.Count == 0) { if (IsBatchOn == 0) //Only jump out if no telegrams are in batch.. { IsInPost = false; continue; } } if (IsBatchOn == 0) //If telegrams are in the batch dont send short message { BinSendBuffer = new byte[1]; BinSendBuffer[0] = (byte)((int)(TheBaseAssets.MyServiceHostInfo.MyDeviceInfo.SenderType)).ToString()[0]; break; } } if (tQueued.OrgMessage != null && tQueued.OrgMessage.ToCloudOnly() && MyTargetNodeChannel.SenderType == cdeSenderType.CDE_CLOUDROUTE) { tQueued.OrgMessage.SetToCloudOnly(false); } TheDeviceMessage tDev = new TheDeviceMessage { DID = TheBaseAssets.MyServiceHostInfo.MyDeviceInfo.DeviceID.ToString() // MyTargetNodeChannel.cdeMID.ToString(); }; if (MyTargetNodeChannel.MySessionState != null) { //BUGFIX: After fast Cloud Disconnect/reconnect-Relay lost Scopeing because it Scope was not properly stored in SessionState if (string.IsNullOrEmpty(MyTargetNodeChannel.MySessionState.SScopeID) && TheBaseAssets.MyScopeManager.IsScopingEnabled) { MyTargetNodeChannel.MySessionState.SScopeID = TheBaseAssets.MyScopeManager.GetScrambledScopeID(); //GRSI: rare } if (TheBaseAssets.MyServiceHostInfo.EnableFastSecurity) { tDev.SID = MyTargetNodeChannel.MySessionState.SScopeID; } else { tDev.SID = TheBaseAssets.MyScopeManager.GetScrambledScopeID(MyTargetNodeChannel.MySessionState.SScopeID, false); //GRSI: high frequency! } } else { tDev.SID = TheBaseAssets.MyScopeManager.GetScrambledScopeID(); //GRSI: rare } tDev.MSG = tQueued.OrgMessage; tDev.FID = "1"; if (IsConnecting) { tDev.TOP = TheCommCore.SetConnectingBufferStr(MyTargetNodeChannel, null); } else { tDev.TOP = tQueued.Topic; tQueued.OrgMessage?.GetNextSerial(tQueued.SubMsgCnt); if (MyTargetNodeChannel.MySessionState != null) { tDev.FID = MyTargetNodeChannel.MySessionState.GetNextSerial().ToString(); //(SendCounter + 1).ToString(); //V3B3: New was empty //V4.1010: Same as WS now } } #region Batch Serialization IsBatchOn++; if (MCQCount == 0 || IsBatchOn > TheBaseAssets.MyServiceHostInfo.MaxBatchedTelegrams || tQueued.IsChunked) { if (MCQCount != 0) { tDev.CNT = MCQCount; } IsBatchOn = 0; } else { if (tSendBufferStr.Length > TheBaseAssets.MAX_MessageSize[(int)MyTargetNodeChannel.SenderType]) { tDev.CNT = MCQCount; IsBatchOn = 0; } } if (tSendBufferStr.Length > 1) { tSendBufferStr.Append(","); } tSendBufferStr.Append(TheCommonUtils.SerializeObjectToJSONString(tDev)); #endregion } else { IsBatchOn = 0; } } while (IsBatchOn > 0 && IsInPost && TheBaseAssets.MasterSwitch); if ((!IsInPost || tSendBufferStr.Length < 2) && BinSendBuffer == null) { IsInPost = false; continue; } string tMimeType = "application/octet-stream"; if (BinSendBuffer == null) { tSendBufferStr.Append("]"); if (MyTargetNodeChannel.SenderType == cdeSenderType.CDE_MINI || TheBaseAssets.MyServiceHostInfo.MyDeviceInfo.SenderType == cdeSenderType.CDE_MINI) { tMimeType = "application/json"; BinSendBuffer = TheCommonUtils.CUTF8String2Array(tSendBufferStr.ToString()); } else { tMimeType = "application/x-gzip"; BinSendBuffer = TheCommonUtils.cdeCompressString(tSendBufferStr.ToString()); } } if (MyTargetNodeChannel == null) { TheBaseAssets.MySYSLOG.WriteToLog(235, TSM.L(eDEBUG_LEVELS.OFF) ? null : new TSM("QueuedSender", $"Channel was deleted - exiting SenderThread", eMsgLevel.l2_Warning)); IsInPost = false; break; } string ISBPath = new Uri(TargetUri, TheBaseAssets.MyScopeManager.GetISBPath(TargetUriPath, TheCommonUtils.GetOriginST(MyTargetNodeChannel), MyTargetNodeChannel.SenderType, MyTargetNodeChannel.MySessionState == null? 1: MyTargetNodeChannel.MySessionState.FID /*Interlocked.Increment(ref SendCounter)*/, (MyTargetNodeChannel.MySessionState == null || !IsConnected) ?Guid.Empty: MyTargetNodeChannel.MySessionState.cdeMID, MyTargetNodeChannel.IsWebSocket)).ToString(); //V3B4: changed from TheBaseAssets.MyServiceHostInfo.MyDeviceInfo TheRequestData pData = new TheRequestData { RemoteAddress = TheBaseAssets.MyServiceHostInfo.GetPrimaryStationURL(false), RequestUri = new Uri(ISBPath), PostData = BinSendBuffer, ResponseMimeType = tMimeType, DeviceID = TheBaseAssets.MyServiceHostInfo.MyDeviceInfo.DeviceID, HttpMethod = "POST" }; if (!TheCertificates.SetClientCert(pData, MyTargetNodeChannel?.ClientCertificateThumb)) { throw new Exception("Client Certificate could not be added"); } MyREST.PostRESTAsync(pData, sinkUploadDataCompleted, FireSenderProblem); if (BinSendBuffer != null) { TheCDEKPIs.IncrementKPI(eKPINames.QKBSent, BinSendBuffer.Length); } IsInPost = false; } FlushQueue(); TheBaseAssets.MySYSLOG.WriteToLog(235, TSM.L(eDEBUG_LEVELS.ESSENTIALS) ? null : new TSM("QueuedSender", $"QSenderThread was closed for {MyTargetNodeChannel?.ToMLString()}", eMsgLevel.l6_Debug)); } catch (Exception e) { IsInPost = false; TheBaseAssets.MySYSLOG.WriteToLog(235, TSM.L(eDEBUG_LEVELS.OFF) ? null : new TSM("QueuedSender", "Exception in jcSenderThread.", eMsgLevel.l1_Error, "Error:" + e)); if (MyTargetNodeChannel?.SenderType != cdeSenderType.CDE_BACKCHANNEL) { FireSenderProblem(new TheRequestData() { ErrorDescription = $"1308:{e}" }); } } finally { IsSenderThreadRunning = false; IsAlive = false; IsInPost = false; CloudInRetry = false; StopHeartBeat(); } }
internal override void PostToSocket(TheDeviceMessage pMsg, byte[] pPostBuffer, bool PostAsBinary, bool IsInitialConnect) { TheDiagnostics.SetThreadName("WSPostToSocketCSWS:" + (MyQSender.MyTargetNodeChannel?.ToString() ?? "DEAD")); if (MyQSender != null && !MyQSender.IsConnected && !IsInitialConnect) { Shutdown(true, "1653:QSenderCSWS not connected but Posting in illegal state"); return; } if (!ProcessingAllowed) //NEW:V3BETA2: New Waiting Algorythm WaitUntilProcessingAllowed(); if (!IsActive || !TheBaseAssets.MasterSwitch) return; if (websocket == null && webSocketSession==null) { eventClosed?.Invoke("1654:WebSockets are down"); return; } ProcessingAllowed = false; try { if (pPostBuffer != null) { TheCDEKPIs.IncrementKPI(eKPINames.QKBSent, pPostBuffer.Length); if (PostAsBinary) { if (webSocketSession != null) webSocketSession.SendB(pPostBuffer); else { websocket?.Send(pPostBuffer); } } else { if (webSocketSession != null) webSocketSession.SendB(TheCommonUtils.CArray2UTF8String(pPostBuffer)); else { websocket?.Send(TheCommonUtils.CArray2UTF8String(pPostBuffer)); } } } else { string toSend = TheCommonUtils.SerializeObjectToJSONString(pMsg); if (PostAsBinary) { byte[] toSendb = TheCommonUtils.CUTF8String2Array(toSend); TheCDEKPIs.IncrementKPI(eKPINames.QKBSent, toSendb.Length); if (webSocketSession != null) webSocketSession.SendB(toSendb); else { websocket?.Send(toSendb); } } else { if (webSocketSession != null) webSocketSession.SendB(toSend); else { websocket?.Send(toSend); } } } } catch (Exception e) { Shutdown(true, "1655:DoPostToSocketCSWS had a fault: "+e); } if (mre != null) ProcessingAllowed = true; }
internal override void PostToSocket(TheDeviceMessage pMsg, byte[] pPostBuffer, bool SendAsBinary, bool IsInitialConnect) { TheDiagnostics.SetThreadName("WSPostToSocket:" + ((MyQSender?.MyTargetNodeChannel != null) ? MyQSender.MyTargetNodeChannel.ToString():"DEAD")); if (MyQSender?.MyTargetNodeChannel == null) { TheBaseAssets.MySYSLOG.WriteToLog(4369, TSM.L(eDEBUG_LEVELS.ESSENTIALS) ? null : new TSM("ProcessWS", $"QSender8 not Has not QSender or TargetChannel {MyQSender}", eMsgLevel.l1_Error)); Shutdown(true, "1608:WS8 has not QSender but is Posting - illegal state"); return; } if (MyQSender != null && !MyQSender.IsConnected && !IsInitialConnect) { TheBaseAssets.MySYSLOG.WriteToLog(4369, TSM.L(eDEBUG_LEVELS.ESSENTIALS) ? null : new TSM("ProcessWS", "QSender8 not connected but Posting - illegal state", eMsgLevel.l1_Error)); Shutdown(true, "1609:QSender8 not connected but Posting - illegal state"); return; } bool HasFaulted = false; lock (_postToSocketLock) // The lock needs to be at the websocket level: assumption is that there is at most one WSProcessor per socket! { if (!IsActive || !TheBaseAssets.MasterSwitch) { return; } ProcessingAllowed = false; string errorMsg = ""; try { if (!IsSocketReady(websocket)) { HasFaulted = true; errorMsg = "Socket Not Ready"; } else { // TODO MH - Move this outside of the lock so we can minimize the lock time? Or are there ordering constraints on the serialization for some reason? ArraySegment <byte> outputBuffer; if (pPostBuffer != null) { TheCDEKPIs.IncrementKPI(eKPINames.QKBSent, pPostBuffer.Length); outputBuffer = new ArraySegment <byte>(pPostBuffer); } else { string tStr = TheCommonUtils.SerializeObjectToJSONString(pMsg); TheCDEKPIs.IncrementKPI(eKPINames.QKBSent, tStr.Length); outputBuffer = new ArraySegment <byte>(Encoding.UTF8.GetBytes(tStr)); } //LogBufferToFile("wsoutputputlog", outputBuffer.Array, outputBuffer.Offset, outputBuffer.Count); Task tTask = websocket.SendAsync(outputBuffer, SendAsBinary ? WebSocketMessageType.Binary : WebSocketMessageType.Text, true, TheBaseAssets.MasterSwitchCancelationToken); tTask.Wait(TheBaseAssets.MyServiceHostInfo.TO.WsTimeOut * 10); if (!tTask.IsCompleted) { var timeoutValue = TheBaseAssets.MyServiceHostInfo.TO.WsTimeOut * 10; TheBaseAssets.MySYSLOG.WriteToLog(43610, new TSM("TheWSProcessor", $"WebSocketServer-PostToSocket error: PostAsync Timeout {tTask.Status} after {timeoutValue} ms for {MyQSender?.MyTargetNodeChannel}", eMsgLevel.l1_Error)); errorMsg = $"SendAsync timed out after {timeoutValue} ms"; HasFaulted = true; } } } catch (Exception e) { TheBaseAssets.MySYSLOG.WriteToLog(43610, TSM.L(eDEBUG_LEVELS.ESSENTIALS) ? null : new TSM("TheWSProcessor", "WebSocketServer-PostToSocket Error:", eMsgLevel.l1_Error, ((int)TheBaseAssets.MyServiceHostInfo.DebugLevel > 1? e.ToString():e.Message))); errorMsg = $"PostToSocket failed: {e.Message}"; HasFaulted = true; } if (HasFaulted) { Shutdown(true, $"1610:{errorMsg}"); } //IsPosting = false; if (mre != null) { ProcessingAllowed = true; } } }