using System; using System.Collections.Generic; using System.Text; using System.Threading; using DTS.Common.Utilities.Logging; namespace DTS.DASLib.Command.TDAS { public class CommandBase : AbstractCommandBase { private static TextLogger _logger; public static void RollLog() { if (null != _logger) { _logger.ReRollLog = true; } } // ReSharper disable once InconsistentNaming protected string _responseData; public string ResponseData { get { if (null != _responseData) return _responseData; try { ProcessData(); } catch (Exception ex) { APILogger.Log("error: ", ex); throw; } return _responseData; } } private bool _SingleModuleCommand = false; public bool SingleModuleCommand { get { return _SingleModuleCommand; } set { _SingleModuleCommand = value; } } private string _RackSerialNumber = "NONE"; public string RackSerialNumber { get { return _RackSerialNumber; } set { _RackSerialNumber = value; } } public bool IsErrored() { if (null == _responseData) { ProcessData(); } if (_responseData.ToLower().StartsWith("err")) { return true; } return false; } public string GetErrorString() { if (null == _responseData) { ProcessData(); } // ReSharper disable once StringIndexOfIsCultureSpecific.1 var index = ResponseData.IndexOf("ERR"); if (index < 0) return ""; var s = ResponseData.Substring(index + 4, ResponseData.Length - 4 - index); return s; } protected override CommandPacketBase GetCommandPacket(byte[] buffer) { if (HasStatusPacket(buffer)) { buffer = StripTDASResponseHeader(buffer); } return new TDASCommandPacketBase(buffer, baseCommand); } /// /// returns true if there's a status packet present /// private bool HasStatusPacket(byte[] buffer) { //status packet is 20 bytes long, ends with 4 bytes of FF //this appears to be because the field is unused, but even if we falsely say it doesn't //have a status packet, it just means the response will look uglier than it should //which, is the old behavior at time of change if (buffer.Length <= 20) { return false; } return buffer[19] == byte.MaxValue && buffer[18] == byte.MaxValue && buffer[17] == byte.MaxValue && buffer[16] == byte.MaxValue; } private const int TDAS_STATUS_PACKET_LENGTH = 20; /// /// there's two packets sent by TDAS for a response, first is status, second is actual /// data, we want to remove the status packet for now, possibly decide what to do with it /// in the future /// /// /// private byte[] StripTDASResponseHeader(byte[] packets) { //the check that this has a status packet was done before this (HasStatusPacket) //ordinarily we have 20 bytes, I'm assuming MAX_MODULES is a constant (8) //also note that the structure as defined below looks like it should be 24 bytes //but my captures show 20 bytes ... maybe the int is a short, or the long isn't 8, I don't know //luckily we don't need the packet currently, we are just getting rid of it from our stream //example //char peer1_0[] = { /* Packet 9 */ // 0x01, 0x01, 0x00, 0x00, 0x00, 0x00, 0x03, 0xee, // 0x00, 0x00, 0x00, 0x0c, 0x00, 0xff, 0xff, 0xff, // 0xff, 0xff, 0xff, 0xff }; //17715 Process Status Packet from TDAS, remove from logging var newBuffer = new byte[packets.Length - TDAS_STATUS_PACKET_LENGTH]; Buffer.BlockCopy(packets, TDAS_STATUS_PACKET_LENGTH, newBuffer, 0, newBuffer.Length); return newBuffer; //here's the structure, we may use it in the future ... //BYTE CDBId; // status for which CDB //BYTE CDBCmdId; // status for which command string //BYTE errStatus; // IPEngine server status //BYTE reserved; //int rackID; // connection ID index //unsigned long dataSize; // incomming bulk transfer size + EOT //BYTE modStatus[MAX_MODULES]; // transaction status for each module //// 0 IO_SUCCESS //// 1 IO_NO_CMD //// < 0 error (see ioObj.h) } protected override CommandPacketBase GetCommandPacket() { return baseCommand; } public CommandBase(DTS.Common.Interface.DASFactory.ICommunication sock) : base(sock, 30000) { } public CommandBase(DTS.Common.Interface.DASFactory.ICommunication sock, int timeoutMillisec) : base(sock, timeoutMillisec) { } protected virtual void ProcessData() { if (!(baseResponse is TDASCommandPacketBase response)) { return; } var s = Encoding.ASCII.GetString(response.ToBytes()); var command = baseCommand as TDASCommandPacketBase; var start = s.IndexOf(command.GetCommandString(0)); var end = s.LastIndexOf("\r\n"); if (start < end && start >= 0) { //System.Diagnostics.Debug.Assert(start >= 0 && end > start); var csLength = command.GetCommandString(0).Length + 1; _responseData = s.Substring(start + csLength, end - start - csLength).TrimStart(); if (IsErrored()) { //APILogger.Log(_responseData); throw new InvalidOperationException(_responseData); } } else { _responseData = ""; } } public override void CommandToString(ref List> lines) { base.CommandToString(ref lines); lines[0].Add(recorder.SerialNumber); var command = baseCommand as TDASCommandPacketBase; lines.Add(new List { command.ToCommandString() }); } public override void ResponseToString(ref List> lines) { base.ResponseToString(ref lines); lines[0].Add(recorder.SerialNumber); if (null != ResponseData) { lines.Add(new List { ResponseData }); } } /// /// 10843 TDAS communication needs to be throttled /// this initializes the throttling of TDAS devices /// /// /// public static void InitializeSemaphore(double delay, int spots) { _semaphoreDelay = delay; if (null != _pool) { _pool.Dispose(); } _pool = new SemaphoreSlim(spots, spots); } public override void SyncExecute() { _pool.Wait(); try { var start = DateTime.Now; base.SyncExecute(); if (null != ResponseData) { ProcessData(); } var elapsed = DateTime.Now.Subtract(start); if (elapsed.TotalMilliseconds < _semaphoreDelay) { Thread.Sleep(Convert.ToInt32(_semaphoreDelay - elapsed.TotalMilliseconds)); } } finally { _pool.Release(); } } /// /// 10843 TDAS communication needs to be throttled /// this is normally initialized by the application, so this constructor for the case of the application /// not initializing /// private static SemaphoreSlim _pool = new SemaphoreSlim(3, 3); private static double _semaphoreDelay = 100; protected override void LogCommand(bool sending) { base.LogCommand(sending); try { if (null == _logger) { _logger = new TextLogger("logs\\TDAScomm.log", WriteCycleExceptionHandler); } if (sending) { if (GetCommandPacket() is TDASCommandPacketBase pBase) { Log(pBase.ToCommandString()); } } else { if (LogCommands) { if (null == baseResponse) return; var s = Encoding.ASCII.GetString(baseResponse.ToBytes()); var lastEndString = s.LastIndexOf('\0'); //trim random garbage before our payload if (lastEndString > 0) { s = s.Substring(lastEndString + 1); } //trim random ? garbage at the start of the payload while (s.StartsWith("?")) { s = s.Substring(1); } Log(s); } } } catch (Exception) { } } private void Log(string message) { if (null == _logger) { return; } try { var dt = DateTime.Now; var commandSequenceNumber = GetCommandPacket().SequenceNumber; //17686 add additional debug information into log if (null != baseResponse) { _logger.LogMessage( $"{dt.Year:0000}-{dt.Month:00}-{dt.Day:00} {dt.Hour:00}:{dt.Minute:00}:{dt.Second:00}.{dt.Millisecond} ({recorder.ConnectString}) [{commandSequenceNumber}]\\[{baseResponse.SequenceNumber}] {message}\r\n"); } else { _logger.LogMessage( $"{dt.Year:0000}-{dt.Month:00}-{dt.Day:00} {dt.Hour:00}:{dt.Minute:00}:{dt.Second:00}.{dt.Millisecond} ({recorder.ConnectString}) [{commandSequenceNumber}] {message}\r\n"); } } catch (Exception) { } } private static void WriteCycleExceptionHandler(Exception ex) { try { APILogger.Log("exception writing to Hearbeat log", ex); } catch (Exception) { } } } }