public virtual void OnLogout(QuickFix.SessionID session)
{
try
{
logger.Info("OnLogout()");
string msg = String.Format("Logout da sessao: {0}-{1}-{2}-{3}", session.SenderCompID,
session.SenderSubID,
session.TargetCompID,
session.TargetSubID);
if (DateTime.Now.DayOfWeek != DayOfWeek.Sunday && DateTime.Now.DayOfWeek != DayOfWeek.Saturday)
{
if (DateTime.Now.Hour >= ConstantesMDS.HORARIO_NOTIFICACAO_EMAIL_INICIO &&
DateTime.Now.Hour < ConstantesMDS.HORARIO_NOTIFICACAO_EMAIL_FIM)
{
MDSUtils.EnviarEmail("FIX Logout", msg);
}
}
}
catch (Exception ex)
{
logger.Error("OnLogout(): " + ex.Message, ex);
}
_bConectadoBolsa = false;
}
private void monitoraCanal()
{
logger.Info("Iniciando monitoracao do canal incremental [" + channelConfig.ChannelID + "]");
long lastWatchDog = DateTime.UtcNow.Ticks;
while (isRunning)
{
try
{
if (mktIncrProc != null && !mktIncrProc.IsAlive() && shouldMonitor)
{
string subject = "REINICIANDO CANAL [" + channelConfig.ChannelID + "]";
string msg = subject + "\r\n" + "reiniciando as " + DateTime.Now.ToString("dd/MM/yyyy HH:mm:ss.fff");
logger.Warn(subject);
if (DateTime.Now.DayOfWeek != DayOfWeek.Sunday && DateTime.Now.DayOfWeek != DayOfWeek.Saturday)
{
if (DateTime.Now.Hour >= ConstantesMDS.HORARIO_NOTIFICACAO_EMAIL_INICIO &&
DateTime.Now.Hour < ConstantesMDS.HORARIO_NOTIFICACAO_EMAIL_FIM)
{
MDSUtils.EnviarEmail(subject, msg);
}
}
finalizaCanal();
Thread.Sleep(10000);
iniciaCanal();
Thread.Sleep(10000);
}
else
{
TimeSpan ts = new TimeSpan(DateTime.UtcNow.Ticks - lastWatchDog);
if (ts.TotalMilliseconds > 30000)
{
logger.Info("Canal [" + channelConfig.ChannelID + "] ativo");
lastWatchDog = DateTime.UtcNow.Ticks;
}
}
}
catch (Exception ex)
{
logger.Error("monitoraCanal(): " + ex.Message, ex);
}
Thread.Sleep(250);
}
}
public virtual void OnMessage(QuickFix.FIX44.ApplicationMessageReport message, SessionID session)
{
try
{
logger.Info("*** Relatorio de Retransmissao");
logger.Info("ApplReportID.....: " + message.GetString(QuickFix.Fields.Tags.ApplReportID));
logger.Info("ApplReportType...: " + message.GetString(QuickFix.Fields.Tags.ApplReportType));
int applReportType = Convert.ToInt32(message.ApplReportType.ToString());
string lastSeqNum = "";
if (message.IsSetField(QuickFix.Fields.Tags.NoApplIDs))
{
int numApplIDs = message.GetInt(QuickFix.Fields.Tags.NoApplIDs);
logger.Info("ApplIDs..........: " + numApplIDs);
for (int numApplID = 1; numApplID <= numApplIDs; numApplID++)
{
QuickFix.FIX44.ApplicationMessageReport.NoApplIDsGroup groupApplID = new QuickFix.FIX44.ApplicationMessageReport.NoApplIDsGroup();
message.GetGroup(numApplID, groupApplID);
logger.Info("RefApplID[" + numApplID + "].....:" + groupApplID.GetString(QuickFix.Fields.Tags.RefApplID));
if (groupApplID.IsSetField(QuickFix.Fields.Tags.RefApplLastSeqNum))
{
lastSeqNum = groupApplID.GetString(QuickFix.Fields.Tags.RefApplLastSeqNum);
logger.Info("RefApplLastSeqNum[" + numApplID + "].:" + lastSeqNum);
}
if (groupApplID.IsSetField(QuickFix.Fields.Tags.ApplRespError))
{
logger.Info("ApplResponseError[" + numApplID + "].:" + groupApplID.GetString(QuickFix.Fields.Tags.ApplRespError));
}
}
}
string[] quebraApplReqID = message.GetString(QuickFix.Fields.Tags.ApplReqID).Split("-".ToCharArray());
string channelID = quebraApplReqID[1];
if (applReportType == 3)
{
logger.Info("Libera ChannelID: [" + channelID + "]");
lock (listaChannelQueues[channelID].replayLockObject)
{
Monitor.Pulse(listaChannelQueues[channelID].replayLockObject);
}
}
else
{
logger.Warn("Application Resend Error, nao libera channelID [" + channelID + "] devera reiniciar por timeout");
if (DateTime.Now.DayOfWeek != DayOfWeek.Sunday && DateTime.Now.DayOfWeek != DayOfWeek.Saturday)
{
if (DateTime.Now.Hour >= ConstantesMDS.HORARIO_NOTIFICACAO_EMAIL_INICIO &&
DateTime.Now.Hour < ConstantesMDS.HORARIO_NOTIFICACAO_EMAIL_FIM)
{
MDSUtils.EnviarEmail("Erro em recovery [" + channelID + "]", "Application Resend Error, nao libera channelID [" + channelID + "] devera reiniciar por timeout");
}
}
}
logger.Info("Final da Retransmissao ***");
}
catch (Exception ex)
{
logger.Error("onMessage(ApplicationMessageReport): " + ex.Message, ex);
}
}
protected override void udpPacketProcessor()
{
int lastUdpReceived = 0;
long lastWatchDog = 0;
long seqNumInicialAnterior = 0;
long seqNumFinalAnterior = 0;
long lastLogUDP = 0;
long lastForaOrdem = 0;
int queueRead = 0;
CreateSocket(multicastServerPRI, multicastPortPRI);
while (bKeepRunning)
{
try
{
TimeSpan tsWatchDog = new TimeSpan(DateTime.UtcNow.Ticks - lastWatchDog);
if (tsWatchDog.TotalMilliseconds > 30000)
{
logger.Info("Aguardando recepcao pacotes UDP");
lastWatchDog = DateTime.UtcNow.Ticks;
}
UdpPacket udppacket = null;
if (qUdpPkt.TryDequeue(out udppacket) && queueRead < 1000)
{
queueRead++;
UmdfPacket umdfpacket = new UmdfPacket(udppacket.byteData, 0, udppacket.pktLength);
if (logger.IsDebugEnabled)
{
logger.DebugFormat("Recebeu pacote: {0} {1}/{2} {3}",
umdfpacket.seqNum,
umdfpacket.noChunks,
umdfpacket.currChunk,
umdfpacket.msgLength);
}
// ATP: O chunk pode vir fora de sequencia.... o teste abaixo eh furado
//if (umdfpacket.seqNum == 1 && umdfpacket.currChunk == 1)
//{
// logger.Info("Limpa toda a fila de mensagens de fora de ordem!");
// qUdpPktOut.Clear();
// lastpkt = 0;
//}
// Se o pacote recebido for anterior ao ultimo processado, despreza
if (umdfpacket.seqNum < (lastpkt + 1) && umdfpacket.seqNum != 1 &&
umdfpacket.currChunk < (lastChunk + 1))
{
logger.Info("Despreza SeqNum[" + umdfpacket.seqNum + "] ja processado");
continue;
}
// Se o pacote recebido maior, mas nao consecutivo ao ultimo recebido,
// enfileira e solicita o intervalo
if (umdfpacket.seqNum > (lastUdpReceived + 1))
{
//if (lastpkt == 0 && umdfpacket.seqNum != 1)
//{
// logger.Debug("Despreza pacote[" + umdfpacket.seqNum + "] ate o reinicio da lista");
// continue;
//}
qUdpPktOut.Enqueue(udppacket);
//if (lastUdpReceived != 0 && channelConfig.IsPuma==true)
//{
// logger.Debug("Perdeu pacote[" + (lastUdpReceived + 1) + "], reinfilera pacote[" + umdfpacket.seqNum + "] (Tam seqOut = " + qUdpPktOut.Count + ")");
// packetTimeWindow(qUdpPktOut, lastUdpReceived + 1, umdfpacket.seqNum - 1);
//}
lastUdpReceived = umdfpacket.seqNum;
continue;
}
// Se for apenas maior que o ultimo processado, enfilera
// para reordenacao
if (umdfpacket.seqNum > (this.lastpkt + 1))
{
if (logger.IsDebugEnabled)
{
logger.Debug("Reenfileira pacote[" + (lastUdpReceived + 1) + "] para fila out (Tam seqOut = " + qUdpPktOut.Count + ")");
}
qUdpPktOut.Enqueue(udppacket);
lastUdpReceived = umdfpacket.seqNum;
continue;
}
if (logger.IsDebugEnabled)
{
logger.Debug("Submetendo pacote [" + umdfpacket.seqNum + "] para fila de processamento");
}
//bool bsinaliza = qUmdfPacket.IsEmpty;
qUmdfPacket.Enqueue(umdfpacket);
//if (bsinaliza)
//{
// lock (syncQueueUmdfPacket)
// {
// Monitor.Pulse(syncQueueUmdfPacket);
// }
//}
lastUdpReceived = lastpkt = umdfpacket.seqNum;
if (umdfpacket.currChunk == umdfpacket.noChunks)
{
lastChunk = 0;
}
else
{
lastChunk = umdfpacket.currChunk;
}
if (MDSUtils.shouldLog(lastLogUDP))
{
logger.Info("Fila de pacotes UDP recebidos: " + qUdpPkt.Count);
lastLogUDP = DateTime.UtcNow.Ticks;
}
continue;
}
queueRead = 0;
if (MDSUtils.shouldLog(lastForaOrdem, 5))
{
logger.Info("Processando fila de pacotes fora de ordem (out) tamout=" + qUdpPktOut.Count);
lastForaOrdem = DateTime.UtcNow.Ticks;
if (qUdpPktOut.Count > 25000)
{
logger.Fatal("Holy shit, deve reiniciar o canal por excesso de pacotes aguardando processamento");
string msg = "Canal [" + this.channelConfig.ChannelID + "] precisa ser derrubado, pois nao fila esta acumulando.\r\n";
msg += "Ultima processada: " + lastMsgSeqNum;
string titulo = string.Format("Derrubando canal [{0}] por fila crescente", this.channelConfig.ChannelID);
bKeepRunning = false;
}
}
// Tenta processar pacotes recebidos via replay
int tentativa = 0;
while (qUdpPktReplay.Count > 0 && bKeepRunning && tentativa < qUdpPktReplay.Count)
{
tentativa++;
UdpPacket udppacket1 = null;
lock (this.qUdpPktReplay)
{
udppacket1 = qUdpPktReplay.Dequeue();
}
UmdfPacket umdfpacket = new UmdfPacket(udppacket1.byteData, 0, udppacket1.pktLength);
if (logger.IsDebugEnabled)
{
logger.DebugFormat("Recebeu pacote Replay : {0} {1}/{2} {3}",
umdfpacket.seqNum,
umdfpacket.noChunks,
umdfpacket.currChunk,
umdfpacket.msgLength);
}
if (umdfpacket.seqNum < (lastpkt + 1) && umdfpacket.seqNum != 1)
{
logger.Info("Despreza pacote replay SeqNum[" + umdfpacket.seqNum + "] ja processado");
continue;
}
if (umdfpacket.seqNum > (lastpkt + 1))
{
if (logger.IsDebugEnabled)
{
logger.Debug("Pacote replay ainda nao eh o esperado, reinfilera pacote[" + umdfpacket.seqNum + "]");
}
lock (qUdpPktReplay)
{
qUdpPktReplay.Enqueue(udppacket1);
}
continue;
}
if (logger.IsDebugEnabled)
{
logger.Debug("Submetendo pacote replay [" + umdfpacket.seqNum + "] para fila de processamento");
}
//bool bsinaliza = qUmdfPacket.IsEmpty;
qUmdfPacket.Enqueue(umdfpacket);
//if (bsinaliza)
//{
// lock (syncQueueUmdfPacket)
// {
// Monitor.Pulse(syncQueueUmdfPacket);
// }
//}
lastpkt = umdfpacket.seqNum;
continue;
}
// Tenta processar pacotes fora de ordem....
//int tentativa = 0;
//tentativa = 0;
if (tentativa == 0) // Se ja processou tudo via replay
{
while (qUdpPktOut.Count > 0 && bKeepRunning && tentativa < qUdpPktOut.Count)
{
tentativa++;
UdpPacket udppacket1 = null;
lock (qUdpPktOut)
{
udppacket1 = qUdpPktOut.Peek();
}
UmdfPacket umdfpacket = new UmdfPacket(udppacket1.byteData, 0, udppacket1.pktLength);
if (logger.IsDebugEnabled)
{
logger.DebugFormat("Recebeu pacote out: {0} {1}/{2} {3}",
umdfpacket.seqNum,
umdfpacket.noChunks,
umdfpacket.currChunk,
umdfpacket.msgLength);
}
if (umdfpacket.seqNum < (lastpkt + 1) && umdfpacket.seqNum != 1 && umdfpacket.noChunks == 1)
{
logger.Info("Despreza out SeqNum[" + umdfpacket.seqNum + "] ja processado");
lock (qUdpPktOut)
{
udppacket1 = qUdpPktOut.Dequeue();
}
continue;
}
if (!this.channelConfig.IsNewsChannel)
{
if (!this.channelConfig.IsPuma || (DateTime.Now.Hour >= 9 && DateTime.Now.Hour <= 18))
{
if (umdfpacket.seqNum > (lastpkt + 1) && ProcessamentoMensagensEnabled)
{
if (logger.IsDebugEnabled)
{
logger.Debug("Out: Perdeu pacote [" + (lastpkt + 1) + "], reinfilera pacote[" + umdfpacket.seqNum + "]");
}
//lock (qUdpPktOut)
//{
// qUdpPktOut.Enqueue(udppacket);
//}
//Sanity check....
int seqNumInicial = lastpkt + 1;
int seqNumFinal = umdfpacket.seqNum - 1;
if (seqNumInicial <= seqNumFinal)
{
// Se expirou o TTL do pacote, descarta
TimeSpan ts = new TimeSpan(DateTime.Now.Ticks - udppacket1.pktTimestamp);
if (ts.TotalMilliseconds > 20 && lastpkt != 0 &&
(seqNumInicialAnterior == 0 || seqNumFinalAnterior == 0 || seqNumInicial < seqNumInicialAnterior || seqNumInicial > seqNumFinalAnterior))
{
if (!packetTimeWindow(qUdpPktOut, seqNumInicial, seqNumFinal))
{
logger.Fatal("Holy shit, nao recebeu replay, deve reiniciar o canal");
string msg = "Canal [" + this.channelConfig.ChannelID + "] precisa ser derrubado, pois nao recebeu resposta do replay.\r\n";
msg += "Timeout aguardando tcpreplay, ultima processada: " + lastMsgSeqNum;
string titulo = string.Format("Derrubando canal [{0}] por timeout replay", this.channelConfig.ChannelID);
if (DateTime.Now.DayOfWeek != DayOfWeek.Sunday && DateTime.Now.DayOfWeek != DayOfWeek.Saturday)
{
if (DateTime.Now.Hour >= ConstantesMDS.HORARIO_NOTIFICACAO_EMAIL_INICIO &&
DateTime.Now.Hour < ConstantesMDS.HORARIO_NOTIFICACAO_EMAIL_FIM)
{
MDSUtils.EnviarEmail(titulo, msg);
}
}
bKeepRunning = false;
}
seqNumInicialAnterior = seqNumInicial;
seqNumFinalAnterior = seqNumFinal;
break;
}
}
break;
}
}
}
if (logger.IsDebugEnabled)
{
logger.Debug("Submetendo pacote out[" + umdfpacket.seqNum + "] para fila de processamento");
}
lock (qUdpPktOut)
{
udppacket1 = qUdpPktOut.Dequeue();
}
//bool bsinaliza = qUmdfPacket.IsEmpty;
qUmdfPacket.Enqueue(umdfpacket);
//if (bsinaliza)
//{
// lock (syncQueueUmdfPacket)
// {
// Monitor.Pulse(syncQueueUmdfPacket);
// }
//}
lastpkt = umdfpacket.seqNum;
}
}
lock (syncQueueUdpPkt)
{
Monitor.Wait(syncQueueUdpPkt, 100);
}
}
catch (Exception ex)
{
logger.Error("udpPacketProcessor: " + ex.Message, ex);
}
}
}
protected virtual void umdfPacketAssembler()
{
//UmdfPacket packet = null;
int lastSeqNum = 0;
UmdfPacket [] chunks = null;
int receivedChunks = 0;
Dictionary <int, long> dctSeqNum = new Dictionary <int, long>();
//StreamWriter tracewriter = new StreamWriter("d:\\turingoms\\servicos\\mdsnetpuma2\\logs\\Trace-" + this.channelID + "-" + this.multicastPortPRI + ".txt", true);
while (bKeepRunning)
{
Context context = null;
UmdfPacket packet = null;
if (qUmdfPacket.TryDequeue(out packet))
{
int totalBytes = packet.data.Length;
try
{
//if (context != null)
//{
// ((OpenFAST.Debug.BasicDecodeTrace)context.DecodeTrace).Writer.Close();
// ((OpenFAST.Debug.BasicDecodeTrace)context.DecodeTrace).Writer.Dispose();
// context = null;
//}
context = new Context();
context.TemplateRegistry = registry;
//context.TraceEnabled = true;
//context.StartTrace();
//((OpenFAST.Debug.BasicDecodeTrace)context.DecodeTrace).Writer = tracewriter;
if (packet.noChunks > 1)
{
logger.Debug("pktAss() noChunks: " + packet.noChunks + " currChunk: " + packet.currChunk + " seqNum: " + packet.seqNum + " lastSeqNum:" + lastSeqNum);
if (chunks == null || packet.seqNum != lastSeqNum)
{
logger.Debug("pktAss() Alocando array para [" + packet.noChunks + "] chunks: null ou seqNum!=");
chunks = new UmdfPacket[packet.noChunks];
receivedChunks = 0;
}
// Verifica se ainda esta no mesmo chunk, e se ainda dentro da mesma
// rodada do snapshot
if (dctSeqNum.ContainsKey(packet.seqNum))
{
TimeSpan ts = new TimeSpan(DateTime.Now.Ticks - dctSeqNum[packet.seqNum]);
if (ts.TotalMilliseconds > PACKET_TIME_WINDOW && processorType.Equals(ProcessorType.MarketIncremental))
{
logger.Debug("pktAss() REALOCANDO array para [" + packet.noChunks + "] chunks");
chunks = new UmdfPacket[packet.noChunks];
receivedChunks = 0;
}
dctSeqNum[packet.seqNum] = DateTime.Now.Ticks;
}
else
{
logger.Debug("pktAss() Alocando array para [" + packet.noChunks + "] chunks");
dctSeqNum.Add(packet.seqNum, DateTime.Now.Ticks);
chunks = new UmdfPacket[packet.noChunks];
receivedChunks = 0;
}
if ((packet.currChunk - 1) < chunks.Length)
{
if (chunks[packet.currChunk - 1] == null)
{
receivedChunks++;
}
chunks[packet.currChunk - 1] = packet;
}
else
{
logger.Error("pktAss() Puts...[" + (packet.currChunk - 1) + "] <=> [" + chunks.Length + "] fdp furou!!!!");
continue;
}
logger.Debug("pktAss() noChunks: " + packet.noChunks + " currChunk: " + packet.currChunk);
lastSeqNum = packet.seqNum;
if (receivedChunks < packet.noChunks)
{
continue;
}
dctSeqNum.Remove(packet.seqNum);
logger.Debug("pktAss() Remontando pacote noChunks=" + packet.noChunks + " received=" + receivedChunks + " length=" + chunks.Length);
byte[] reassembled = UmdfUtils.reassemble(chunks);
totalBytes = reassembled.Length;
chunks = null;
receivedChunks = 0;
packet.data = reassembled;
packet.msgLength = totalBytes;
System.IO.MemoryStream byteIn = new System.IO.MemoryStream(packet.data, 0, packet.msgLength);
FastDecoder decoder = new FastDecoder(context, byteIn);
Message message = decoder.ReadMessage();
bool bsinaliza = queueToProcessor.IsEmpty;
queueToProcessor.Enqueue(message);
if (bsinaliza)
{
lock (syncQueueToProcessor)
{
Monitor.Pulse(syncQueueToProcessor);
}
}
// testa se debug esta habilitado por conta do writegroup
// mais performatico
if (logger.IsDebugEnabled)
{
logger.Debug(UmdfUtils.writeGroup(message));
}
}
else
{
lastSeqNum = packet.seqNum;
System.IO.MemoryStream byteIn = new System.IO.MemoryStream(packet.data, 0, packet.msgLength);
FastDecoder decoder = new FastDecoder(context, byteIn);
Message message = decoder.ReadMessage();
bool bsinaliza = queueToProcessor.IsEmpty;
queueToProcessor.Enqueue(message);
if (bsinaliza)
{
lock (syncQueueToProcessor)
{
Monitor.Pulse(syncQueueToProcessor);
}
}
if (logger.IsDebugEnabled)
{
logger.Debug(UmdfUtils.writeGroup(message));
}
}
}
catch (Exception ex)
{
logger.Error("pktAss() Erro: " + ex.Message, ex);
// Bom, com uma exception dessas, acho melhor iniciar o canal, pode ser falha no decoder
string msg = string.Format("Canal [{0}] precisa ser derrubado, pois deu falha grave no PacketAssembler().\r\n\r\n{1}\r\n\r\n{2}", channelID, ex.Message, ex);
string titulo = string.Format("Derrubando canal [{0}] por falha em pktAss()", channelID);
MDSUtils.EnviarEmail(titulo, msg);
bKeepRunning = false;
//lastpkt = 0;
}
continue;
}
lock (syncQueueUmdfPacket)
{
Monitor.Wait(syncQueueUmdfPacket, 100);
}
}
}
