public string ShowHeader() { string AllTopics = ""; foreach (var t in MySubscriptions.TheValues) { if (t == null) { continue; } string tColor = "black"; string tVer = ""; if (TheBaseAssets.MyServiceHostInfo.IsCloudService) { var tS = MyNodeInfo?.MyServices?.FirstOrDefault(s => s?.ClassName == t.Topic); if (tS != null) { tVer = $" V{tS.Version}"; if (tS.IsMiniRelay) { tColor = "purple"; } } } if (!t.ToServiceOnly) { tColor = "lightgray"; } string tt = $"<li style='color:{tColor}'>{t.Topic}{tVer}"; if (!string.IsNullOrEmpty(t.RScopeID)) { string tScop = t.RScopeID; if (tScop.Length < 4) { tt += $" <span style='color:red'>ILLEGAL-Scope: {tScop.ToUpper()}</span>"; } else { tt += $" {cdeStatus.GetScopeHashML(tScop.Substring(0, 4).ToUpper())}"; } } int tMinAlive = TheCommonUtils.CInt((DateTimeOffset.Now - t.cdeCTIM).TotalMinutes); tt += $" ({Math.Round(t.Hits>0 && tMinAlive>0?t.Hits/tMinAlive:0.0,2)} , {t.Hits})</li>"; AllTopics += tt; } return($"<li {(!IsTrusted? "style='color:red'" : "")}>{MyTargetNodeChannel.ToMLString()} ({GetNodeName()}) {(MyNodeInfo?.MyServiceInfo?.ClientCertificateThumb?.Length > 3 ? MyNodeInfo?.MyServiceInfo?.ClientCertificateThumb?.Substring(0, 4) : "No cert")}<ul>{AllTopics}</ul></li>"); }
internal void ResetHeartbeatTimer(bool IsChangeRequest, TheSessionState pSession) { InitHeartbeatTimer(); if (MyTargetNodeChannel == null || MyTargetNodeChannel.SenderType == cdeSenderType.CDE_LOCALHOST) { return; } TheBaseAssets.MySession.WriteSession(pSession); if (string.IsNullOrEmpty(MyTargetNodeChannel.RealScopeID) && !string.IsNullOrEmpty(pSession.SScopeID) && MyISBlock == null) //RScope-OK: This should be super rare that a channel has no RScope but the SessionState has a Scope { UpdateSubscriptionScope(TheBaseAssets.MyScopeManager.GetRealScopeID(pSession.SScopeID)); //GRSI: rare } if (IsChangeRequest) { TheBaseAssets.MySYSLOG.WriteToLog(247, TSM.L(eDEBUG_LEVELS.FULLVERBOSE) ? null : new TSM("QueuedSender", $"{TheBaseAssets.MyServiceHostInfo.GetPrimaryStationURL(false)} received Heartbeat Change Request for {MyTargetNodeChannel.ToMLString()}", eMsgLevel.l6_Debug), true); } else { TheBaseAssets.MySYSLOG.WriteToLog(247, TSM.L(eDEBUG_LEVELS.FULLVERBOSE) ? null : new TSM("QueuedSender", $"{TheBaseAssets.MyServiceHostInfo.GetPrimaryStationURL(false)} received and reset Heartbeat for {MyTargetNodeChannel.ToMLString()}", eMsgLevel.l6_Debug), true); } }
internal void timerMyHeartbeatTimer() { if (mInHeartBeatTimer) { // This should never happen: we are running this under a lock TheBaseAssets.MySYSLOG.WriteToLog(248, TSM.L(eDEBUG_LEVELS.OFF) ? null : new TSM("QueuedSender", $"QSender {MyTargetNodeChannel?.ToMLString()}: Internal error (timer reentered)", eMsgLevel.l2_Warning), true); return; } if (!TheBaseAssets.MasterSwitch || !IsQSenderReadyForHB || IsInWSPost || IsInPost || MyREST?.IsPosting > 0) { TheBaseAssets.MySYSLOG.WriteToLog(248, TSM.L(eDEBUG_LEVELS.VERBOSE) ? null : new TSM("QueuedSender", $"QSender {MyTargetNodeChannel?.ToMLString()} suspended due to: MS:{TheBaseAssets.MasterSwitch} IA:{IsAlive} ISSRFHB:{IsQSenderReadyForHB} INWSP:{IsInWSPost} INP:{IsInPost} RPCNT:{MyREST?.IsPosting}", eMsgLevel.l6_Debug), true); return; //New in 4.205: HB is not checked if QSender is in post (for example during a large telegram going to a browser) } if (MyTargetNodeChannel.IsWebSocket && !IsConnecting) { if (!TheCommonUtils.IsDeviceSenderType(MyTargetNodeChannel.SenderType)) //IDST-OK: Only update session state for none-devices { TheBaseAssets.MySession.WriteSession(MyTargetNodeChannel.MySessionState); } } mInHeartBeatTimer = true; try { if (!IsConnecting && !IsConnected) { TheBaseAssets.MySYSLOG.WriteToLog(248, TSM.L(eDEBUG_LEVELS.ESSENTIALS) ? null : new TSM("QueuedSender", $"QSender {MyTargetNodeChannel?.ToMLString()} in illegal state (not connected AND not connecting) for Heartbeat!", eMsgLevel.l2_Warning), false); FireSenderProblem(new TheRequestData() { ErrorDescription = "1304:Heartbeat found !Connected and !IsConnecting" }); return; } if (!IsConnected && IsConnecting) { ConnectRetries++; if (ConnectRetries > TheBaseAssets.MyServiceHostInfo.TO.HeartBeatMissed) { TSM tMsg = new TSM("QueuedSender", $"Initial Connection failed. {MyTargetNodeChannel?.ToMLString()} might be down!", eMsgLevel.l2_Warning); HeartBeatCnt = 0; //FlushQueue(); tMsg.ORG = MyTargetNodeChannel.cdeMID.ToString(); TheBaseAssets.MySYSLOG.WriteToLog(248, tMsg, true); FireSenderProblem(new TheRequestData() { ErrorDescription = $"1305:Connecting failed for {ConnectRetries} retries" }); ConnectRetries = 0; IsConnecting = false; } } else { if (IsConnecting) { TheBaseAssets.MySYSLOG.WriteToLog(248, TSM.L(eDEBUG_LEVELS.ESSENTIALS) ? null : new TSM("QueuedSender", $"QSender {MyTargetNodeChannel?.ToMLString()} in illegal state (Connected AND Connecting) for Heartbeat!", eMsgLevel.l2_Warning), false); return; } TheBaseAssets.MySYSLOG.WriteToLog(248, TSM.L(eDEBUG_LEVELS.FULLVERBOSE) ? null : new TSM("QueuedSender", "Enter HeartBeatTick for " + MyTargetNodeChannel, eMsgLevel.l6_Debug), true); int Misses = TheBaseAssets.MyServiceHostInfo.TO.OnAdrenalin ? 2 : 1; if (HeartBeatCnt > TheBaseAssets.MyServiceHostInfo.TO.HeartBeatMissed * Misses) { TSM tMsg = new TSM("QueuedSender", $"Too Many Heartbeats ({HeartBeatCnt}) missed - {MyTargetNodeChannel?.ToMLString()} might be down!", eMsgLevel.l2_Warning); HeartBeatCnt = 0; tMsg.ORG = MyTargetNodeChannel.cdeMID.ToString(); TheBaseAssets.MySYSLOG.WriteToLog(248, tMsg, true); FireSenderProblem(new TheRequestData() { ErrorDescription = "1306:Heartbeat failure!!" }); } else { if (HeartBeatCnt > TheBaseAssets.MyServiceHostInfo.TO.HeartBeatWarning) { TSM tMsg = new TSM("QueuedSender", $"More than {TheBaseAssets.MyServiceHostInfo.TO.HeartBeatWarning} ({HeartBeatCnt}) Heartbeats from {MyTargetNodeChannel?.ToMLString()} missed", eMsgLevel.l2_Warning) { ORG = MyTargetNodeChannel.cdeMID.ToString() }; TheBaseAssets.MySYSLOG.WriteToLog(248, tMsg, true); } if (MyTargetNodeChannel != null) // && MyTargetNodeChannel.References > 0) legacy { SendPickupMessage(); } HeartBeatCnt++; } } } catch (Exception e) { TheBaseAssets.MySYSLOG.WriteToLog(248, new TSM("QueuedSender", $"Exception in Healthtimer for {MyTargetNodeChannel?.ToMLString()}", eMsgLevel.l1_Error, e.ToString()), true); } finally { TheBaseAssets.MySYSLOG.WriteToLog(248, TSM.L(eDEBUG_LEVELS.FULLVERBOSE) ? null : new TSM("QueuedSender", $"Leave HeartBeatTick for {MyTargetNodeChannel?.ToMLString()}", eMsgLevel.l6_Debug), false); mInHeartBeatTimer = false; } }
private void sinkHeartBeatTimer(long NOTUSED) { try { TheDiagnostics.SetThreadName("HeartbeatTimer", true); mHeartBeatTicker++; TheBaseAssets.MySYSLOG.WriteToLog(2803, TSM.L(eDEBUG_LEVELS.EVERYTHING) ? null : new TSM("QSender", $"Enter HearbeatTimer for ORG:{MyTargetNodeChannel}", eMsgLevel.l7_HostDebugMessage)); TheTimeouts tTO = TheBaseAssets.MyServiceHostInfo.TO; if (!IsHeartBeatAlive(tTO.DeviceCleanSweepTimeout * 2) && TheCommonUtils.IsDeviceSenderType(MyTargetNodeChannel?.SenderType ?? cdeSenderType.NOTSET) && MyTargetNodeChannel?.IsWebSocket == false) //IDST-OK: Remove dead devices that might have hard disconnected (no correct disconnect) i.e. http browsers were just closed { TheBaseAssets.MySYSLOG.WriteToLog(2820, TSM.L(eDEBUG_LEVELS.OFF) ? null : new TSM("QSender", $"Forced Removal of QSender {MyTargetNodeChannel.ToMLString()} due to DeviceCleanSweep", eMsgLevel.l4_Message)); Guid?tTarget = MyTargetNodeChannel?.cdeMID; DisposeSender(true); if (tTarget.HasValue) { TheQueuedSenderRegistry.RemoveOrphan(tTarget.Value); TheCommCore.PublishCentral(new TSM(eEngineName.ContentService, "CDE_DELETEORPHAN", tTarget.ToString())); } return; } if (!IsAlive && !MyTargetNodeChannel?.IsWebSocket == true) { return; //NEW:V3 2013/12/13 allow for cloud reconnect if WebSockets } if ((mHeartBeatTicker % (tTO.HeartBeatRate * 2)) == 0) { if (MyTargetNodeChannel?.SenderType != cdeSenderType.CDE_LOCALHOST) { timerMyHeartbeatTimer(); } if (MyTargetNodeChannel?.SenderType == cdeSenderType.CDE_CLOUDROUTE && ((!IsConnected && !IsConnecting) || !IsAlive) && (mHeartBeatTicker % (tTO.HeartBeatRate * 10)) == 0) //tQ.MyTargetNodeChannel.IsWebSocket && NOW ALWAYS RECONNECT { TheCommonUtils.cdeRunAsync("ReconnectCloud", true, (o) => ReconnectCloud()); } if (MyTargetNodeChannel?.SenderType != cdeSenderType.CDE_LOCALHOST && IsAlive && IsConnected) //!TheBaseAssets.MyServiceHostInfo.IsCloudService && !tQ.MyTargetNodeChannel.IsWebSocket && { if (MyTargetNodeChannel?.IsWebSocket != true) { if (GetQueLength() == 0) { TheBaseAssets.MyServiceHostInfo.TO.MakeHeartPump(); // CODE REVIEW Markus: Isn't this backwards: we should pump faster while we have more work to do? SendPickupMessage(); //Pickup } else { TheBaseAssets.MyServiceHostInfo.TO.MakeHeartNormal(); } } else { SendPickupMessage(); //Pickup } } } } catch (Exception e) { TheBaseAssets.MySYSLOG.WriteToLog(2821, new TSM("QSRegistry", $"Fatal Error in HealthTimer for QS:{this.cdeMID} and MTNC:{MyTargetNodeChannel?.ToMLString()}", eMsgLevel.l1_Error, e.ToString())); } }
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 void SetWebSocketProcessor(object pSocket) { TheBaseAssets.MySYSLOG.WriteToLog(2370, TSM.L(eDEBUG_LEVELS.ESSENTIALS) ? null : new TSM("WSQueuedSender", $"Setting WebSocketProcessor HasPSocket:{pSocket != null}", eMsgLevel.l4_Message)); if (pSocket == null) { return; } if (MyTargetNodeChannel != null && MyREST == null) { MyTargetNodeChannel.IsWebSocket = true; if (string.IsNullOrEmpty(MyTargetNodeChannel.TargetUrl) || MyTargetNodeChannel.TargetUrl.StartsWith("/")) { MyTargetNodeChannel.TargetUrl = "WS://" + MyTargetNodeChannel.cdeMID; } } if (MyWebSocketProcessor == null && MyREST == null) { MyWebSocketProcessor = pSocket as TheWSProcessorBase; if (MyWebSocketProcessor != null) { MyWebSocketProcessor.eventClosed = null; MyWebSocketProcessor.eventClosed += DoFireSenderProblem; MyWebSocketProcessor.MyQSender = this; } } if (MyWebSocketProcessor != null && MyTargetNodeChannel != null) { MyWebSocketProcessor.OwnerNodeID = MyTargetNodeChannel.cdeMID; if (MyTargetNodeChannel.SenderType == cdeSenderType.CDE_BACKCHANNEL) { //if this is a backchannel the connection was established by the incoming node and the QS is already connected IsConnected = true; IsConnecting = false; } else { IsConnected = false; IsConnecting = true; } if (!IsSenderThreadRunning) { TheBaseAssets.MySYSLOG.WriteToLog(2371, TSM.L(eDEBUG_LEVELS.ESSENTIALS) ? null : new TSM("WSQueuedSender", $"Starting new WSSender Thread IsAlive:{IsAlive}", eMsgLevel.l4_Message)); MyWebSocketProcessor.IsActive = true; TheCommonUtils.cdeRunTaskAsync($"WSQSender for ORG:{MyTargetNodeChannel}", o => { if (IsSenderThreadRunning) { return; //In Case the Thread took longer to create and another one was successful in the meantime } TheWSSenderThread(); TheBaseAssets.MySYSLOG.WriteToLog(2372, TSM.L(eDEBUG_LEVELS.ESSENTIALS) ? null : new TSM("WSQueuedSender", $"WSQSenderThread was closed (In RunAync) for {MyTargetNodeChannel?.ToMLString()}", eMsgLevel.l1_Error)); if (IsAlive) { TheBaseAssets.MySYSLOG.WriteToLog(236, new TSM("WSQueuedSender", $"WSQSender Thread {MyTargetNodeChannel?.ToMLString()} died", eMsgLevel.l1_Error)); FireSenderProblem(new TheRequestData() { ErrorDescription = $"1309:WSQSender Thread {MyTargetNodeChannel?.ToMLString()} died" }); IsAlive = false; IsInWSPost = false; } }, null, true); } } }
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 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(); } }
/// <summary> /// Returns true if new subscriptions were added /// </summary> /// <param name="pScopedTopics"></param> /// <param name="OwnedSubs"></param> /// <returns></returns> internal bool Subscribe(string pScopedTopics, bool OwnedSubs = false) { int len = MySubscriptions.Count; CombineSubscriptions(pScopedTopics, out bool WasUpdated, OwnedSubs); if (WasUpdated) //len != MySubscriptions.Count || { TheBaseAssets.MySYSLOG.WriteToLog(296, TSM.L(eDEBUG_LEVELS.ESSENTIALS) ? null : new TSM("QueuedSender", $"New # of Subscriptions {MySubscriptions?.Count} - Previously {len} for {MyTargetNodeChannel?.ToMLString()}", eMsgLevel.l4_Message)); return(true); } return(false); }
private void ReduceSubscriptions(string pTopics) { if (string.IsNullOrEmpty(pTopics)) { return; } TheBaseAssets.MySYSLOG.WriteToLog(296, TSM.L(eDEBUG_LEVELS.ESSENTIALS) ? null : new TSM("QueuedSender", $"Unsubscribe request of Topics={pTopics} from {MyTargetNodeChannel?.ToMLString()}", eMsgLevel.l4_Message)); lock (CombineSubscriptionLock) { string[] subs = pTopics.Split(';'); for (int i = 0; i < subs.Length; i++) { string tRealScope = TheBaseAssets.MyScopeManager.GetRealScopeIDFromTopic(subs[i], out string tTopicName); //Low Frequency if (string.IsNullOrEmpty(tTopicName)) { continue; } foreach (string t in MySubscriptions.TheKeys) { if (!string.IsNullOrEmpty(tRealScope)) { if (tRealScope.Equals(MySubscriptions.MyRecords[t]?.RScopeID) && tTopicName.Equals(MySubscriptions.MyRecords[t]?.Topic)) { MySubscriptions.RemoveAnItemByKey(t, null); break; } } else { if (subs[i].Equals(t)) { MySubscriptions.RemoveAnItemByKey(t, null); break; } } } } } }