pa/eqemu-server
2
0
Fork 0
mirror of https://github.com/EQEmu/Server.git synced 2026-05-16 18:52:22 +00:00
Code Issues Actions Packages Projects Releases Wiki Activity

Merge of a monster

Browse Source
This commit is contained in:
KimLS
2017-04-02 20:03:51 -07:00
parent 9750d09635 773932d8f6
commit 281483efc1
146 changed files with 10532 additions and 7432 deletions
Download Patch File Download Diff File Expand all files Collapse all files
common/eq_stream.cpp
+118 -118
View File
@@ -84,14 +84,14 @@ void EQStream::init(bool resetSession) {
OpMgr = nullptr;
if(uint16(SequencedBase + SequencedQueue.size()) != NextOutSeq) {
Log.Out(Logs::Detail, Logs::Netcode, _L "init Invalid Sequenced queue: BS %d + SQ %d != NOS %d" __L, SequencedBase, SequencedQueue.size(), NextOutSeq);
Log(Logs::Detail, Logs::Netcode, _L "init Invalid Sequenced queue: BS %d + SQ %d != NOS %d" __L, SequencedBase, SequencedQueue.size(), NextOutSeq);
}
}
EQRawApplicationPacket *EQStream::MakeApplicationPacket(EQProtocolPacket *p)
{
EQRawApplicationPacket *ap=nullptr;
Log.Out(Logs::Detail, Logs::Netcode, _L "Creating new application packet, length %d" __L, p->size);
Log(Logs::Detail, Logs::Netcode, _L "Creating new application packet, length %d" __L, p->size);
// _raw(NET__APP_CREATE_HEX, 0xFFFF, p);
ap = p->MakeAppPacket();
return ap;
@@ -100,7 +100,7 @@ EQRawApplicationPacket *EQStream::MakeApplicationPacket(EQProtocolPacket *p)
EQRawApplicationPacket *EQStream::MakeApplicationPacket(const unsigned char *buf, uint32 len)
{
EQRawApplicationPacket *ap=nullptr;
Log.Out(Logs::Detail, Logs::Netcode, _L "Creating new application packet, length %d" __L, len);
Log(Logs::Detail, Logs::Netcode, _L "Creating new application packet, length %d" __L, len);
ap = new EQRawApplicationPacket(buf, len);
return ap;
}
@@ -130,7 +130,7 @@ void EQStream::ProcessPacket(EQProtocolPacket *p)
}
if (!Session && p->opcode!=OP_SessionRequest && p->opcode!=OP_SessionResponse) {
Log.Out(Logs::Detail, Logs::Netcode, _L "Session not initialized, packet ignored" __L);
Log(Logs::Detail, Logs::Netcode, _L "Session not initialized, packet ignored" __L);
// _raw(NET__DEBUG, 0xFFFF, p);
return;
}
@@ -141,7 +141,7 @@ void EQStream::ProcessPacket(EQProtocolPacket *p)
while(processed < p->size) {
subpacket_length=*(p->pBuffer+processed);
EQProtocolPacket *subp=MakeProtocolPacket(p->pBuffer+processed+1,subpacket_length);
Log.Out(Logs::Detail, Logs::Netcode, _L "Extracting combined packet of length %d" __L, subpacket_length);
Log(Logs::Detail, Logs::Netcode, _L "Extracting combined packet of length %d" __L, subpacket_length);
// _raw(NET__NET_CREATE_HEX, 0xFFFF, subp);
subp->copyInfo(p);
ProcessPacket(subp);
@@ -156,12 +156,12 @@ void EQStream::ProcessPacket(EQProtocolPacket *p)
while(processed<p->size) {
EQRawApplicationPacket *ap=nullptr;
if ((subpacket_length=(unsigned char)*(p->pBuffer+processed))!=0xff) {
Log.Out(Logs::Detail, Logs::Netcode, _L "Extracting combined app packet of length %d, short len" __L, subpacket_length);
Log(Logs::Detail, Logs::Netcode, _L "Extracting combined app packet of length %d, short len" __L, subpacket_length);
ap=MakeApplicationPacket(p->pBuffer+processed+1,subpacket_length);
processed+=subpacket_length+1;
} else {
subpacket_length=ntohs(*(uint16 *)(p->pBuffer+processed+1));
Log.Out(Logs::Detail, Logs::Netcode, _L "Extracting combined app packet of length %d, short len" __L, subpacket_length);
Log(Logs::Detail, Logs::Netcode, _L "Extracting combined app packet of length %d, short len" __L, subpacket_length);
ap=MakeApplicationPacket(p->pBuffer+processed+3,subpacket_length);
processed+=subpacket_length+3;
}
@@ -176,29 +176,29 @@ void EQStream::ProcessPacket(EQProtocolPacket *p)
case OP_Packet: {
if(!p->pBuffer || (p->Size() < 4))
{
Log.Out(Logs::Detail, Logs::Netcode, _L "Received OP_Packet that was of malformed size" __L);
Log(Logs::Detail, Logs::Netcode, _L "Received OP_Packet that was of malformed size" __L);
break;
}
uint16 seq=ntohs(*(uint16 *)(p->pBuffer));
SeqOrder check=CompareSequence(NextInSeq,seq);
if (check == SeqFuture) {
Log.Out(Logs::Detail, Logs::Netcode, _L "Future OP_Packet: Expecting Seq=%d, but got Seq=%d" __L, NextInSeq, seq);
Log(Logs::Detail, Logs::Netcode, _L "Future OP_Packet: Expecting Seq=%d, but got Seq=%d" __L, NextInSeq, seq);
// _raw(NET__DEBUG, seq, p);
PacketQueue[seq]=p->Copy();
Log.Out(Logs::Detail, Logs::Netcode, _L "OP_Packet Queue size=%d" __L, PacketQueue.size());
Log(Logs::Detail, Logs::Netcode, _L "OP_Packet Queue size=%d" __L, PacketQueue.size());
//SendOutOfOrderAck(seq);
} else if (check == SeqPast) {
Log.Out(Logs::Detail, Logs::Netcode, _L "Duplicate OP_Packet: Expecting Seq=%d, but got Seq=%d" __L, NextInSeq, seq);
Log(Logs::Detail, Logs::Netcode, _L "Duplicate OP_Packet: Expecting Seq=%d, but got Seq=%d" __L, NextInSeq, seq);
// _raw(NET__DEBUG, seq, p);
SendOutOfOrderAck(seq); //we already got this packet but it was out of order
} else {
// In case we did queue one before as well.
EQProtocolPacket *qp=RemoveQueue(seq);
if (qp) {
Log.Out(Logs::General, Logs::Netcode, "[NET_TRACE] OP_Packet: Removing older queued packet with sequence %d", seq);
Log(Logs::General, Logs::Netcode, "[NET_TRACE] OP_Packet: Removing older queued packet with sequence %d", seq);
delete qp;
}
@@ -207,7 +207,7 @@ void EQStream::ProcessPacket(EQProtocolPacket *p)
// Check for an embedded OP_AppCombinded (protocol level 0x19)
if (*(p->pBuffer+2)==0x00 && *(p->pBuffer+3)==0x19) {
EQProtocolPacket *subp=MakeProtocolPacket(p->pBuffer+2,p->size-2);
Log.Out(Logs::Detail, Logs::Netcode, _L "seq %d, Extracting combined packet of length %d" __L, seq, subp->size);
Log(Logs::Detail, Logs::Netcode, _L "seq %d, Extracting combined packet of length %d" __L, seq, subp->size);
// _raw(NET__NET_CREATE_HEX, seq, subp);
subp->copyInfo(p);
ProcessPacket(subp);
@@ -226,29 +226,29 @@ void EQStream::ProcessPacket(EQProtocolPacket *p)
case OP_Fragment: {
if(!p->pBuffer || (p->Size() < 4))
{
Log.Out(Logs::Detail, Logs::Netcode, _L "Received OP_Fragment that was of malformed size" __L);
Log(Logs::Detail, Logs::Netcode, _L "Received OP_Fragment that was of malformed size" __L);
break;
}
uint16 seq=ntohs(*(uint16 *)(p->pBuffer));
SeqOrder check=CompareSequence(NextInSeq,seq);
if (check == SeqFuture) {
Log.Out(Logs::Detail, Logs::Netcode, _L "Future OP_Fragment: Expecting Seq=%d, but got Seq=%d" __L, NextInSeq, seq);
Log(Logs::Detail, Logs::Netcode, _L "Future OP_Fragment: Expecting Seq=%d, but got Seq=%d" __L, NextInSeq, seq);
// _raw(NET__DEBUG, seq, p);
PacketQueue[seq]=p->Copy();
Log.Out(Logs::Detail, Logs::Netcode, _L "OP_Fragment Queue size=%d" __L, PacketQueue.size());
Log(Logs::Detail, Logs::Netcode, _L "OP_Fragment Queue size=%d" __L, PacketQueue.size());
//SendOutOfOrderAck(seq);
} else if (check == SeqPast) {
Log.Out(Logs::Detail, Logs::Netcode, _L "Duplicate OP_Fragment: Expecting Seq=%d, but got Seq=%d" __L, NextInSeq, seq);
Log(Logs::Detail, Logs::Netcode, _L "Duplicate OP_Fragment: Expecting Seq=%d, but got Seq=%d" __L, NextInSeq, seq);
// _raw(NET__DEBUG, seq, p);
SendOutOfOrderAck(seq);
} else {
// In case we did queue one before as well.
EQProtocolPacket *qp=RemoveQueue(seq);
if (qp) {
Log.Out(Logs::General, Logs::Netcode, "[NET_TRACE] OP_Fragment: Removing older queued packet with sequence %d", seq);
Log(Logs::General, Logs::Netcode, "[NET_TRACE] OP_Fragment: Removing older queued packet with sequence %d", seq);
delete qp;
}
SetNextAckToSend(seq);
@@ -256,18 +256,18 @@ void EQStream::ProcessPacket(EQProtocolPacket *p)
if (oversize_buffer) {
memcpy(oversize_buffer+oversize_offset,p->pBuffer+2,p->size-2);
oversize_offset+=p->size-2;
Log.Out(Logs::Detail, Logs::Netcode, _L "Fragment of oversized of length %d, seq %d: now at %d/%d" __L, p->size-2, seq, oversize_offset, oversize_length);
Log(Logs::Detail, Logs::Netcode, _L "Fragment of oversized of length %d, seq %d: now at %d/%d" __L, p->size-2, seq, oversize_offset, oversize_length);
if (oversize_offset==oversize_length) {
if (*(p->pBuffer+2)==0x00 && *(p->pBuffer+3)==0x19) {
EQProtocolPacket *subp=MakeProtocolPacket(oversize_buffer,oversize_offset);
Log.Out(Logs::Detail, Logs::Netcode, _L "seq %d, Extracting combined oversize packet of length %d" __L, seq, subp->size);
Log(Logs::Detail, Logs::Netcode, _L "seq %d, Extracting combined oversize packet of length %d" __L, seq, subp->size);
//// _raw(NET__NET_CREATE_HEX, subp);
subp->copyInfo(p);
ProcessPacket(subp);
delete subp;
} else {
EQRawApplicationPacket *ap=MakeApplicationPacket(oversize_buffer,oversize_offset);
Log.Out(Logs::Detail, Logs::Netcode, _L "seq %d, completed combined oversize packet of length %d" __L, seq, ap->size);
Log(Logs::Detail, Logs::Netcode, _L "seq %d, completed combined oversize packet of length %d" __L, seq, ap->size);
if (ap) {
ap->copyInfo(p);
InboundQueuePush(ap);
@@ -282,20 +282,20 @@ void EQStream::ProcessPacket(EQProtocolPacket *p)
oversize_buffer=new unsigned char[oversize_length];
memcpy(oversize_buffer,p->pBuffer+6,p->size-6);
oversize_offset=p->size-6;
Log.Out(Logs::Detail, Logs::Netcode, _L "First fragment of oversized of seq %d: now at %d/%d" __L, seq, oversize_offset, oversize_length);
Log(Logs::Detail, Logs::Netcode, _L "First fragment of oversized of seq %d: now at %d/%d" __L, seq, oversize_offset, oversize_length);
}
}
}
break;
case OP_KeepAlive: {
NonSequencedPush(new EQProtocolPacket(p->opcode,p->pBuffer,p->size));
Log.Out(Logs::Detail, Logs::Netcode, _L "Received and queued reply to keep alive" __L);
Log(Logs::Detail, Logs::Netcode, _L "Received and queued reply to keep alive" __L);
}
break;
case OP_Ack: {
if(!p->pBuffer || (p->Size() < 4))
{
Log.Out(Logs::Detail, Logs::Netcode, _L "Received OP_Ack that was of malformed size" __L);
Log(Logs::Detail, Logs::Netcode, _L "Received OP_Ack that was of malformed size" __L);
break;
}
uint16 seq=ntohs(*(uint16 *)(p->pBuffer));
@@ -309,11 +309,11 @@ void EQStream::ProcessPacket(EQProtocolPacket *p)
case OP_SessionRequest: {
if(p->Size() < sizeof(SessionRequest))
{
Log.Out(Logs::Detail, Logs::Netcode, _L "Received OP_SessionRequest that was of malformed size" __L);
Log(Logs::Detail, Logs::Netcode, _L "Received OP_SessionRequest that was of malformed size" __L);
break;
}
if (GetState()==ESTABLISHED) {
Log.Out(Logs::Detail, Logs::Netcode, _L "Received OP_SessionRequest in ESTABLISHED state (%d) streamactive (%i) attempt (%i)" __L, GetState(),streamactive,sessionAttempts);
Log(Logs::Detail, Logs::Netcode, _L "Received OP_SessionRequest in ESTABLISHED state (%d) streamactive (%i) attempt (%i)" __L, GetState(),streamactive,sessionAttempts);
// client seems to try a max of 30 times (initial+3 retries) then gives up, giving it a few more attempts just in case
// streamactive means we identified the opcode for the stream, we cannot re-establish this connection
@@ -331,7 +331,7 @@ void EQStream::ProcessPacket(EQProtocolPacket *p)
SessionRequest *Request=(SessionRequest *)p->pBuffer;
Session=ntohl(Request->Session);
SetMaxLen(ntohl(Request->MaxLength));
Log.Out(Logs::Detail, Logs::Netcode, _L "Received OP_SessionRequest: session %lu, maxlen %d" __L, (unsigned long)Session, MaxLen);
Log(Logs::Detail, Logs::Netcode, _L "Received OP_SessionRequest: session %lu, maxlen %d" __L, (unsigned long)Session, MaxLen);
SetState(ESTABLISHED);
Key=0x11223344;
SendSessionResponse();
@@ -340,7 +340,7 @@ void EQStream::ProcessPacket(EQProtocolPacket *p)
case OP_SessionResponse: {
if(p->Size() < sizeof(SessionResponse))
{
Log.Out(Logs::Detail, Logs::Netcode, _L "Received OP_SessionResponse that was of malformed size" __L);
Log(Logs::Detail, Logs::Netcode, _L "Received OP_SessionResponse that was of malformed size" __L);
break;
}
@@ -356,7 +356,7 @@ void EQStream::ProcessPacket(EQProtocolPacket *p)
compressed=(Response->Format&FLAG_COMPRESSED);
encoded=(Response->Format&FLAG_ENCODED);
Log.Out(Logs::Detail, Logs::Netcode, _L "Received OP_SessionResponse: session %lu, maxlen %d, key %lu, compressed? %s, encoded? %s" __L, (unsigned long)Session, MaxLen, (unsigned long)Key, compressed?"yes":"no", encoded?"yes":"no");
Log(Logs::Detail, Logs::Netcode, _L "Received OP_SessionResponse: session %lu, maxlen %d, key %lu, compressed? %s, encoded? %s" __L, (unsigned long)Session, MaxLen, (unsigned long)Key, compressed?"yes":"no", encoded?"yes":"no");
// Kinda kludgy, but trie for now
if (StreamType==UnknownStream) {
@@ -379,17 +379,17 @@ void EQStream::ProcessPacket(EQProtocolPacket *p)
EQStreamState state = GetState();
if(state == ESTABLISHED) {
//client initiated disconnect?
Log.Out(Logs::Detail, Logs::Netcode, _L "Received unsolicited OP_SessionDisconnect. Treating like a client-initiated disconnect." __L);
Log(Logs::Detail, Logs::Netcode, _L "Received unsolicited OP_SessionDisconnect. Treating like a client-initiated disconnect." __L);
_SendDisconnect();
SetState(CLOSED);
} else if(state == CLOSING) {
//we were waiting for this anyways, ignore pending messages, send the reply and be closed.
Log.Out(Logs::Detail, Logs::Netcode, _L "Received OP_SessionDisconnect when we have a pending close, they beat us to it. Were happy though." __L);
Log(Logs::Detail, Logs::Netcode, _L "Received OP_SessionDisconnect when we have a pending close, they beat us to it. Were happy though." __L);
_SendDisconnect();
SetState(CLOSED);
} else {
//we are expecting this (or have already gotten it, but dont care either way)
Log.Out(Logs::Detail, Logs::Netcode, _L "Received expected OP_SessionDisconnect. Moving to closed state." __L);
Log(Logs::Detail, Logs::Netcode, _L "Received expected OP_SessionDisconnect. Moving to closed state." __L);
SetState(CLOSED);
}
}
@@ -397,24 +397,24 @@ void EQStream::ProcessPacket(EQProtocolPacket *p)
case OP_OutOfOrderAck: {
if(!p->pBuffer || (p->Size() < 4))
{
Log.Out(Logs::Detail, Logs::Netcode, _L "Received OP_OutOfOrderAck that was of malformed size" __L);
Log(Logs::Detail, Logs::Netcode, _L "Received OP_OutOfOrderAck that was of malformed size" __L);
break;
}
uint16 seq=ntohs(*(uint16 *)(p->pBuffer));
MOutboundQueue.lock();
if(uint16(SequencedBase + SequencedQueue.size()) != NextOutSeq) {
Log.Out(Logs::Detail, Logs::Netcode, _L "Pre-OOA Invalid Sequenced queue: BS %d + SQ %d != NOS %d" __L, SequencedBase, SequencedQueue.size(), NextOutSeq);
Log(Logs::Detail, Logs::Netcode, _L "Pre-OOA Invalid Sequenced queue: BS %d + SQ %d != NOS %d" __L, SequencedBase, SequencedQueue.size(), NextOutSeq);
}
//if the packet they got out of order is between our last acked packet and the last sent packet, then its valid.
if (CompareSequence(SequencedBase,seq) != SeqPast && CompareSequence(NextOutSeq,seq) == SeqPast) {
Log.Out(Logs::Detail, Logs::Netcode, _L "Received OP_OutOfOrderAck for sequence %d, starting retransmit at the start of our unacked buffer (seq %d, was %d)." __L,
Log(Logs::Detail, Logs::Netcode, _L "Received OP_OutOfOrderAck for sequence %d, starting retransmit at the start of our unacked buffer (seq %d, was %d)." __L,
seq, SequencedBase, SequencedBase+SequencedQueue.size());
uint16 sqsize = SequencedQueue.size();
uint16 index = seq - SequencedBase;
Log.Out(Logs::Detail, Logs::Netcode, _L "OP_OutOfOrderAck marking packet acked in queue (queue index = %d, queue size = %d)." __L, index, sqsize);
Log(Logs::Detail, Logs::Netcode, _L "OP_OutOfOrderAck marking packet acked in queue (queue index = %d, queue size = %d)." __L, index, sqsize);
if (index < sqsize) {
SequencedQueue[index]->acked = true;
// flag packets for a resend
@@ -423,7 +423,7 @@ void EQStream::ProcessPacket(EQProtocolPacket *p)
for (auto sitr = SequencedQueue.begin(); sitr != SequencedQueue.end() && count < index; ++sitr, ++count) {
if (!(*sitr)->acked && (*sitr)->sent_time > 0 && (((*sitr)->sent_time + timeout) < Timer::GetCurrentTime())) {
(*sitr)->sent_time = 0;
Log.Out(Logs::Detail, Logs::Netcode, _L "OP_OutOfOrderAck Flagging packet %d for retransmission" __L, SequencedBase + count);
Log(Logs::Detail, Logs::Netcode, _L "OP_OutOfOrderAck Flagging packet %d for retransmission" __L, SequencedBase + count);
}
}
}
@@ -432,11 +432,11 @@ void EQStream::ProcessPacket(EQProtocolPacket *p)
retransmittimer = Timer::GetCurrentTime();
}
} else {
Log.Out(Logs::Detail, Logs::Netcode, _L "Received OP_OutOfOrderAck for out-of-window %d. Window (%d->%d)." __L, seq, SequencedBase, NextOutSeq);
Log(Logs::Detail, Logs::Netcode, _L "Received OP_OutOfOrderAck for out-of-window %d. Window (%d->%d)." __L, seq, SequencedBase, NextOutSeq);
}
if(uint16(SequencedBase + SequencedQueue.size()) != NextOutSeq) {
Log.Out(Logs::Detail, Logs::Netcode, _L "Post-OOA Invalid Sequenced queue: BS %d + SQ %d != NOS %d" __L, SequencedBase, SequencedQueue.size(), NextOutSeq);
Log(Logs::Detail, Logs::Netcode, _L "Post-OOA Invalid Sequenced queue: BS %d + SQ %d != NOS %d" __L, SequencedBase, SequencedQueue.size(), NextOutSeq);
}
MOutboundQueue.unlock();
@@ -445,11 +445,11 @@ void EQStream::ProcessPacket(EQProtocolPacket *p)
case OP_SessionStatRequest: {
if(p->Size() < sizeof(ClientSessionStats))
{
Log.Out(Logs::Detail, Logs::Netcode, _L "Received OP_SessionStatRequest that was of malformed size" __L);
Log(Logs::Detail, Logs::Netcode, _L "Received OP_SessionStatRequest that was of malformed size" __L);
break;
}
ClientSessionStats *ClientStats=(ClientSessionStats *)p->pBuffer;
Log.Out(Logs::Detail, Logs::Netcode, _L "Received Stats: %lu packets received, %lu packets sent, Deltas: local %lu, (%lu <- %lu -> %lu) remote %lu" __L,
Log(Logs::Detail, Logs::Netcode, _L "Received Stats: %lu packets received, %lu packets sent, Deltas: local %lu, (%lu <- %lu -> %lu) remote %lu" __L,
(unsigned long)ntohl(ClientStats->packets_received), (unsigned long)ntohl(ClientStats->packets_sent), (unsigned long)ntohl(ClientStats->last_local_delta),
(unsigned long)ntohl(ClientStats->low_delta), (unsigned long)ntohl(ClientStats->average_delta),
(unsigned long)ntohl(ClientStats->high_delta), (unsigned long)ntohl(ClientStats->last_remote_delta));
@@ -468,7 +468,7 @@ void EQStream::ProcessPacket(EQProtocolPacket *p)
retransmittimeout += 300;
if(retransmittimeout > RETRANSMIT_TIMEOUT_MAX)
retransmittimeout = RETRANSMIT_TIMEOUT_MAX;
Log.Out(Logs::Detail, Logs::Netcode, _L "Retransmit timeout recalculated to %dms" __L, retransmittimeout);
Log(Logs::Detail, Logs::Netcode, _L "Retransmit timeout recalculated to %dms" __L, retransmittimeout);
}
}
@@ -485,11 +485,11 @@ void EQStream::ProcessPacket(EQProtocolPacket *p)
}
break;
case OP_SessionStatResponse: {
Log.Out(Logs::Detail, Logs::Netcode, _L "Received OP_SessionStatResponse. Ignoring." __L);
Log(Logs::Detail, Logs::Netcode, _L "Received OP_SessionStatResponse. Ignoring." __L);
}
break;
case OP_OutOfSession: {
Log.Out(Logs::Detail, Logs::Netcode, _L "Received OP_OutOfSession. Ignoring." __L);
Log(Logs::Detail, Logs::Netcode, _L "Received OP_OutOfSession. Ignoring." __L);
}
break;
default:
@@ -520,7 +520,7 @@ void EQStream::FastQueuePacket(EQApplicationPacket **p, bool ack_req)
return;
if(OpMgr == nullptr || *OpMgr == nullptr) {
Log.Out(Logs::Detail, Logs::Netcode, _L "Packet enqueued into a stream with no opcode manager, dropping." __L);
Log(Logs::Detail, Logs::Netcode, _L "Packet enqueued into a stream with no opcode manager, dropping." __L);
delete pack;
return;
}
@@ -545,32 +545,32 @@ void EQStream::SendPacket(uint16 opcode, EQApplicationPacket *p)
uint32 chunksize, used;
uint32 length;
if (Log.log_settings[Logs::Server_Client_Packet].is_category_enabled == 1){
if (LogSys.log_settings[Logs::Server_Client_Packet].is_category_enabled == 1){
if (p->GetOpcode() != OP_SpecialMesg){
Log.Out(Logs::General, Logs::Server_Client_Packet, "[%s - 0x%04x] [Size: %u]", OpcodeManager::EmuToName(p->GetOpcode()), p->GetOpcode(), p->Size());
Log(Logs::General, Logs::Server_Client_Packet, "[%s - 0x%04x] [Size: %u]", OpcodeManager::EmuToName(p->GetOpcode()), p->GetOpcode(), p->Size());
}
}
if (Log.log_settings[Logs::Server_Client_Packet_With_Dump].is_category_enabled == 1){
if (LogSys.log_settings[Logs::Server_Client_Packet_With_Dump].is_category_enabled == 1){
if (p->GetOpcode() != OP_SpecialMesg){
Log.Out(Logs::General, Logs::Server_Client_Packet_With_Dump, "[%s - 0x%04x] [Size: %u] %s", OpcodeManager::EmuToName(p->GetOpcode()), p->GetOpcode(), p->Size(), DumpPacketToString(p).c_str());
Log(Logs::General, Logs::Server_Client_Packet_With_Dump, "[%s - 0x%04x] [Size: %u] %s", OpcodeManager::EmuToName(p->GetOpcode()), p->GetOpcode(), p->Size(), DumpPacketToString(p).c_str());
}
}
// Convert the EQApplicationPacket to 1 or more EQProtocolPackets
if (p->size>(MaxLen-8)) { // proto-op(2), seq(2), app-op(2) ... data ... crc(2)
Log.Out(Logs::Detail, Logs::Netcode, _L "Making oversized packet, len %d" __L, p->Size());
Log(Logs::Detail, Logs::Netcode, _L "Making oversized packet, len %d" __L, p->Size());
auto tmpbuff = new unsigned char[p->size + 3];
length=p->serialize(opcode, tmpbuff);
if (length != p->Size())
Log.Out(Logs::Detail, Logs::Netcode, _L "Packet adjustment, len %d to %d" __L, p->Size(), length);
Log(Logs::Detail, Logs::Netcode, _L "Packet adjustment, len %d to %d" __L, p->Size(), length);
auto out = new EQProtocolPacket(OP_Fragment, nullptr, MaxLen - 4);
*(uint32 *)(out->pBuffer+2)=htonl(length);
used=MaxLen-10;
memcpy(out->pBuffer+6,tmpbuff,used);
Log.Out(Logs::Detail, Logs::Netcode, _L "First fragment: used %d/%d. Payload size %d in the packet" __L, used, length, p->size);
Log(Logs::Detail, Logs::Netcode, _L "First fragment: used %d/%d. Payload size %d in the packet" __L, used, length, p->size);
SequencedPush(out);
@@ -581,7 +581,7 @@ void EQStream::SendPacket(uint16 opcode, EQApplicationPacket *p)
out->size=chunksize+2;
SequencedPush(out);
used+=chunksize;
Log.Out(Logs::Detail, Logs::Netcode, _L "Subsequent fragment: len %d, used %d/%d." __L, chunksize, used, length);
Log(Logs::Detail, Logs::Netcode, _L "Subsequent fragment: len %d, used %d/%d." __L, chunksize, used, length);
}
delete p;
delete[] tmpbuff;
@@ -602,18 +602,18 @@ void EQStream::SequencedPush(EQProtocolPacket *p)
{
MOutboundQueue.lock();
if (uint16(SequencedBase + SequencedQueue.size()) != NextOutSeq) {
Log.Out(Logs::Detail, Logs::Netcode, _L "Pre-Push Invalid Sequenced queue: BS %d + SQ %d != NOS %d" __L,
Log(Logs::Detail, Logs::Netcode, _L "Pre-Push Invalid Sequenced queue: BS %d + SQ %d != NOS %d" __L,
SequencedBase, SequencedQueue.size(), NextOutSeq);
}
Log.Out(Logs::Detail, Logs::Netcode, _L "Pushing sequenced packet %d of length %d. Base Seq is %d." __L,
Log(Logs::Detail, Logs::Netcode, _L "Pushing sequenced packet %d of length %d. Base Seq is %d." __L,
NextOutSeq, p->size, SequencedBase);
*(uint16 *)(p->pBuffer) = htons(NextOutSeq);
SequencedQueue.push_back(p);
NextOutSeq++;
if (uint16(SequencedBase + SequencedQueue.size()) != NextOutSeq) {
Log.Out(Logs::Detail, Logs::Netcode, _L "Push Invalid Sequenced queue: BS %d + SQ %d != NOS %d" __L,
Log(Logs::Detail, Logs::Netcode, _L "Push Invalid Sequenced queue: BS %d + SQ %d != NOS %d" __L,
SequencedBase, SequencedQueue.size(), NextOutSeq);
}
@@ -623,7 +623,7 @@ void EQStream::SequencedPush(EQProtocolPacket *p)
void EQStream::NonSequencedPush(EQProtocolPacket *p)
{
MOutboundQueue.lock();
Log.Out(Logs::Detail, Logs::Netcode, _L "Pushing non-sequenced packet of length %d" __L, p->size);
Log(Logs::Detail, Logs::Netcode, _L "Pushing non-sequenced packet of length %d" __L, p->size);
NonSequencedQueue.push(p);
MOutboundQueue.unlock();
}
@@ -631,14 +631,14 @@ void EQStream::NonSequencedPush(EQProtocolPacket *p)
void EQStream::SendAck(uint16 seq)
{
uint16 Seq=htons(seq);
Log.Out(Logs::Detail, Logs::Netcode, _L "Sending ack with sequence %d" __L, seq);
Log(Logs::Detail, Logs::Netcode, _L "Sending ack with sequence %d" __L, seq);
SetLastAckSent(seq);
NonSequencedPush(new EQProtocolPacket(OP_Ack,(unsigned char *)&Seq,sizeof(uint16)));
}
void EQStream::SendOutOfOrderAck(uint16 seq)
{
Log.Out(Logs::Detail, Logs::Netcode, _L "Sending out of order ack with sequence %d" __L, seq);
Log(Logs::Detail, Logs::Netcode, _L "Sending out of order ack with sequence %d" __L, seq);
uint16 Seq=htons(seq);
NonSequencedPush(new EQProtocolPacket(OP_OutOfOrderAck,(unsigned char *)&Seq,sizeof(uint16)));
}
@@ -688,24 +688,24 @@ void EQStream::Write(int eq_fd)
// If we don't have a packet to try to combine into, use this one as the base
// And remove it form the queue
p = NonSequencedQueue.front();
Log.Out(Logs::Detail, Logs::Netcode, _L "Starting combined packet with non-seq packet of len %d" __L, p->size);
Log(Logs::Detail, Logs::Netcode, _L "Starting combined packet with non-seq packet of len %d" __L, p->size);
NonSequencedQueue.pop();
} else if (!p->combine(NonSequencedQueue.front())) {
// Trying to combine this packet with the base didn't work (too big maybe)
// So just send the base packet (we'll try this packet again later)
Log.Out(Logs::Detail, Logs::Netcode, _L "Combined packet full at len %d, next non-seq packet is len %d" __L, p->size, (NonSequencedQueue.front())->size);
Log(Logs::Detail, Logs::Netcode, _L "Combined packet full at len %d, next non-seq packet is len %d" __L, p->size, (NonSequencedQueue.front())->size);
ReadyToSend.push(p);
BytesWritten+=p->size;
p=nullptr;
if (BytesWritten > threshold) {
// Sent enough this round, lets stop to be fair
Log.Out(Logs::Detail, Logs::Netcode, _L "Exceeded write threshold in nonseq (%d > %d)" __L, BytesWritten, threshold);
Log(Logs::Detail, Logs::Netcode, _L "Exceeded write threshold in nonseq (%d > %d)" __L, BytesWritten, threshold);
break;
}
} else {
// Combine worked, so just remove this packet and it's spot in the queue
Log.Out(Logs::Detail, Logs::Netcode, _L "Combined non-seq packet of len %d, yeilding %d combined." __L, (NonSequencedQueue.front())->size, p->size);
Log(Logs::Detail, Logs::Netcode, _L "Combined non-seq packet of len %d, yeilding %d combined." __L, (NonSequencedQueue.front())->size, p->size);
delete NonSequencedQueue.front();
NonSequencedQueue.pop();
}
@@ -718,7 +718,7 @@ void EQStream::Write(int eq_fd)
uint16 seq_send = SequencedBase + count; //just for logging...
if(SequencedQueue.empty()) {
Log.Out(Logs::Detail, Logs::Netcode, _L "Tried to write a packet with an empty queue (%d is past next out %d)" __L, seq_send, NextOutSeq);
Log(Logs::Detail, Logs::Netcode, _L "Tried to write a packet with an empty queue (%d is past next out %d)" __L, seq_send, NextOutSeq);
SeqEmpty=true;
continue;
}
@@ -728,35 +728,35 @@ void EQStream::Write(int eq_fd)
++sitr;
++count;
if (p) {
Log.Out(Logs::Detail, Logs::Netcode, _L "Final combined packet not full, len %d" __L, p->size);
Log(Logs::Detail, Logs::Netcode, _L "Final combined packet not full, len %d" __L, p->size);
ReadyToSend.push(p);
BytesWritten += p->size;
p = nullptr;
}
Log.Out(Logs::Detail, Logs::Netcode, _L "Not retransmitting seq packet %d because already marked as acked" __L, seq_send);
Log(Logs::Detail, Logs::Netcode, _L "Not retransmitting seq packet %d because already marked as acked" __L, seq_send);
} else if (!p) {
// If we don't have a packet to try to combine into, use this one as the base
// Copy it first as it will still live until it is acked
p=(*sitr)->Copy();
Log.Out(Logs::Detail, Logs::Netcode, _L "Starting combined packet with seq packet %d of len %d" __L, seq_send, p->size);
Log(Logs::Detail, Logs::Netcode, _L "Starting combined packet with seq packet %d of len %d" __L, seq_send, p->size);
(*sitr)->sent_time = Timer::GetCurrentTime();
++sitr;
++count;
} else if (!p->combine(*sitr)) {
// Trying to combine this packet with the base didn't work (too big maybe)
// So just send the base packet (we'll try this packet again later)
Log.Out(Logs::Detail, Logs::Netcode, _L "Combined packet full at len %d, next seq packet %d is len %d" __L, p->size, seq_send + 1, (*sitr)->size);
Log(Logs::Detail, Logs::Netcode, _L "Combined packet full at len %d, next seq packet %d is len %d" __L, p->size, seq_send + 1, (*sitr)->size);
ReadyToSend.push(p);
BytesWritten+=p->size;
p=nullptr;
if ((*sitr)->opcode != OP_Fragment && BytesWritten > threshold) {
// Sent enough this round, lets stop to be fair
Log.Out(Logs::Detail, Logs::Netcode, _L "Exceeded write threshold in seq (%d > %d)" __L, BytesWritten, threshold);
Log(Logs::Detail, Logs::Netcode, _L "Exceeded write threshold in seq (%d > %d)" __L, BytesWritten, threshold);
break;
}
} else {
// Combine worked
Log.Out(Logs::Detail, Logs::Netcode, _L "Combined seq packet %d of len %d, yeilding %d combined." __L, seq_send, (*sitr)->size, p->size);
Log(Logs::Detail, Logs::Netcode, _L "Combined seq packet %d of len %d, yeilding %d combined." __L, seq_send, (*sitr)->size, p->size);
(*sitr)->sent_time = Timer::GetCurrentTime();
++sitr;
++count;
@@ -766,7 +766,7 @@ void EQStream::Write(int eq_fd)
++sitr;
++count;
if (p) {
Log.Out(Logs::Detail, Logs::Netcode, _L "Final combined packet not full, len %d" __L, p->size);
Log(Logs::Detail, Logs::Netcode, _L "Final combined packet not full, len %d" __L, p->size);
ReadyToSend.push(p);
BytesWritten += p->size;
p = nullptr;
@@ -776,25 +776,25 @@ void EQStream::Write(int eq_fd)
// Copy it first as it will still live until it is acked
p=(*sitr)->Copy();
(*sitr)->sent_time = Timer::GetCurrentTime();
Log.Out(Logs::Detail, Logs::Netcode, _L "Starting combined packet with seq packet %d of len %d" __L, seq_send, p->size);
Log(Logs::Detail, Logs::Netcode, _L "Starting combined packet with seq packet %d of len %d" __L, seq_send, p->size);
++sitr;
++count;
} else if (!p->combine(*sitr)) {
// Trying to combine this packet with the base didn't work (too big maybe)
// So just send the base packet (we'll try this packet again later)
Log.Out(Logs::Detail, Logs::Netcode, _L "Combined packet full at len %d, next seq packet %d is len %d" __L, p->size, seq_send, (*sitr)->size);
Log(Logs::Detail, Logs::Netcode, _L "Combined packet full at len %d, next seq packet %d is len %d" __L, p->size, seq_send, (*sitr)->size);
ReadyToSend.push(p);
BytesWritten+=p->size;
p=nullptr;
if (BytesWritten > threshold) {
// Sent enough this round, lets stop to be fair
Log.Out(Logs::Detail, Logs::Netcode, _L "Exceeded write threshold in seq (%d > %d)" __L, BytesWritten, threshold);
Log(Logs::Detail, Logs::Netcode, _L "Exceeded write threshold in seq (%d > %d)" __L, BytesWritten, threshold);
break;
}
} else {
// Combine worked
Log.Out(Logs::Detail, Logs::Netcode, _L "Combined seq packet %d of len %d, yielding %d combined." __L, seq_send, (*sitr)->size, p->size);
Log(Logs::Detail, Logs::Netcode, _L "Combined seq packet %d of len %d, yielding %d combined." __L, seq_send, (*sitr)->size, p->size);
(*sitr)->sent_time = Timer::GetCurrentTime();
++sitr;
++count;
@@ -802,7 +802,7 @@ void EQStream::Write(int eq_fd)
}
if(uint16(SequencedBase + SequencedQueue.size()) != NextOutSeq) {
Log.Out(Logs::Detail, Logs::Netcode, _L "Post send Invalid Sequenced queue: BS %d + SQ %d != NOS %d" __L, SequencedBase, SequencedQueue.size(), NextOutSeq);
Log(Logs::Detail, Logs::Netcode, _L "Post send Invalid Sequenced queue: BS %d + SQ %d != NOS %d" __L, SequencedBase, SequencedQueue.size(), NextOutSeq);
}
} else {
// No more sequenced packets
@@ -814,7 +814,7 @@ void EQStream::Write(int eq_fd)
// We have a packet still, must have run out of both seq and non-seq, so send it
if (p) {
Log.Out(Logs::Detail, Logs::Netcode, _L "Final combined packet not full, len %d" __L, p->size);
Log(Logs::Detail, Logs::Netcode, _L "Final combined packet not full, len %d" __L, p->size);
ReadyToSend.push(p);
BytesWritten+=p->size;
}
@@ -831,7 +831,7 @@ void EQStream::Write(int eq_fd)
if(SeqEmpty && NonSeqEmpty) {
//no more data to send
if(CheckState(CLOSING)) {
Log.Out(Logs::Detail, Logs::Netcode, _L "All outgoing data flushed, closing stream." __L );
Log(Logs::Detail, Logs::Netcode, _L "All outgoing data flushed, closing stream." __L );
//we are waiting for the queues to empty, now we can do our disconnect.
//this packet will not actually go out until the next call to Write().
_SendDisconnect();
@@ -896,7 +896,7 @@ void EQStream::SendSessionResponse()
out->size=sizeof(SessionResponse);
Log.Out(Logs::Detail, Logs::Netcode, _L "Sending OP_SessionResponse: session %lu, maxlen=%d, key=0x%x, compressed? %s, encoded? %s" __L,
Log(Logs::Detail, Logs::Netcode, _L "Sending OP_SessionResponse: session %lu, maxlen=%d, key=0x%x, compressed? %s, encoded? %s" __L,
(unsigned long)Session, MaxLen, Key, compressed?"yes":"no", encoded?"yes":"no");
NonSequencedPush(out);
@@ -910,7 +910,7 @@ void EQStream::SendSessionRequest()
Request->Session=htonl(time(nullptr));
Request->MaxLength=htonl(512);
Log.Out(Logs::Detail, Logs::Netcode, _L "Sending OP_SessionRequest: session %lu, maxlen=%d" __L, (unsigned long)ntohl(Request->Session), ntohl(Request->MaxLength));
Log(Logs::Detail, Logs::Netcode, _L "Sending OP_SessionRequest: session %lu, maxlen=%d" __L, (unsigned long)ntohl(Request->Session), ntohl(Request->MaxLength));
NonSequencedPush(out);
}
@@ -924,7 +924,7 @@ void EQStream::_SendDisconnect()
*(uint32 *)out->pBuffer=htonl(Session);
NonSequencedPush(out);
Log.Out(Logs::Detail, Logs::Netcode, _L "Sending OP_SessionDisconnect: session %lu" __L, (unsigned long)Session);
Log(Logs::Detail, Logs::Netcode, _L "Sending OP_SessionDisconnect: session %lu" __L, (unsigned long)Session);
}
void EQStream::InboundQueuePush(EQRawApplicationPacket *p)
@@ -950,7 +950,7 @@ EQRawApplicationPacket *p=nullptr;
if (OpMgr != nullptr && *OpMgr != nullptr) {
EmuOpcode emu_op = (*OpMgr)->EQToEmu(p->opcode);
if (emu_op == OP_Unknown) {
// Log.Out(Logs::General, Logs::Client_Server_Packet_Unhandled, "Unknown :: [%s - 0x%04x] [Size: %u] %s", OpcodeManager::EmuToName(p->GetOpcode()), p->opcode, p->Size(), DumpPacketToString(p).c_str());
// Log(Logs::General, Logs::Client_Server_Packet_Unhandled, "Unknown :: [%s - 0x%04x] [Size: %u] %s", OpcodeManager::EmuToName(p->GetOpcode()), p->opcode, p->Size(), DumpPacketToString(p).c_str());
}
p->SetOpcode(emu_op);
}
@@ -976,7 +976,7 @@ EQRawApplicationPacket *p=nullptr;
if(OpMgr != nullptr && *OpMgr != nullptr) {
EmuOpcode emu_op = (*OpMgr)->EQToEmu(p->opcode);
if(emu_op == OP_Unknown) {
Log.Out(Logs::General, Logs::Netcode, "Unable to convert EQ opcode 0x%.4x to an Application opcode.", p->opcode);
Log(Logs::General, Logs::Netcode, "Unable to convert EQ opcode 0x%.4x to an Application opcode.", p->opcode);
}
p->SetOpcode(emu_op);
@@ -1004,7 +1004,7 @@ void EQStream::InboundQueueClear()
{
EQApplicationPacket *p=nullptr;
Log.Out(Logs::Detail, Logs::Netcode, _L "Clearing inbound queue" __L);
Log(Logs::Detail, Logs::Netcode, _L "Clearing inbound queue" __L);
MInboundQueue.lock();
if (!InboundQueue.empty()) {
@@ -1047,7 +1047,7 @@ void EQStream::OutboundQueueClear()
{
EQProtocolPacket *p=nullptr;
Log.Out(Logs::Detail, Logs::Netcode, _L "Clearing outbound queue" __L);
Log(Logs::Detail, Logs::Netcode, _L "Clearing outbound queue" __L);
MOutboundQueue.lock();
while(!NonSequencedQueue.empty()) {
@@ -1069,7 +1069,7 @@ void EQStream::PacketQueueClear()
{
EQProtocolPacket *p=nullptr;
Log.Out(Logs::Detail, Logs::Netcode, _L "Clearing future packet queue" __L);
Log(Logs::Detail, Logs::Netcode, _L "Clearing future packet queue" __L);
if(!PacketQueue.empty()) {
std::map<unsigned short,EQProtocolPacket *>::iterator itr;
@@ -1101,7 +1101,7 @@ void EQStream::Process(const unsigned char *buffer, const uint32 length)
delete p;
ProcessQueue();
} else {
Log.Out(Logs::Detail, Logs::Netcode, _L "Incoming packet failed checksum" __L);
Log(Logs::Detail, Logs::Netcode, _L "Incoming packet failed checksum" __L);
}
}
@@ -1132,23 +1132,23 @@ std::deque<EQProtocolPacket *>::iterator itr, tmp;
SeqOrder ord = CompareSequence(SequencedBase, seq);
if(ord == SeqInOrder) {
//they are not acking anything new...
Log.Out(Logs::Detail, Logs::Netcode, _L "Received an ack with no window advancement (seq %d)." __L, seq);
Log(Logs::Detail, Logs::Netcode, _L "Received an ack with no window advancement (seq %d)." __L, seq);
} else if(ord == SeqPast) {
//they are nacking blocks going back before our buffer, wtf?
Log.Out(Logs::Detail, Logs::Netcode, _L "Received an ack with backward window advancement (they gave %d, our window starts at %d). This is bad." __L, seq, SequencedBase);
Log(Logs::Detail, Logs::Netcode, _L "Received an ack with backward window advancement (they gave %d, our window starts at %d). This is bad." __L, seq, SequencedBase);
} else {
Log.Out(Logs::Detail, Logs::Netcode, _L "Received an ack up through sequence %d. Our base is %d." __L, seq, SequencedBase);
Log(Logs::Detail, Logs::Netcode, _L "Received an ack up through sequence %d. Our base is %d." __L, seq, SequencedBase);
//this is a good ack, we get to ack some blocks.
seq++; //we stop at the block right after their ack, counting on the wrap of both numbers.
while(SequencedBase != seq) {
if(SequencedQueue.empty()) {
Log.Out(Logs::Detail, Logs::Netcode, _L "OUT OF PACKETS acked packet with sequence %lu. Next send is %d before this." __L, (unsigned long)SequencedBase, SequencedQueue.size());
Log(Logs::Detail, Logs::Netcode, _L "OUT OF PACKETS acked packet with sequence %lu. Next send is %d before this." __L, (unsigned long)SequencedBase, SequencedQueue.size());
SequencedBase = NextOutSeq;
break;
}
Log.Out(Logs::Detail, Logs::Netcode, _L "Removing acked packet with sequence %lu." __L, (unsigned long)SequencedBase);
Log(Logs::Detail, Logs::Netcode, _L "Removing acked packet with sequence %lu." __L, (unsigned long)SequencedBase);
//clean out the acked packet
delete SequencedQueue.front();
SequencedQueue.pop_front();
@@ -1156,7 +1156,7 @@ std::deque<EQProtocolPacket *>::iterator itr, tmp;
SequencedBase++;
}
if(uint16(SequencedBase + SequencedQueue.size()) != NextOutSeq) {
Log.Out(Logs::Detail, Logs::Netcode, _L "Post-Ack on %d Invalid Sequenced queue: BS %d + SQ %d != NOS %d" __L, seq, SequencedBase, SequencedQueue.size(), NextOutSeq);
Log(Logs::Detail, Logs::Netcode, _L "Post-Ack on %d Invalid Sequenced queue: BS %d + SQ %d != NOS %d" __L, seq, SequencedBase, SequencedQueue.size(), NextOutSeq);
}
}
@@ -1166,7 +1166,7 @@ std::deque<EQProtocolPacket *>::iterator itr, tmp;
void EQStream::SetNextAckToSend(uint32 seq)
{
MAcks.lock();
Log.Out(Logs::Detail, Logs::Netcode, _L "Set Next Ack To Send to %lu" __L, (unsigned long)seq);
Log(Logs::Detail, Logs::Netcode, _L "Set Next Ack To Send to %lu" __L, (unsigned long)seq);
NextAckToSend=seq;
MAcks.unlock();
}
@@ -1174,7 +1174,7 @@ void EQStream::SetNextAckToSend(uint32 seq)
void EQStream::SetLastAckSent(uint32 seq)
{
MAcks.lock();
Log.Out(Logs::Detail, Logs::Netcode, _L "Set Last Ack Sent to %lu" __L, (unsigned long)seq);
Log(Logs::Detail, Logs::Netcode, _L "Set Last Ack Sent to %lu" __L, (unsigned long)seq);
LastAckSent=seq;
MAcks.unlock();
}
@@ -1187,10 +1187,10 @@ void EQStream::ProcessQueue()
EQProtocolPacket *qp=nullptr;
while((qp=RemoveQueue(NextInSeq))!=nullptr) {
Log.Out(Logs::Detail, Logs::Netcode, _L "Processing Queued Packet: Seq=%d" __L, NextInSeq);
Log(Logs::Detail, Logs::Netcode, _L "Processing Queued Packet: Seq=%d" __L, NextInSeq);
ProcessPacket(qp);
delete qp;
Log.Out(Logs::Detail, Logs::Netcode, _L "OP_Packet Queue size=%d" __L, PacketQueue.size());
Log(Logs::Detail, Logs::Netcode, _L "OP_Packet Queue size=%d" __L, PacketQueue.size());
}
}
@@ -1201,21 +1201,21 @@ EQProtocolPacket *qp=nullptr;
if ((itr=PacketQueue.find(seq))!=PacketQueue.end()) {
qp=itr->second;
PacketQueue.erase(itr);
Log.Out(Logs::Detail, Logs::Netcode, _L "OP_Packet Queue size=%d" __L, PacketQueue.size());
Log(Logs::Detail, Logs::Netcode, _L "OP_Packet Queue size=%d" __L, PacketQueue.size());
}
return qp;
}
void EQStream::SetStreamType(EQStreamType type)
{
Log.Out(Logs::Detail, Logs::Netcode, _L "Changing stream type from %s to %s" __L, StreamTypeString(StreamType), StreamTypeString(type));
Log(Logs::Detail, Logs::Netcode, _L "Changing stream type from %s to %s" __L, StreamTypeString(StreamType), StreamTypeString(type));
StreamType=type;
switch (StreamType) {
case LoginStream:
app_opcode_size=1;
compressed=false;
encoded=false;
Log.Out(Logs::Detail, Logs::Netcode, _L "Login stream has app opcode size %d, is not compressed or encoded." __L, app_opcode_size);
Log(Logs::Detail, Logs::Netcode, _L "Login stream has app opcode size %d, is not compressed or encoded." __L, app_opcode_size);
break;
case ChatOrMailStream:
case ChatStream:
@@ -1223,7 +1223,7 @@ void EQStream::SetStreamType(EQStreamType type)
app_opcode_size=1;
compressed=false;
encoded=true;
Log.Out(Logs::Detail, Logs::Netcode, _L "Chat/Mail stream has app opcode size %d, is not compressed, and is encoded." __L, app_opcode_size);
Log(Logs::Detail, Logs::Netcode, _L "Chat/Mail stream has app opcode size %d, is not compressed, and is encoded." __L, app_opcode_size);
break;
case ZoneStream:
case WorldStream:
@@ -1231,7 +1231,7 @@ void EQStream::SetStreamType(EQStreamType type)
app_opcode_size=2;
compressed=true;
encoded=false;
Log.Out(Logs::Detail, Logs::Netcode, _L "World/Zone stream has app opcode size %d, is compressed, and is not encoded." __L, app_opcode_size);
Log(Logs::Detail, Logs::Netcode, _L "World/Zone stream has app opcode size %d, is compressed, and is not encoded." __L, app_opcode_size);
break;
}
}
@@ -1281,7 +1281,7 @@ EQStream::SeqOrder EQStream::CompareSequence(uint16 expected_seq , uint16 seq)
void EQStream::SetState(EQStreamState state) {
MState.lock();
Log.Out(Logs::Detail, Logs::Netcode, _L "Changing state from %d to %d" __L, State, state);
Log(Logs::Detail, Logs::Netcode, _L "Changing state from %d to %d" __L, State, state);
State=state;
MState.unlock();
}
@@ -1293,29 +1293,29 @@ void EQStream::CheckTimeout(uint32 now, uint32 timeout) {
EQStreamState orig_state = GetState();
if (orig_state == CLOSING && !outgoing_data) {
Log.Out(Logs::Detail, Logs::Netcode, _L "Out of data in closing state, disconnecting." __L);
Log(Logs::Detail, Logs::Netcode, _L "Out of data in closing state, disconnecting." __L);
_SendDisconnect();
SetState(DISCONNECTING);
} else if (LastPacket && (now-LastPacket) > timeout) {
switch(orig_state) {
case CLOSING:
//if we time out in the closing state, they are not acking us, just give up
Log.Out(Logs::Detail, Logs::Netcode, _L "Timeout expired in closing state. Moving to closed state." __L);
Log(Logs::Detail, Logs::Netcode, _L "Timeout expired in closing state. Moving to closed state." __L);
_SendDisconnect();
SetState(CLOSED);
break;
case DISCONNECTING:
//we timed out waiting for them to send us the disconnect reply, just give up.
Log.Out(Logs::Detail, Logs::Netcode, _L "Timeout expired in disconnecting state. Moving to closed state." __L);
Log(Logs::Detail, Logs::Netcode, _L "Timeout expired in disconnecting state. Moving to closed state." __L);
SetState(CLOSED);
break;
case CLOSED:
Log.Out(Logs::Detail, Logs::Netcode, _L "Timeout expired in closed state??" __L);
Log(Logs::Detail, Logs::Netcode, _L "Timeout expired in closed state??" __L);
break;
case ESTABLISHED:
//we timed out during normal operation. Try to be nice about it.
//we will almost certainly time out again waiting for the disconnect reply, but oh well.
Log.Out(Logs::Detail, Logs::Netcode, _L "Timeout expired in established state. Closing connection." __L);
Log(Logs::Detail, Logs::Netcode, _L "Timeout expired in established state. Closing connection." __L);
_SendDisconnect();
SetState(DISCONNECTING);
break;
@@ -1342,7 +1342,7 @@ void EQStream::Decay()
for (auto sitr = SequencedQueue.begin(); sitr != SequencedQueue.end(); ++sitr, count++) {
if (!(*sitr)->acked && (*sitr)->sent_time > 0 && ((*sitr)->sent_time + retransmittimeout) < Timer::GetCurrentTime()) {
(*sitr)->sent_time = 0;
Log.Out(Logs::Detail, Logs::Netcode, _L "Timeout exceeded for seq %d. Flagging packet for retransmission" __L, SequencedBase + count);
Log(Logs::Detail, Logs::Netcode, _L "Timeout exceeded for seq %d. Flagging packet for retransmission" __L, SequencedBase + count);
}
}
MOutboundQueue.unlock();
@@ -1359,11 +1359,11 @@ void EQStream::AdjustRates(uint32 average_delta)
DecayRate=DECAYBASE/average_delta;
if (BytesWritten > RateThreshold)
BytesWritten = RateThreshold + DecayRate;
Log.Out(Logs::Detail, Logs::Netcode, _L "Adjusting data rate to thresh %d, decay %d based on avg delta %d" __L,
Log(Logs::Detail, Logs::Netcode, _L "Adjusting data rate to thresh %d, decay %d based on avg delta %d" __L,
RateThreshold, DecayRate, average_delta);
MRate.unlock();
} else {
Log.Out(Logs::Detail, Logs::Netcode, _L "Not adjusting data rate because avg delta over max (%d > %d)" __L,
Log(Logs::Detail, Logs::Netcode, _L "Not adjusting data rate because avg delta over max (%d > %d)" __L,
average_delta, AVERAGE_DELTA_MAX);
AverageDelta = AVERAGE_DELTA_MAX;
}
@@ -1374,7 +1374,7 @@ void EQStream::AdjustRates(uint32 average_delta)
BytesWritten = 0;
RateThreshold=RATEBASE/average_delta;
DecayRate=DECAYBASE/average_delta;
Log.Out(Logs::Detail, Logs::Netcode, _L "Adjusting data rate to thresh %d, decay %d based on avg delta %d" __L,
Log(Logs::Detail, Logs::Netcode, _L "Adjusting data rate to thresh %d, decay %d based on avg delta %d" __L,
RateThreshold, DecayRate, average_delta);
MRate.unlock();
}
@@ -1384,12 +1384,12 @@ void EQStream::AdjustRates(uint32 average_delta)
void EQStream::Close() {
if(HasOutgoingData()) {
//there is pending data, wait for it to go out.
Log.Out(Logs::Detail, Logs::Netcode, _L "Stream requested to Close(), but there is pending data, waiting for it." __L);
Log(Logs::Detail, Logs::Netcode, _L "Stream requested to Close(), but there is pending data, waiting for it." __L);
SetState(CLOSING);
} else {
//otherwise, we are done, we can drop immediately.
_SendDisconnect();
Log.Out(Logs::Detail, Logs::Netcode, _L "Stream closing immediate due to Close()" __L);
Log(Logs::Detail, Logs::Netcode, _L "Stream closing immediate due to Close()" __L);
SetState(DISCONNECTING);
}
}
@@ -1417,19 +1417,19 @@ EQStream::MatchState EQStream::CheckSignature(const Signature *sig) {
} else if(p->opcode == sig->first_eq_opcode) {
//opcode matches, check length..
if(p->size == sig->first_length) {
Log.Out(Logs::General, Logs::Netcode, "[IDENT_TRACE] %s:%d: First opcode matched 0x%x and length matched %d", long2ip(GetRemoteIP()).c_str(), ntohs(GetRemotePort()), sig->first_eq_opcode, p->size);
Log(Logs::General, Logs::Netcode, "[IDENT_TRACE] %s:%d: First opcode matched 0x%x and length matched %d", long2ip(GetRemoteIP()).c_str(), ntohs(GetRemotePort()), sig->first_eq_opcode, p->size);
res = MatchSuccessful;
} else if(sig->first_length == 0) {
Log.Out(Logs::General, Logs::Netcode, "[IDENT_TRACE] %s:%d: First opcode matched 0x%x and length (%d) is ignored", long2ip(GetRemoteIP()).c_str(), ntohs(GetRemotePort()), sig->first_eq_opcode, p->size);
Log(Logs::General, Logs::Netcode, "[IDENT_TRACE] %s:%d: First opcode matched 0x%x and length (%d) is ignored", long2ip(GetRemoteIP()).c_str(), ntohs(GetRemotePort()), sig->first_eq_opcode, p->size);
res = MatchSuccessful;
} else {
//opcode matched but length did not.
Log.Out(Logs::General, Logs::Netcode, "[IDENT_TRACE] %s:%d: First opcode matched 0x%x, but length %d did not match expected %d", long2ip(GetRemoteIP()).c_str(), ntohs(GetRemotePort()), sig->first_eq_opcode, p->size, sig->first_length);
Log(Logs::General, Logs::Netcode, "[IDENT_TRACE] %s:%d: First opcode matched 0x%x, but length %d did not match expected %d", long2ip(GetRemoteIP()).c_str(), ntohs(GetRemotePort()), sig->first_eq_opcode, p->size, sig->first_length);
res = MatchFailed;
}
} else {
//first opcode did not match..
Log.Out(Logs::General, Logs::Netcode, "[IDENT_TRACE] %s:%d: First opcode 0x%x did not match expected 0x%x", long2ip(GetRemoteIP()).c_str(), ntohs(GetRemotePort()), p->opcode, sig->first_eq_opcode);
Log(Logs::General, Logs::Netcode, "[IDENT_TRACE] %s:%d: First opcode 0x%x did not match expected 0x%x", long2ip(GetRemoteIP()).c_str(), ntohs(GetRemotePort()), p->opcode, sig->first_eq_opcode);
res = MatchFailed;
}
}