diff --git a/common/eq_stream.cpp b/common/eq_stream.cpp index 96b816b1f..22ba69503 100644 --- a/common/eq_stream.cpp +++ b/common/eq_stream.cpp @@ -84,14 +84,14 @@ void EQStream::init(bool resetSession) { OpMgr = nullptr; if(uint16(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); + LogNetcode(_L "init Invalid Sequenced queue: BS [{}] + SQ [{}] != NOS [{}]" __L, SequencedBase, SequencedQueue.size(), NextOutSeq); } } EQRawApplicationPacket *EQStream::MakeApplicationPacket(EQProtocolPacket *p) { EQRawApplicationPacket *ap=nullptr; - Log(Logs::Detail, Logs::Netcode, _L "Creating new application packet, length %d" __L, p->size); + LogNetcode(_L "Creating new application packet, length [{}]" __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(Logs::Detail, Logs::Netcode, _L "Creating new application packet, length %d" __L, len); + LogNetcode(_L "Creating new application packet, length [{}]" __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(Logs::Detail, Logs::Netcode, _L "Session not initialized, packet ignored" __L); + LogNetcode(_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(Logs::Detail, Logs::Netcode, _L "Extracting combined packet of length %d" __L, subpacket_length); + LogNetcode(_L "Extracting combined packet of length [{}]" __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(processedsize) { EQRawApplicationPacket *ap=nullptr; if ((subpacket_length=(unsigned char)*(p->pBuffer+processed))!=0xff) { - Log(Logs::Detail, Logs::Netcode, _L "Extracting combined app packet of length %d, short len" __L, subpacket_length); + LogNetcode(_L "Extracting combined app packet of length [{}], 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(Logs::Detail, Logs::Netcode, _L "Extracting combined app packet of length %d, short len" __L, subpacket_length); + LogNetcode(_L "Extracting combined app packet of length [{}], 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(Logs::Detail, Logs::Netcode, _L "Received OP_Packet that was of malformed size" __L); + LogNetcode(_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(Logs::Detail, Logs::Netcode, _L "Future OP_Packet: Expecting Seq=%d, but got Seq=%d" __L, NextInSeq, seq); + LogNetcode(_L "Future OP_Packet: Expecting Seq=[{}], but got Seq=[{}]" __L, NextInSeq, seq); // _raw(NET__DEBUG, seq, p); PacketQueue[seq]=p->Copy(); - Log(Logs::Detail, Logs::Netcode, _L "OP_Packet Queue size=%d" __L, PacketQueue.size()); + LogNetcode(_L "OP_Packet Queue size=[{}]" __L, PacketQueue.size()); //SendOutOfOrderAck(seq); } else if (check == SeqPast) { - Log(Logs::Detail, Logs::Netcode, _L "Duplicate OP_Packet: Expecting Seq=%d, but got Seq=%d" __L, NextInSeq, seq); + LogNetcode(_L "Duplicate OP_Packet: Expecting Seq=[{}], but got Seq=[{}]" __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(Logs::General, Logs::Netcode, "[NET_TRACE] OP_Packet: Removing older queued packet with sequence %d", seq); + LogNetcode("[NET_TRACE] OP_Packet: Removing older queued packet with sequence [{}]", 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(Logs::Detail, Logs::Netcode, _L "seq %d, Extracting combined packet of length %d" __L, seq, subp->size); + LogNetcode(_L "seq [{}], Extracting combined packet of length [{}]" __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(Logs::Detail, Logs::Netcode, _L "Received OP_Fragment that was of malformed size" __L); + LogNetcode(_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(Logs::Detail, Logs::Netcode, _L "Future OP_Fragment: Expecting Seq=%d, but got Seq=%d" __L, NextInSeq, seq); + LogNetcode(_L "Future OP_Fragment: Expecting Seq=[{}], but got Seq=[{}]" __L, NextInSeq, seq); // _raw(NET__DEBUG, seq, p); PacketQueue[seq]=p->Copy(); - Log(Logs::Detail, Logs::Netcode, _L "OP_Fragment Queue size=%d" __L, PacketQueue.size()); + LogNetcode(_L "OP_Fragment Queue size=[{}]" __L, PacketQueue.size()); //SendOutOfOrderAck(seq); } else if (check == SeqPast) { - Log(Logs::Detail, Logs::Netcode, _L "Duplicate OP_Fragment: Expecting Seq=%d, but got Seq=%d" __L, NextInSeq, seq); + LogNetcode(_L "Duplicate OP_Fragment: Expecting Seq=[{}], but got Seq=[{}]" __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(Logs::General, Logs::Netcode, "[NET_TRACE] OP_Fragment: Removing older queued packet with sequence %d", seq); + LogNetcode("[NET_TRACE] OP_Fragment: Removing older queued packet with sequence [{}]", 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(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); + LogNetcode(_L "Fragment of oversized of length [{}], seq [{}]: now at [{}]/[{}]" __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(Logs::Detail, Logs::Netcode, _L "seq %d, Extracting combined oversize packet of length %d" __L, seq, subp->size); + LogNetcode(_L "seq [{}], Extracting combined oversize packet of length [{}]" __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(Logs::Detail, Logs::Netcode, _L "seq %d, completed combined oversize packet of length %d" __L, seq, ap->size); + LogNetcode(_L "seq [{}], completed combined oversize packet of length [{}]" __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(Logs::Detail, Logs::Netcode, _L "First fragment of oversized of seq %d: now at %d/%d" __L, seq, oversize_offset, oversize_length); + LogNetcode(_L "First fragment of oversized of seq [{}]: now at [{}]/[{}]" __L, seq, oversize_offset, oversize_length); } } } break; case OP_KeepAlive: { NonSequencedPush(new EQProtocolPacket(p->opcode,p->pBuffer,p->size)); - Log(Logs::Detail, Logs::Netcode, _L "Received and queued reply to keep alive" __L); + LogNetcode(_L "Received and queued reply to keep alive" __L); } break; case OP_Ack: { if(!p->pBuffer || (p->Size() < 4)) { - Log(Logs::Detail, Logs::Netcode, _L "Received OP_Ack that was of malformed size" __L); + LogNetcode(_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(Logs::Detail, Logs::Netcode, _L "Received OP_SessionRequest that was of malformed size" __L); + LogNetcode(_L "Received OP_SessionRequest that was of malformed size" __L); break; } if (GetState()==ESTABLISHED) { - Log(Logs::Detail, Logs::Netcode, _L "Received OP_SessionRequest in ESTABLISHED state (%d) streamactive (%i) attempt (%i)" __L, GetState(),streamactive,sessionAttempts); + LogNetcode(_L "Received OP_SessionRequest in ESTABLISHED state ([{}]) streamactive ([{}]) attempt ([{}])" __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(Logs::Detail, Logs::Netcode, _L "Received OP_SessionRequest: session %lu, maxlen %d" __L, (unsigned long)Session, MaxLen); + LogNetcode(_L "Received OP_SessionRequest: session [{}], maxlen [{}]" __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(Logs::Detail, Logs::Netcode, _L "Received OP_SessionResponse that was of malformed size" __L); + LogNetcode(_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(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"); + LogNetcode(_L "Received OP_SessionResponse: session [{}], maxlen [{}], key [{}], compressed? [{}], encoded? [{}]" __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(Logs::Detail, Logs::Netcode, _L "Received unsolicited OP_SessionDisconnect. Treating like a client-initiated disconnect." __L); + LogNetcode(_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(Logs::Detail, Logs::Netcode, _L "Received OP_SessionDisconnect when we have a pending close, they beat us to it. Were happy though." __L); + LogNetcode(_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(Logs::Detail, Logs::Netcode, _L "Received expected OP_SessionDisconnect. Moving to closed state." __L); + LogNetcode(_L "Received expected OP_SessionDisconnect. Moving to closed state" __L); SetState(CLOSED); } } @@ -397,14 +397,14 @@ void EQStream::ProcessPacket(EQProtocolPacket *p) case OP_OutOfOrderAck: { if(!p->pBuffer || (p->Size() < 4)) { - Log(Logs::Detail, Logs::Netcode, _L "Received OP_OutOfOrderAck that was of malformed size" __L); + LogNetcode(_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(Logs::Detail, Logs::Netcode, _L "Pre-OOA Invalid Sequenced queue: BS %d + SQ %d != NOS %d" __L, SequencedBase, SequencedQueue.size(), NextOutSeq); + LogNetcode(_L "Pre-OOA Invalid Sequenced queue: BS [{}] + SQ [{}] != NOS [{}]" __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. @@ -414,7 +414,7 @@ void EQStream::ProcessPacket(EQProtocolPacket *p) uint16 sqsize = SequencedQueue.size(); uint16 index = seq - SequencedBase; - Log(Logs::Detail, Logs::Netcode, _L "OP_OutOfOrderAck marking packet acked in queue (queue index = %d, queue size = %d)." __L, index, sqsize); + LogNetcode(_L "OP_OutOfOrderAck marking packet acked in queue (queue index = [{}], queue size = [{}])" __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(Logs::Detail, Logs::Netcode, _L "OP_OutOfOrderAck Flagging packet %d for retransmission" __L, SequencedBase + count); + LogNetcode(_L "OP_OutOfOrderAck Flagging packet [{}] for retransmission" __L, SequencedBase + count); } } } @@ -432,11 +432,11 @@ void EQStream::ProcessPacket(EQProtocolPacket *p) retransmittimer = Timer::GetCurrentTime(); } } else { - Log(Logs::Detail, Logs::Netcode, _L "Received OP_OutOfOrderAck for out-of-window %d. Window (%d->%d)." __L, seq, SequencedBase, NextOutSeq); + LogNetcode(_L "Received OP_OutOfOrderAck for out-of-window [{}]. Window ([{}]->[{}])" __L, seq, SequencedBase, NextOutSeq); } if(uint16(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); + LogNetcode(_L "Post-OOA Invalid Sequenced queue: BS [{}] + SQ [{}] != NOS [{}]" __L, SequencedBase, SequencedQueue.size(), NextOutSeq); } MOutboundQueue.unlock(); @@ -445,7 +445,7 @@ void EQStream::ProcessPacket(EQProtocolPacket *p) case OP_SessionStatRequest: { if(p->Size() < sizeof(ClientSessionStats)) { - Log(Logs::Detail, Logs::Netcode, _L "Received OP_SessionStatRequest that was of malformed size" __L); + LogNetcode(_L "Received OP_SessionStatRequest that was of malformed size" __L); break; } ClientSessionStats *ClientStats=(ClientSessionStats *)p->pBuffer; @@ -468,7 +468,7 @@ void EQStream::ProcessPacket(EQProtocolPacket *p) retransmittimeout += 300; if(retransmittimeout > RETRANSMIT_TIMEOUT_MAX) retransmittimeout = RETRANSMIT_TIMEOUT_MAX; - Log(Logs::Detail, Logs::Netcode, _L "Retransmit timeout recalculated to %dms" __L, retransmittimeout); + LogNetcode(_L "Retransmit timeout recalculated to [{}]ms" __L, retransmittimeout); } } @@ -485,11 +485,11 @@ void EQStream::ProcessPacket(EQProtocolPacket *p) } break; case OP_SessionStatResponse: { - Log(Logs::Detail, Logs::Netcode, _L "Received OP_SessionStatResponse. Ignoring." __L); + LogNetcode(_L "Received OP_SessionStatResponse. Ignoring" __L); } break; case OP_OutOfSession: { - Log(Logs::Detail, Logs::Netcode, _L "Received OP_OutOfSession. Ignoring." __L); + LogNetcode(_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(Logs::Detail, Logs::Netcode, _L "Packet enqueued into a stream with no opcode manager, dropping." __L); + LogNetcode(_L "Packet enqueued into a stream with no opcode manager, dropping" __L); delete pack; return; } @@ -559,18 +559,18 @@ void EQStream::SendPacket(uint16 opcode, EQApplicationPacket *p) // 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(Logs::Detail, Logs::Netcode, _L "Making oversized packet, len %d" __L, p->Size()); + LogNetcode(_L "Making oversized packet, len [{}]" __L, p->Size()); auto tmpbuff = new unsigned char[p->size + 3]; length=p->serialize(opcode, tmpbuff); if (length != p->Size()) - Log(Logs::Detail, Logs::Netcode, _L "Packet adjustment, len %d to %d" __L, p->Size(), length); + LogNetcode(_L "Packet adjustment, len [{}] to [{}]" __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(Logs::Detail, Logs::Netcode, _L "First fragment: used %d/%d. Payload size %d in the packet" __L, used, length, p->size); + LogNetcode(_L "First fragment: used [{}]/[{}]. Payload size [{}] 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(Logs::Detail, Logs::Netcode, _L "Subsequent fragment: len %d, used %d/%d." __L, chunksize, used, length); + LogNetcode(_L "Subsequent fragment: len [{}], used [{}]/[{}]" __L, chunksize, used, length); } delete p; delete[] tmpbuff; @@ -623,7 +623,7 @@ void EQStream::SequencedPush(EQProtocolPacket *p) void EQStream::NonSequencedPush(EQProtocolPacket *p) { MOutboundQueue.lock(); - Log(Logs::Detail, Logs::Netcode, _L "Pushing non-sequenced packet of length %d" __L, p->size); + LogNetcode(_L "Pushing non-sequenced packet of length [{}]" __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(Logs::Detail, Logs::Netcode, _L "Sending ack with sequence %d" __L, seq); + LogNetcode(_L "Sending ack with sequence [{}]" __L, seq); SetLastAckSent(seq); NonSequencedPush(new EQProtocolPacket(OP_Ack,(unsigned char *)&Seq,sizeof(uint16))); } void EQStream::SendOutOfOrderAck(uint16 seq) { - Log(Logs::Detail, Logs::Netcode, _L "Sending out of order ack with sequence %d" __L, seq); + LogNetcode(_L "Sending out of order ack with sequence [{}]" __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(Logs::Detail, Logs::Netcode, _L "Starting combined packet with non-seq packet of len %d" __L, p->size); + LogNetcode(_L "Starting combined packet with non-seq packet of len [{}]" __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(Logs::Detail, Logs::Netcode, _L "Combined packet full at len %d, next non-seq packet is len %d" __L, p->size, (NonSequencedQueue.front())->size); + LogNetcode(_L "Combined packet full at len [{}], next non-seq packet is len [{}]" __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(Logs::Detail, Logs::Netcode, _L "Exceeded write threshold in nonseq (%d > %d)" __L, BytesWritten, threshold); + LogNetcode(_L "Exceeded write threshold in nonseq ([{}] > [{}])" __L, BytesWritten, threshold); break; } } else { // Combine worked, so just remove this packet and it's spot in the queue - Log(Logs::Detail, Logs::Netcode, _L "Combined non-seq packet of len %d, yeilding %d combined." __L, (NonSequencedQueue.front())->size, p->size); + LogNetcode(_L "Combined non-seq packet of len [{}], yeilding [{}] 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(Logs::Detail, Logs::Netcode, _L "Tried to write a packet with an empty queue (%d is past next out %d)" __L, seq_send, NextOutSeq); + LogNetcode(_L "Tried to write a packet with an empty queue ([{}] is past next out [{}])" __L, seq_send, NextOutSeq); SeqEmpty=true; continue; } @@ -728,35 +728,35 @@ void EQStream::Write(int eq_fd) ++sitr; ++count; if (p) { - Log(Logs::Detail, Logs::Netcode, _L "Final combined packet not full, len %d" __L, p->size); + LogNetcode(_L "Final combined packet not full, len [{}]" __L, p->size); ReadyToSend.push(p); BytesWritten += p->size; p = nullptr; } - Log(Logs::Detail, Logs::Netcode, _L "Not retransmitting seq packet %d because already marked as acked" __L, seq_send); + LogNetcode(_L "Not retransmitting seq packet [{}] 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(Logs::Detail, Logs::Netcode, _L "Starting combined packet with seq packet %d of len %d" __L, seq_send, p->size); + LogNetcode(_L "Starting combined packet with seq packet [{}] of len [{}]" __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(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); + LogNetcode(_L "Combined packet full at len [{}], next seq packet [{}] is len [{}]" __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(Logs::Detail, Logs::Netcode, _L "Exceeded write threshold in seq (%d > %d)" __L, BytesWritten, threshold); + LogNetcode(_L "Exceeded write threshold in seq ([{}] > [{}])" __L, BytesWritten, threshold); break; } } else { // Combine worked - Log(Logs::Detail, Logs::Netcode, _L "Combined seq packet %d of len %d, yeilding %d combined." __L, seq_send, (*sitr)->size, p->size); + LogNetcode(_L "Combined seq packet [{}] of len [{}], yeilding [{}] 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(Logs::Detail, Logs::Netcode, _L "Final combined packet not full, len %d" __L, p->size); + LogNetcode(_L "Final combined packet not full, len [{}]" __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(Logs::Detail, Logs::Netcode, _L "Starting combined packet with seq packet %d of len %d" __L, seq_send, p->size); + LogNetcode(_L "Starting combined packet with seq packet [{}] of len [{}]" __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(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); + LogNetcode(_L "Combined packet full at len [{}], next seq packet [{}] is len [{}]" __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(Logs::Detail, Logs::Netcode, _L "Exceeded write threshold in seq (%d > %d)" __L, BytesWritten, threshold); + LogNetcode(_L "Exceeded write threshold in seq ([{}] > [{}])" __L, BytesWritten, threshold); break; } } else { // Combine worked - Log(Logs::Detail, Logs::Netcode, _L "Combined seq packet %d of len %d, yielding %d combined." __L, seq_send, (*sitr)->size, p->size); + LogNetcode(_L "Combined seq packet [{}] of len [{}], yielding [{}] 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(Logs::Detail, Logs::Netcode, _L "Post send Invalid Sequenced queue: BS %d + SQ %d != NOS %d" __L, SequencedBase, SequencedQueue.size(), NextOutSeq); + LogNetcode(_L "Post send Invalid Sequenced queue: BS [{}] + SQ [{}] != NOS [{}]" __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(Logs::Detail, Logs::Netcode, _L "Final combined packet not full, len %d" __L, p->size); + LogNetcode(_L "Final combined packet not full, len [{}]" __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(Logs::Detail, Logs::Netcode, _L "All outgoing data flushed, closing stream." __L ); + LogNetcode(_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(); @@ -910,7 +910,7 @@ void EQStream::SendSessionRequest() Request->Session=htonl(time(nullptr)); Request->MaxLength=htonl(512); - Log(Logs::Detail, Logs::Netcode, _L "Sending OP_SessionRequest: session %lu, maxlen=%d" __L, (unsigned long)ntohl(Request->Session), ntohl(Request->MaxLength)); + LogNetcode(_L "Sending OP_SessionRequest: session [{}], maxlen=[{}]" __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(Logs::Detail, Logs::Netcode, _L "Sending OP_SessionDisconnect: session %lu" __L, (unsigned long)Session); + LogNetcode(_L "Sending OP_SessionDisconnect: session [{}]" __L, (unsigned long)Session); } void EQStream::InboundQueuePush(EQRawApplicationPacket *p) @@ -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(Logs::General, Logs::Netcode, "Unable to convert EQ opcode 0x%.4x to an Application opcode.", p->opcode); + LogNetcode("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(Logs::Detail, Logs::Netcode, _L "Clearing inbound queue" __L); + LogNetcode(_L "Clearing inbound queue" __L); MInboundQueue.lock(); if (!InboundQueue.empty()) { @@ -1047,7 +1047,7 @@ void EQStream::OutboundQueueClear() { EQProtocolPacket *p=nullptr; - Log(Logs::Detail, Logs::Netcode, _L "Clearing outbound queue" __L); + LogNetcode(_L "Clearing outbound queue" __L); MOutboundQueue.lock(); while(!NonSequencedQueue.empty()) { @@ -1069,7 +1069,7 @@ void EQStream::PacketQueueClear() { EQProtocolPacket *p=nullptr; - Log(Logs::Detail, Logs::Netcode, _L "Clearing future packet queue" __L); + LogNetcode(_L "Clearing future packet queue" __L); if(!PacketQueue.empty()) { std::map::iterator itr; @@ -1101,7 +1101,7 @@ void EQStream::Process(const unsigned char *buffer, const uint32 length) delete p; ProcessQueue(); } else { - Log(Logs::Detail, Logs::Netcode, _L "Incoming packet failed checksum" __L); + LogNetcode(_L "Incoming packet failed checksum" __L); } } @@ -1132,23 +1132,23 @@ std::deque::iterator itr, tmp; SeqOrder ord = CompareSequence(SequencedBase, seq); if(ord == SeqInOrder) { //they are not acking anything new... - Log(Logs::Detail, Logs::Netcode, _L "Received an ack with no window advancement (seq %d)." __L, seq); + LogNetcode(_L "Received an ack with no window advancement (seq [{}])" __L, seq); } else if(ord == SeqPast) { //they are nacking blocks going back before our buffer, wtf? - 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); + LogNetcode(_L "Received an ack with backward window advancement (they gave [{}], our window starts at [{}]). This is bad" __L, seq, SequencedBase); } else { - Log(Logs::Detail, Logs::Netcode, _L "Received an ack up through sequence %d. Our base is %d." __L, seq, SequencedBase); + LogNetcode(_L "Received an ack up through sequence [{}]. Our base is [{}]" __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(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()); + LogNetcode(_L "OUT OF PACKETS acked packet with sequence [{}]. Next send is [{}] before this" __L, (unsigned long)SequencedBase, SequencedQueue.size()); SequencedBase = NextOutSeq; break; } - Log(Logs::Detail, Logs::Netcode, _L "Removing acked packet with sequence %lu." __L, (unsigned long)SequencedBase); + LogNetcode(_L "Removing acked packet with sequence [{}]" __L, (unsigned long)SequencedBase); //clean out the acked packet delete SequencedQueue.front(); SequencedQueue.pop_front(); @@ -1156,7 +1156,7 @@ std::deque::iterator itr, tmp; SequencedBase++; } if(uint16(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); + LogNetcode(_L "Post-Ack on [{}] Invalid Sequenced queue: BS [{}] + SQ [{}] != NOS [{}]" __L, seq, SequencedBase, SequencedQueue.size(), NextOutSeq); } } @@ -1166,7 +1166,7 @@ std::deque::iterator itr, tmp; void EQStream::SetNextAckToSend(uint32 seq) { MAcks.lock(); - Log(Logs::Detail, Logs::Netcode, _L "Set Next Ack To Send to %lu" __L, (unsigned long)seq); + LogNetcode(_L "Set Next Ack To Send to [{}]" __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(Logs::Detail, Logs::Netcode, _L "Set Last Ack Sent to %lu" __L, (unsigned long)seq); + LogNetcode(_L "Set Last Ack Sent to [{}]" __L, (unsigned long)seq); LastAckSent=seq; MAcks.unlock(); } @@ -1187,10 +1187,10 @@ void EQStream::ProcessQueue() EQProtocolPacket *qp=nullptr; while((qp=RemoveQueue(NextInSeq))!=nullptr) { - Log(Logs::Detail, Logs::Netcode, _L "Processing Queued Packet: Seq=%d" __L, NextInSeq); + LogNetcode(_L "Processing Queued Packet: Seq=[{}]" __L, NextInSeq); ProcessPacket(qp); delete qp; - Log(Logs::Detail, Logs::Netcode, _L "OP_Packet Queue size=%d" __L, PacketQueue.size()); + LogNetcode(_L "OP_Packet Queue size=[{}]" __L, PacketQueue.size()); } } @@ -1201,21 +1201,21 @@ EQProtocolPacket *qp=nullptr; if ((itr=PacketQueue.find(seq))!=PacketQueue.end()) { qp=itr->second; PacketQueue.erase(itr); - Log(Logs::Detail, Logs::Netcode, _L "OP_Packet Queue size=%d" __L, PacketQueue.size()); + LogNetcode(_L "OP_Packet Queue size=[{}]" __L, PacketQueue.size()); } return qp; } void EQStream::SetStreamType(EQStreamType type) { - Log(Logs::Detail, Logs::Netcode, _L "Changing stream type from %s to %s" __L, StreamTypeString(StreamType), StreamTypeString(type)); + LogNetcode(_L "Changing stream type from [{}] to [{}]" __L, StreamTypeString(StreamType), StreamTypeString(type)); StreamType=type; switch (StreamType) { case LoginStream: app_opcode_size=1; compressed=false; encoded=false; - Log(Logs::Detail, Logs::Netcode, _L "Login stream has app opcode size %d, is not compressed or encoded." __L, app_opcode_size); + LogNetcode(_L "Login stream has app opcode size [{}], 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(Logs::Detail, Logs::Netcode, _L "Chat/Mail stream has app opcode size %d, is not compressed, and is encoded." __L, app_opcode_size); + LogNetcode(_L "Chat/Mail stream has app opcode size [{}], 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(Logs::Detail, Logs::Netcode, _L "World/Zone stream has app opcode size %d, is compressed, and is not encoded." __L, app_opcode_size); + LogNetcode(_L "World/Zone stream has app opcode size [{}], 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(Logs::Detail, Logs::Netcode, _L "Changing state from %d to %d" __L, State, state); + LogNetcode(_L "Changing state from [{}] to [{}]" __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(Logs::Detail, Logs::Netcode, _L "Out of data in closing state, disconnecting." __L); + LogNetcode(_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(Logs::Detail, Logs::Netcode, _L "Timeout expired in closing state. Moving to closed state." __L); + LogNetcode(_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(Logs::Detail, Logs::Netcode, _L "Timeout expired in disconnecting state. Moving to closed state." __L); + LogNetcode(_L "Timeout expired in disconnecting state. Moving to closed state" __L); SetState(CLOSED); break; case CLOSED: - Log(Logs::Detail, Logs::Netcode, _L "Timeout expired in closed state??" __L); + LogNetcode(_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(Logs::Detail, Logs::Netcode, _L "Timeout expired in established state. Closing connection." __L); + LogNetcode(_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(Logs::Detail, Logs::Netcode, _L "Timeout exceeded for seq %d. Flagging packet for retransmission" __L, SequencedBase + count); + LogNetcode(_L "Timeout exceeded for seq [{}]. Flagging packet for retransmission" __L, SequencedBase + count); } } MOutboundQueue.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(Logs::Detail, Logs::Netcode, _L "Stream requested to Close(), but there is pending data, waiting for it." __L); + LogNetcode(_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(Logs::Detail, Logs::Netcode, _L "Stream closing immediate due to Close()" __L); + LogNetcode(_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(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); + LogNetcode("[StreamIdentify] [{}]:[{}]: First opcode matched 0x%x and length matched [{}]", long2ip(GetRemoteIP()).c_str(), ntohs(GetRemotePort()), sig->first_eq_opcode, p->size); res = MatchSuccessful; } else if(sig->first_length == 0) { - 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); + LogNetcode("[StreamIdentify] [{}]:[{}]: First opcode matched 0x%x and length ([{}]) is ignored", long2ip(GetRemoteIP()).c_str(), ntohs(GetRemotePort()), sig->first_eq_opcode, p->size); res = MatchSuccessful; } else { //opcode matched but length did not. - 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); + LogNetcode("[StreamIdentify] [{}]:[{}]: First opcode matched 0x%x, but length [{}] did not match expected [{}]", long2ip(GetRemoteIP()).c_str(), ntohs(GetRemotePort()), sig->first_eq_opcode, p->size, sig->first_length); res = MatchFailed; } } else { //first opcode did not match.. - 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); + LogNetcode("[StreamIdentify] [{}]:[{}]: First opcode 0x%x did not match expected 0x%x", long2ip(GetRemoteIP()).c_str(), ntohs(GetRemotePort()), p->opcode, sig->first_eq_opcode); res = MatchFailed; } } diff --git a/common/eq_stream_ident.cpp b/common/eq_stream_ident.cpp index 5706bbced..58308384f 100644 --- a/common/eq_stream_ident.cpp +++ b/common/eq_stream_ident.cpp @@ -46,7 +46,7 @@ void EQStreamIdentifier::Process() { //first see if this stream has expired if(r.expire.Check(false)) { - Log(Logs::General, Logs::Netcode, "[IDENTIFY] Unable to identify stream from %s:%d before timeout.", r.stream->GetRemoteAddr().c_str(), ntohs(r.stream->GetRemotePort())); + LogNetcode("[StreamIdentify] Unable to identify stream from [{}:{}] before timeout", r.stream->GetRemoteAddr().c_str(), ntohs(r.stream->GetRemotePort())); r.stream->Close(); cur = m_streams.erase(cur); @@ -62,23 +62,23 @@ void EQStreamIdentifier::Process() { } if(r.stream->GetState() != ESTABLISHED) { //the stream closed before it was identified. - Log(Logs::General, Logs::Netcode, "[IDENTIFY] Unable to identify stream from %s:%d before it closed.", long2ip(r.stream->GetRemoteIP()).c_str(), ntohs(r.stream->GetRemotePort())); + LogNetcode("[StreamIdentify] Unable to identify stream from [{}:{}] before it closed", long2ip(r.stream->GetRemoteIP()).c_str(), ntohs(r.stream->GetRemotePort())); switch(r.stream->GetState()) { case ESTABLISHED: - Log(Logs::General, Logs::Netcode, "[IDENTIFY] Stream state was Established"); + LogNetcode("[StreamIdentify] Stream state was Established"); break; case CLOSING: - Log(Logs::General, Logs::Netcode, "[IDENTIFY] Stream state was Closing"); + LogNetcode("[StreamIdentify] Stream state was Closing"); break; case DISCONNECTING: - Log(Logs::General, Logs::Netcode, "[IDENTIFY] Stream state was Disconnecting"); + LogNetcode("[StreamIdentify] Stream state was Disconnecting"); break; case CLOSED: - Log(Logs::General, Logs::Netcode, "[IDENTIFY] Stream state was Closed"); + LogNetcode("[StreamIdentify] Stream state was Closed"); break; default: - Log(Logs::General, Logs::Netcode, "[IDENTIFY] Stream state was Unestablished or unknown"); + LogNetcode("[StreamIdentify] Stream state was Unestablished or unknown"); break; } r.stream->ReleaseFromUse(); @@ -102,13 +102,13 @@ void EQStreamIdentifier::Process() { switch(res) { case EQStreamInterface::MatchNotReady: //the stream has not received enough packets to compare with this signature -// Log.LogDebugType(Logs::General, Logs::Netcode, "[IDENT_TRACE] %s:%d: Tried patch %s, but stream is not ready for it.", long2ip(r.stream->GetRemoteIP()).c_str(), ntohs(r.stream->GetRemotePort()), p->name.c_str()); +// Log.LogDebugType(Logs::General, Logs::Netcode, "[StreamIdentify] %s:%d: Tried patch %s, but stream is not ready for it.", long2ip(r.stream->GetRemoteIP()).c_str(), ntohs(r.stream->GetRemotePort()), p->name.c_str()); all_ready = false; break; case EQStreamInterface::MatchSuccessful: { //yay, a match. - Log(Logs::General, Logs::Netcode, "[IDENTIFY] Identified stream %s:%d with signature %s", long2ip(r.stream->GetRemoteIP()).c_str(), ntohs(r.stream->GetRemotePort()), p->name.c_str()); + LogNetcode("[StreamIdentify] Identified stream [{}:{}] with signature [{}]", long2ip(r.stream->GetRemoteIP()).c_str(), ntohs(r.stream->GetRemotePort()), p->name.c_str()); // before we assign the eqstream to an interface, let the stream recognize it is in use and the session should not be reset any further r.stream->SetActive(true); @@ -122,7 +122,7 @@ void EQStreamIdentifier::Process() { } case EQStreamInterface::MatchFailed: //do nothing... - Log(Logs::General, Logs::Netcode, "[IDENT_TRACE] %s:%d: Tried patch %s, and it did not match.", long2ip(r.stream->GetRemoteIP()).c_str(), ntohs(r.stream->GetRemotePort()), p->name.c_str()); + LogNetcode("[StreamIdentify] [{}:{}]: Tried patch [{}] and it did not match", long2ip(r.stream->GetRemoteIP()).c_str(), ntohs(r.stream->GetRemotePort()), p->name.c_str()); break; } } @@ -130,7 +130,7 @@ void EQStreamIdentifier::Process() { //if we checked all patches and did not find a match. if(all_ready && !found_one) { //the stream cannot be identified. - Log(Logs::General, Logs::Netcode, "[IDENTIFY] Unable to identify stream from %s:%d, no match found.", long2ip(r.stream->GetRemoteIP()).c_str(), ntohs(r.stream->GetRemotePort())); + LogNetcode("[StreamIdentify] Unable to identify stream from [{}:{}], no match found", long2ip(r.stream->GetRemoteIP()).c_str(), ntohs(r.stream->GetRemotePort())); r.stream->ReleaseFromUse(); } diff --git a/common/misc_functions.h b/common/misc_functions.h index 4f295c68a..62a6745c1 100644 --- a/common/misc_functions.h +++ b/common/misc_functions.h @@ -40,7 +40,7 @@ #define VERIFY_PACKET_LENGTH(OPCode, Packet, StructName) \ if(Packet->size != sizeof(StructName)) \ { \ - Log(Logs::Detail, Logs::Netcode, "Size mismatch in " #OPCode " expected %i got %i", sizeof(StructName), Packet->size); \ + LogNetcode("Size mismatch in " #OPCode " expected [{}] got [{}]", sizeof(StructName), Packet->size); \ DumpPacket(Packet); \ return; \ } diff --git a/common/net/eqstream.cpp b/common/net/eqstream.cpp index cb0bbe087..368a23931 100644 --- a/common/net/eqstream.cpp +++ b/common/net/eqstream.cpp @@ -184,23 +184,23 @@ EQStreamInterface::MatchState EQ::Net::EQStream::CheckSignature(const Signature if (opcode == sig->first_eq_opcode) { if (length == sig->first_length) { - LogF(Logs::General, Logs::Netcode, "[IDENT_TRACE] {0}:{1}: First opcode matched {2:#x} and length matched {3}", + LogF(Logs::General, Logs::Netcode, "[StreamIdentify] {0}:{1}: First opcode matched {2:#x} and length matched {3}", m_connection->RemoteEndpoint(), m_connection->RemotePort(), sig->first_eq_opcode, length); return MatchSuccessful; } else if (length == 0) { - LogF(Logs::General, Logs::Netcode, "[IDENT_TRACE] {0}:{1}: First opcode matched {2:#x} and length is ignored.", + LogF(Logs::General, Logs::Netcode, "[StreamIdentify] {0}:{1}: First opcode matched {2:#x} and length is ignored.", m_connection->RemoteEndpoint(), m_connection->RemotePort(), sig->first_eq_opcode); return MatchSuccessful; } else { - LogF(Logs::General, Logs::Netcode, "[IDENT_TRACE] {0}:{1}: First opcode matched {2:#x} but length {3} did not match expected {4}", + LogF(Logs::General, Logs::Netcode, "[StreamIdentify] {0}:{1}: First opcode matched {2:#x} but length {3} did not match expected {4}", m_connection->RemoteEndpoint(), m_connection->RemotePort(), sig->first_eq_opcode, length, sig->first_length); return MatchFailed; } } else { - LogF(Logs::General, Logs::Netcode, "[IDENT_TRACE] {0}:{1}: First opcode {1:#x} did not match expected {2:#x}", + LogF(Logs::General, Logs::Netcode, "[StreamIdentify] {0}:{1}: First opcode {1:#x} did not match expected {2:#x}", m_connection->RemoteEndpoint(), m_connection->RemotePort(), opcode, sig->first_eq_opcode); return MatchFailed; } diff --git a/common/patches/rof.cpp b/common/patches/rof.cpp index 322e187e4..cfc3458c3 100644 --- a/common/patches/rof.cpp +++ b/common/patches/rof.cpp @@ -85,7 +85,7 @@ namespace RoF //TODO: figure out how to support shared memory with multiple patches... opcodes = new RegularOpcodeManager(); if (!opcodes->LoadOpcodes(opfile.c_str())) { - Log(Logs::General, Logs::Netcode, "[OPCODES] Error loading opcodes file %s. Not registering patch %s.", opfile.c_str(), name); + LogNetcode("[OPCODES] Error loading opcodes file [{}]. Not registering patch [{}]", opfile.c_str(), name); return; } } @@ -108,7 +108,7 @@ namespace RoF signature.first_length = sizeof(structs::ClientZoneEntry_Struct); signature.first_eq_opcode = opcodes->EmuToEQ(OP_ZoneEntry); into.RegisterPatch(signature, pname.c_str(), &opcodes, &struct_strategy); - Log(Logs::General, Logs::Netcode, "[IDENTIFY] Registered patch %s", name); + LogNetcode("[StreamIdentify] Registered patch [{}]", name); } void Reload() @@ -125,10 +125,10 @@ namespace RoF opfile += name; opfile += ".conf"; if (!opcodes->ReloadOpcodes(opfile.c_str())) { - Log(Logs::General, Logs::Netcode, "[OPCODES] Error reloading opcodes file %s for patch %s.", opfile.c_str(), name); + LogNetcode("[OPCODES] Error reloading opcodes file [{}] for patch [{}]", opfile.c_str(), name); return; } - Log(Logs::General, Logs::Netcode, "[OPCODES] Reloaded opcodes for patch %s", name); + LogNetcode("[OPCODES] Reloaded opcodes for patch [{}]", name); } } @@ -350,7 +350,7 @@ namespace RoF if (EntryCount == 0 || (in->size % sizeof(BazaarSearchResults_Struct)) != 0) { - Log(Logs::General, Logs::Netcode, "[STRUCTS] Wrong size on outbound %s: Got %d, expected multiple of %d", opcodes->EmuToName(in->GetOpcode()), in->size, sizeof(BazaarSearchResults_Struct)); + LogNetcode("[STRUCTS] Wrong size on outbound [{}]: Got [{}], expected multiple of [{}]", opcodes->EmuToName(in->GetOpcode()), in->size, sizeof(BazaarSearchResults_Struct)); delete in; return; } @@ -589,7 +589,7 @@ namespace RoF for (int index = 0; index < item_count; ++index, ++eq) { SerializeItem(ob, (const EQEmu::ItemInstance*)eq->inst, eq->slot_id, 0, ItemPacketCharInventory); if (ob.tellp() == last_pos) - Log(Logs::General, Logs::Netcode, "RoF::ENCODE(OP_CharInventory) Serialization failed on item slot %d during OP_CharInventory. Item skipped.", eq->slot_id); + LogNetcode("RoF::ENCODE(OP_CharInventory) Serialization failed on item slot [{}] during OP_CharInventory. Item skipped", eq->slot_id); last_pos = ob.tellp(); } @@ -1521,7 +1521,7 @@ namespace RoF SerializeItem(ob, (const EQEmu::ItemInstance*)int_struct->inst, int_struct->slot_id, 0, old_item_pkt->PacketType); if (ob.tellp() == last_pos) { - Log(Logs::General, Logs::Netcode, "RoF::ENCODE(OP_ItemPacket) Serialization failed on item slot %d.", int_struct->slot_id); + LogNetcode("RoF::ENCODE(OP_ItemPacket) Serialization failed on item slot [{}]", int_struct->slot_id); delete in; return; } @@ -2602,7 +2602,7 @@ namespace RoF outapp->WriteUInt8(0); // Unknown - Log(Logs::General, Logs::Netcode, "[STRUCTS] Player Profile Packet is %i bytes", outapp->GetWritePosition()); + LogNetcode("[STRUCTS] Player Profile Packet is [{}] bytes", outapp->GetWritePosition()); auto NewBuffer = new unsigned char[outapp->GetWritePosition()]; memcpy(NewBuffer, outapp->pBuffer, outapp->GetWritePosition()); @@ -3453,7 +3453,7 @@ namespace RoF if (EntryCount == 0 || ((in->size % sizeof(Track_Struct))) != 0) { - Log(Logs::General, Logs::Netcode, "[STRUCTS] Wrong size on outbound %s: Got %d, expected multiple of %d", opcodes->EmuToName(in->GetOpcode()), in->size, sizeof(Track_Struct)); + LogNetcode("[STRUCTS] Wrong size on outbound [{}]: Got [{}], expected multiple of [{}]", opcodes->EmuToName(in->GetOpcode()), in->size, sizeof(Track_Struct)); delete in; return; } @@ -3804,7 +3804,7 @@ namespace RoF //determine and verify length int entrycount = in->size / sizeof(Spawn_Struct); if (entrycount == 0 || (in->size % sizeof(Spawn_Struct)) != 0) { - Log(Logs::General, Logs::Netcode, "[STRUCTS] Wrong size on outbound %s: Got %d, expected multiple of %d", opcodes->EmuToName(in->GetOpcode()), in->size, sizeof(Spawn_Struct)); + LogNetcode("[STRUCTS] Wrong size on outbound [{}]: Got [{}], expected multiple of [{}]", opcodes->EmuToName(in->GetOpcode()), in->size, sizeof(Spawn_Struct)); delete in; return; } @@ -4052,7 +4052,7 @@ namespace RoF Buffer += 29; if (Buffer != (BufferStart + PacketSize)) { - Log(Logs::General, Logs::Netcode, "[ERROR] SPAWN ENCODE LOGIC PROBLEM: Buffer pointer is now %i from end", Buffer - (BufferStart + PacketSize)); + LogNetcode("[ERROR] SPAWN ENCODE LOGIC PROBLEM: Buffer pointer is now [{}] from end", Buffer - (BufferStart + PacketSize)); } //Log.LogDebugType(Logs::General, Logs::Netcode, "[ERROR] Sending zone spawn for %s packet is %i bytes", emu->name, outapp->size); //Log.Hex(Logs::Netcode, outapp->pBuffer, outapp->size); @@ -4621,7 +4621,7 @@ namespace RoF return; } default: - Log(Logs::Detail, Logs::Netcode, "Unhandled OP_GuildBank action"); + LogNetcode("Unhandled OP_GuildBank action"); __packet->SetOpcode(OP_Unknown); /* invalidate the packet */ return; } @@ -5678,7 +5678,7 @@ namespace RoF RoFSlot = server_corpse_slot; } - Log(Logs::Detail, Logs::Netcode, "Convert Server Corpse Slot %i to RoF Corpse Main Slot %i", server_corpse_slot, RoFSlot); + LogNetcode("Convert Server Corpse Slot [{}] to RoF Corpse Main Slot [{}]", server_corpse_slot, RoFSlot); return RoFSlot; } diff --git a/common/patches/rof2.cpp b/common/patches/rof2.cpp index a6cf7a134..6b65adc40 100644 --- a/common/patches/rof2.cpp +++ b/common/patches/rof2.cpp @@ -85,7 +85,7 @@ namespace RoF2 //TODO: figure out how to support shared memory with multiple patches... opcodes = new RegularOpcodeManager(); if (!opcodes->LoadOpcodes(opfile.c_str())) { - Log(Logs::General, Logs::Netcode, "[OPCODES] Error loading opcodes file %s. Not registering patch %s.", opfile.c_str(), name); + LogNetcode("[OPCODES] Error loading opcodes file [{}]. Not registering patch [{}]", opfile.c_str(), name); return; } } @@ -111,7 +111,7 @@ namespace RoF2 - Log(Logs::General, Logs::Netcode, "[IDENTIFY] Registered patch %s", name); + LogNetcode("[StreamIdentify] Registered patch [{}]", name); } void Reload() @@ -128,10 +128,10 @@ namespace RoF2 opfile += name; opfile += ".conf"; if (!opcodes->ReloadOpcodes(opfile.c_str())) { - Log(Logs::General, Logs::Netcode, "[OPCODES] Error reloading opcodes file %s for patch %s.", opfile.c_str(), name); + LogNetcode("[OPCODES] Error reloading opcodes file [{}] for patch [{}]", opfile.c_str(), name); return; } - Log(Logs::General, Logs::Netcode, "[OPCODES] Reloaded opcodes for patch %s", name); + LogNetcode("[OPCODES] Reloaded opcodes for patch [{}]", name); } } @@ -419,7 +419,7 @@ namespace RoF2 if (EntryCount == 0 || (in->size % sizeof(BazaarSearchResults_Struct)) != 0) { - Log(Logs::General, Logs::Netcode, "[STRUCTS] Wrong size on outbound %s: Got %d, expected multiple of %d", opcodes->EmuToName(in->GetOpcode()), in->size, sizeof(BazaarSearchResults_Struct)); + LogNetcode("[STRUCTS] Wrong size on outbound [{}]: Got [{}], expected multiple of [{}]", opcodes->EmuToName(in->GetOpcode()), in->size, sizeof(BazaarSearchResults_Struct)); delete in; return; } @@ -657,7 +657,7 @@ namespace RoF2 for (int index = 0; index < item_count; ++index, ++eq) { SerializeItem(ob, (const EQEmu::ItemInstance*)eq->inst, eq->slot_id, 0, ItemPacketCharInventory); if (ob.tellp() == last_pos) - Log(Logs::General, Logs::Netcode, "RoF2::ENCODE(OP_CharInventory) Serialization failed on item slot %d during OP_CharInventory. Item skipped.", eq->slot_id); + LogNetcode("RoF2::ENCODE(OP_CharInventory) Serialization failed on item slot [{}] during OP_CharInventory. Item skipped", eq->slot_id); last_pos = ob.tellp(); } @@ -1589,7 +1589,7 @@ namespace RoF2 SerializeItem(ob, (const EQEmu::ItemInstance*)int_struct->inst, int_struct->slot_id, 0, old_item_pkt->PacketType); if (ob.tellp() == last_pos) { - Log(Logs::General, Logs::Netcode, "RoF2::ENCODE(OP_ItemPacket) Serialization failed on item slot %d.", int_struct->slot_id); + LogNetcode("RoF2::ENCODE(OP_ItemPacket) Serialization failed on item slot [{}]", int_struct->slot_id); delete in; return; } @@ -2688,7 +2688,7 @@ namespace RoF2 // Think we need 1 byte of padding at the end outapp->WriteUInt8(0); // Unknown - Log(Logs::General, Logs::Netcode, "[STRUCTS] Player Profile Packet is %i bytes", outapp->GetWritePosition()); + LogNetcode("[STRUCTS] Player Profile Packet is [{}] bytes", outapp->GetWritePosition()); auto NewBuffer = new unsigned char[outapp->GetWritePosition()]; memcpy(NewBuffer, outapp->pBuffer, outapp->GetWritePosition()); @@ -3520,7 +3520,7 @@ namespace RoF2 if (EntryCount == 0 || ((in->size % sizeof(Track_Struct))) != 0) { - Log(Logs::General, Logs::Netcode, "[STRUCTS] Wrong size on outbound %s: Got %d, expected multiple of %d", opcodes->EmuToName(in->GetOpcode()), in->size, sizeof(Track_Struct)); + LogNetcode("[STRUCTS] Wrong size on outbound [{}]: Got [{}], expected multiple of [{}]", opcodes->EmuToName(in->GetOpcode()), in->size, sizeof(Track_Struct)); delete in; return; } @@ -3946,7 +3946,7 @@ namespace RoF2 //determine and verify length int entrycount = in->size / sizeof(Spawn_Struct); if (entrycount == 0 || (in->size % sizeof(Spawn_Struct)) != 0) { - Log(Logs::General, Logs::Netcode, "[STRUCTS] Wrong size on outbound %s: Got %d, expected multiple of %d", opcodes->EmuToName(in->GetOpcode()), in->size, sizeof(Spawn_Struct)); + LogNetcode("[STRUCTS] Wrong size on outbound [{}]: Got [{}], expected multiple of [{}]", opcodes->EmuToName(in->GetOpcode()), in->size, sizeof(Spawn_Struct)); delete in; return; } @@ -4278,7 +4278,7 @@ namespace RoF2 Buffer += 29; if (Buffer != (BufferStart + PacketSize)) { - Log(Logs::General, Logs::Netcode, "[ERROR] SPAWN ENCODE LOGIC PROBLEM: Buffer pointer is now %i from end", Buffer - (BufferStart + PacketSize)); + LogNetcode("[ERROR] SPAWN ENCODE LOGIC PROBLEM: Buffer pointer is now [{}] from end", Buffer - (BufferStart + PacketSize)); } //Log.LogDebugType(Logs::General, Logs::Netcode, "[ERROR] Sending zone spawn for %s packet is %i bytes", emu->name, outapp->size); //Log.Hex(Logs::Netcode, outapp->pBuffer, outapp->size); @@ -4859,7 +4859,7 @@ namespace RoF2 return; } default: - Log(Logs::Detail, Logs::Netcode, "Unhandled OP_GuildBank action"); + LogNetcode("Unhandled OP_GuildBank action"); __packet->SetOpcode(OP_Unknown); /* invalidate the packet */ return; } @@ -5012,7 +5012,7 @@ namespace RoF2 emu->to_slot = RoF2ToServerSlot(eq->to_slot); IN(number_in_stack); - //Log(Logs::General, Logs::Netcode, "[RoF2] MoveItem Slot from %u to %u, Number %u", emu->from_slot, emu->to_slot, emu->number_in_stack); + //LogNetcode("[RoF2] MoveItem Slot from [{}] to [{}], Number [{}]", emu->from_slot, emu->to_slot, emu->number_in_stack); FINISH_DIRECT_DECODE(); } @@ -5966,7 +5966,7 @@ namespace RoF2 RoF2Slot = server_corpse_slot; } - Log(Logs::Detail, Logs::Netcode, "Convert Server Corpse Slot %i to RoF2 Corpse Main Slot %i", server_corpse_slot, RoF2Slot); + LogNetcode("Convert Server Corpse Slot [{}] to RoF2 Corpse Main Slot [{}]", server_corpse_slot, RoF2Slot); return RoF2Slot; } @@ -6149,7 +6149,7 @@ namespace RoF2 ServerSlot = rof2_corpse_slot; } - Log(Logs::Detail, Logs::Netcode, "Convert RoF2 Corpse Main Slot %i to Server Corpse Slot %i", rof2_corpse_slot, ServerSlot); + LogNetcode("Convert RoF2 Corpse Main Slot [{}] to Server Corpse Slot [{}]", rof2_corpse_slot, ServerSlot); return ServerSlot; } diff --git a/common/patches/sod.cpp b/common/patches/sod.cpp index 11aae5cc9..2c05c1425 100644 --- a/common/patches/sod.cpp +++ b/common/patches/sod.cpp @@ -79,7 +79,7 @@ namespace SoD //TODO: figure out how to support shared memory with multiple patches... opcodes = new RegularOpcodeManager(); if (!opcodes->LoadOpcodes(opfile.c_str())) { - Log(Logs::General, Logs::Netcode, "[OPCODES] Error loading opcodes file %s. Not registering patch %s.", opfile.c_str(), name); + LogNetcode("[OPCODES] Error loading opcodes file [{}]. Not registering patch [{}]", opfile.c_str(), name); return; } } @@ -105,7 +105,7 @@ namespace SoD - Log(Logs::General, Logs::Netcode, "[IDENTIFY] Registered patch %s", name); + LogNetcode("[StreamIdentify] Registered patch [{}]", name); } void Reload() @@ -122,10 +122,10 @@ namespace SoD opfile += name; opfile += ".conf"; if (!opcodes->ReloadOpcodes(opfile.c_str())) { - Log(Logs::General, Logs::Netcode, "[OPCODES] Error reloading opcodes file %s for patch %s.", opfile.c_str(), name); + LogNetcode("[OPCODES] Error reloading opcodes file [{}] for patch [{}]", opfile.c_str(), name); return; } - Log(Logs::General, Logs::Netcode, "[OPCODES] Reloaded opcodes for patch %s", name); + LogNetcode("[OPCODES] Reloaded opcodes for patch [{}]", name); } } @@ -277,7 +277,7 @@ namespace SoD if (EntryCount == 0 || (in->size % sizeof(BazaarSearchResults_Struct)) != 0) { - Log(Logs::General, Logs::Netcode, "[STRUCTS] Wrong size on outbound %s: Got %d, expected multiple of %d", opcodes->EmuToName(in->GetOpcode()), in->size, sizeof(BazaarSearchResults_Struct)); + LogNetcode("[STRUCTS] Wrong size on outbound [{}]: Got [{}], expected multiple of [{}]", opcodes->EmuToName(in->GetOpcode()), in->size, sizeof(BazaarSearchResults_Struct)); delete in; return; } @@ -400,7 +400,7 @@ namespace SoD for (int index = 0; index < item_count; ++index, ++eq) { SerializeItem(ob, (const EQEmu::ItemInstance*)eq->inst, eq->slot_id, 0); if (ob.tellp() == last_pos) - Log(Logs::General, Logs::Netcode, "SoD::ENCODE(OP_CharInventory) Serialization failed on item slot %d during OP_CharInventory. Item skipped.", eq->slot_id); + LogNetcode("SoD::ENCODE(OP_CharInventory) Serialization failed on item slot [{}] during OP_CharInventory. Item skipped", eq->slot_id); last_pos = ob.tellp(); } @@ -1069,7 +1069,7 @@ namespace SoD SerializeItem(ob, (const EQEmu::ItemInstance*)int_struct->inst, int_struct->slot_id, 0); if (ob.tellp() == last_pos) { - Log(Logs::General, Logs::Netcode, "SoD::ENCODE(OP_ItemPacket) Serialization failed on item slot %d.", int_struct->slot_id); + LogNetcode("SoD::ENCODE(OP_ItemPacket) Serialization failed on item slot [{}]", int_struct->slot_id); delete in; return; } @@ -2198,7 +2198,7 @@ namespace SoD if (EntryCount == 0 || ((in->size % sizeof(Track_Struct))) != 0) { - Log(Logs::General, Logs::Netcode, "[STRUCTS] Wrong size on outbound %s: Got %d, expected multiple of %d", opcodes->EmuToName(in->GetOpcode()), in->size, sizeof(Track_Struct)); + LogNetcode("[STRUCTS] Wrong size on outbound [{}]: Got [{}], expected multiple of [{}]", opcodes->EmuToName(in->GetOpcode()), in->size, sizeof(Track_Struct)); delete in; return; } @@ -2435,7 +2435,7 @@ namespace SoD //determine and verify length int entrycount = in->size / sizeof(Spawn_Struct); if (entrycount == 0 || (in->size % sizeof(Spawn_Struct)) != 0) { - Log(Logs::General, Logs::Netcode, "[STRUCTS] Wrong size on outbound %s: Got %d, expected multiple of %d", opcodes->EmuToName(in->GetOpcode()), in->size, sizeof(Spawn_Struct)); + LogNetcode("[STRUCTS] Wrong size on outbound [{}]: Got [{}], expected multiple of [{}]", opcodes->EmuToName(in->GetOpcode()), in->size, sizeof(Spawn_Struct)); delete in; return; } @@ -3848,7 +3848,7 @@ namespace SoD SoDSlot = serverSlot; } - Log(Logs::Detail, Logs::Netcode, "Convert Server Slot %i to SoD Slot %i", serverSlot, SoDSlot); + LogNetcode("Convert Server Slot [{}] to SoD Slot [{}]", serverSlot, SoDSlot); return SoDSlot; } @@ -3865,7 +3865,7 @@ namespace SoD SoDSlot = server_corpse_slot - 2; } - Log(Logs::Detail, Logs::Netcode, "Convert Server Corpse Slot %i to SoD Corpse Slot %i", server_corpse_slot, SoDSlot); + LogNetcode("Convert Server Corpse Slot [{}] to SoD Corpse Slot [{}]", server_corpse_slot, SoDSlot); return SoDSlot; } @@ -3930,7 +3930,7 @@ namespace SoD server_slot = sod_slot; } - Log(Logs::Detail, Logs::Netcode, "Convert SoD Slot %i to Server Slot %i", sod_slot, server_slot); + LogNetcode("Convert SoD Slot [{}] to Server Slot [{}]", sod_slot, server_slot); return server_slot; } @@ -3947,7 +3947,7 @@ namespace SoD server_slot = sod_corpse_slot + 2; } - Log(Logs::Detail, Logs::Netcode, "Convert SoD Corpse Slot %i to Server Corpse Slot %i", sod_corpse_slot, server_slot); + LogNetcode("Convert SoD Corpse Slot [{}] to Server Corpse Slot [{}]", sod_corpse_slot, server_slot); return server_slot; } diff --git a/common/patches/sof.cpp b/common/patches/sof.cpp index bb310a76c..0d2189740 100644 --- a/common/patches/sof.cpp +++ b/common/patches/sof.cpp @@ -79,7 +79,7 @@ namespace SoF //TODO: figure out how to support shared memory with multiple patches... opcodes = new RegularOpcodeManager(); if (!opcodes->LoadOpcodes(opfile.c_str())) { - Log(Logs::General, Logs::Netcode, "[OPCODES] Error loading opcodes file %s. Not registering patch %s.", opfile.c_str(), name); + LogNetcode("[OPCODES] Error loading opcodes file [{}]. Not registering patch [{}]", opfile.c_str(), name); return; } } @@ -103,7 +103,7 @@ namespace SoF signature.first_eq_opcode = opcodes->EmuToEQ(OP_ZoneEntry); into.RegisterPatch(signature, pname.c_str(), &opcodes, &struct_strategy); - Log(Logs::General, Logs::Netcode, "[IDENTIFY] Registered patch %s", name); + LogNetcode("[StreamIdentify] Registered patch [{}]", name); } void Reload() @@ -120,10 +120,10 @@ namespace SoF opfile += name; opfile += ".conf"; if (!opcodes->ReloadOpcodes(opfile.c_str())) { - Log(Logs::General, Logs::Netcode, "[OPCODES] Error reloading opcodes file %s for patch %s.", opfile.c_str(), name); + LogNetcode("[OPCODES] Error reloading opcodes file [{}] for patch [{}]", opfile.c_str(), name); return; } - Log(Logs::General, Logs::Netcode, "[OPCODES] Reloaded opcodes for patch %s", name); + LogNetcode("[OPCODES] Reloaded opcodes for patch [{}]", name); } } @@ -380,7 +380,7 @@ namespace SoF for (int index = 0; index < item_count; ++index, ++eq) { SerializeItem(ob, (const EQEmu::ItemInstance*)eq->inst, eq->slot_id, 0); if (ob.tellp() == last_pos) - Log(Logs::General, Logs::Netcode, "SoF::ENCODE(OP_CharInventory) Serialization failed on item slot %d during OP_CharInventory. Item skipped.", eq->slot_id); + LogNetcode("SoF::ENCODE(OP_CharInventory) Serialization failed on item slot [{}] during OP_CharInventory. Item skipped", eq->slot_id); last_pos = ob.tellp(); } @@ -864,7 +864,7 @@ namespace SoF SerializeItem(ob, (const EQEmu::ItemInstance*)int_struct->inst, int_struct->slot_id, 0); if (ob.tellp() == last_pos) { - Log(Logs::General, Logs::Netcode, "SoF::ENCODE(OP_ItemPacket) Serialization failed on item slot %d.", int_struct->slot_id); + LogNetcode("SoF::ENCODE(OP_ItemPacket) Serialization failed on item slot [{}]", int_struct->slot_id); delete in; return; } @@ -1827,7 +1827,7 @@ namespace SoF if (EntryCount == 0 || ((in->size % sizeof(Track_Struct))) != 0) { - Log(Logs::General, Logs::Netcode, "[STRUCTS] Wrong size on outbound %s: Got %d, expected multiple of %d", opcodes->EmuToName(in->GetOpcode()), in->size, sizeof(Track_Struct)); + LogNetcode("[STRUCTS] Wrong size on outbound [{}]: Got [{}], expected multiple of [{}]", opcodes->EmuToName(in->GetOpcode()), in->size, sizeof(Track_Struct)); delete in; return; } @@ -1989,7 +1989,7 @@ namespace SoF //determine and verify length int entrycount = in->size / sizeof(Spawn_Struct); if (entrycount == 0 || (in->size % sizeof(Spawn_Struct)) != 0) { - Log(Logs::General, Logs::Netcode, "[STRUCTS] Wrong size on outbound %s: Got %d, expected multiple of %d", opcodes->EmuToName(in->GetOpcode()), in->size, sizeof(Spawn_Struct)); + LogNetcode("[STRUCTS] Wrong size on outbound [{}]: Got [{}], expected multiple of [{}]", opcodes->EmuToName(in->GetOpcode()), in->size, sizeof(Spawn_Struct)); delete in; return; } @@ -3244,7 +3244,7 @@ namespace SoF sof_slot = server_slot; } - Log(Logs::Detail, Logs::Netcode, "Convert Server Slot %i to SoF Slot %i", server_slot, sof_slot); + LogNetcode("Convert Server Slot [{}] to SoF Slot [{}]", server_slot, sof_slot); return sof_slot; } @@ -3330,7 +3330,7 @@ namespace SoF server_slot = sof_slot; } - Log(Logs::Detail, Logs::Netcode, "Convert SoF Slot %i to Server Slot %i", sof_slot, server_slot); + LogNetcode("Convert SoF Slot [{}] to Server Slot [{}]", sof_slot, server_slot); return server_slot; } diff --git a/common/patches/ss_define.h b/common/patches/ss_define.h index bd5c065c5..57bf6b1b4 100644 --- a/common/patches/ss_define.h +++ b/common/patches/ss_define.h @@ -87,14 +87,14 @@ //check length of packet before decoding. Call before setup. #define ENCODE_LENGTH_EXACT(struct_) \ if((*p)->size != sizeof(struct_)) { \ - Log(Logs::Detail, Logs::Netcode, "Wrong size on outbound %s (" #struct_ "): Got %d, expected %d", opcodes->EmuToName((*p)->GetOpcode()), (*p)->size, sizeof(struct_)); \ + LogNetcode("Wrong size on outbound [{}] (" #struct_ "): Got [{}], expected [{}]", opcodes->EmuToName((*p)->GetOpcode()), (*p)->size, sizeof(struct_)); \ delete *p; \ *p = nullptr; \ return; \ } #define ENCODE_LENGTH_ATLEAST(struct_) \ if((*p)->size < sizeof(struct_)) { \ - Log(Logs::Detail, Logs::Netcode, "Wrong size on outbound %s (" #struct_ "): Got %d, expected at least %d", opcodes->EmuToName((*p)->GetOpcode()), (*p)->size, sizeof(struct_)); \ + LogNetcode("Wrong size on outbound [{}] (" #struct_ "): Got [{}], expected at least [{}]", opcodes->EmuToName((*p)->GetOpcode()), (*p)->size, sizeof(struct_)); \ delete *p; \ *p = nullptr; \ return; \ @@ -153,13 +153,13 @@ //check length of packet before decoding. Call before setup. #define DECODE_LENGTH_EXACT(struct_) \ if(__packet->size != sizeof(struct_)) { \ - Log(Logs::Detail, Logs::Netcode, "Wrong size on incoming %s (" #struct_ "): Got %d, expected %d", opcodes->EmuToName(__packet->GetOpcode()), __packet->size, sizeof(struct_)); \ + LogNetcode("Wrong size on incoming [{}] (" #struct_ "): Got [{}], expected [{}]", opcodes->EmuToName(__packet->GetOpcode()), __packet->size, sizeof(struct_)); \ __packet->SetOpcode(OP_Unknown); /* invalidate the packet */ \ return; \ } #define DECODE_LENGTH_ATLEAST(struct_) \ if(__packet->size < sizeof(struct_)) { \ - Log(Logs::Detail, Logs::Netcode, "Wrong size on incoming %s (" #struct_ "): Got %d, expected at least %d", opcodes->EmuToName(__packet->GetOpcode()), __packet->size, sizeof(struct_)); \ + LogNetcode("Wrong size on incoming [{}] (" #struct_ "): Got [{}], expected at least [{}]", opcodes->EmuToName(__packet->GetOpcode()), __packet->size, sizeof(struct_)); \ __packet->SetOpcode(OP_Unknown); /* invalidate the packet */ \ return; \ } diff --git a/common/patches/titanium.cpp b/common/patches/titanium.cpp index b50df595c..5cb8e5897 100644 --- a/common/patches/titanium.cpp +++ b/common/patches/titanium.cpp @@ -78,7 +78,7 @@ namespace Titanium //TODO: figure out how to support shared memory with multiple patches... opcodes = new RegularOpcodeManager(); if (!opcodes->LoadOpcodes(opfile.c_str())) { - Log(Logs::General, Logs::Netcode, "[OPCODES] Error loading opcodes file %s. Not registering patch %s.", opfile.c_str(), name); + LogNetcode("[OPCODES] Error loading opcodes file [{}]. Not registering patch [{}]", opfile.c_str(), name); return; } } @@ -104,7 +104,7 @@ namespace Titanium - Log(Logs::General, Logs::Netcode, "[IDENTIFY] Registered patch %s", name); + LogNetcode("[StreamIdentify] Registered patch [{}]", name); } void Reload() @@ -121,10 +121,10 @@ namespace Titanium opfile += name; opfile += ".conf"; if (!opcodes->ReloadOpcodes(opfile.c_str())) { - Log(Logs::General, Logs::Netcode, "[OPCODES] Error reloading opcodes file %s for patch %s.", opfile.c_str(), name); + LogNetcode("[OPCODES] Error reloading opcodes file [{}] for patch [{}]", opfile.c_str(), name); return; } - Log(Logs::General, Logs::Netcode, "[OPCODES] Reloaded opcodes for patch %s", name); + LogNetcode("[OPCODES] Reloaded opcodes for patch [{}]", name); } } @@ -337,7 +337,7 @@ namespace Titanium for (int r = 0; r < itemcount; r++, eq++) { SerializeItem(ob, (const EQEmu::ItemInstance*)eq->inst, ServerToTitaniumSlot(eq->slot_id), 0); if (ob.tellp() == last_pos) - Log(Logs::General, Logs::Netcode, "Titanium::ENCODE(OP_CharInventory) Serialization failed on item slot %d during OP_CharInventory. Item skipped.", eq->slot_id); + LogNetcode("Titanium::ENCODE(OP_CharInventory) Serialization failed on item slot [{}] during OP_CharInventory. Item skipped", eq->slot_id); last_pos = ob.tellp(); } @@ -822,7 +822,7 @@ namespace Titanium SerializeItem(ob, (const EQEmu::ItemInstance*)int_struct->inst, ServerToTitaniumSlot(int_struct->slot_id), 0); if (ob.tellp() == last_pos) { - Log(Logs::General, Logs::Netcode, "Titanium::ENCODE(OP_ItemPacket) Serialization failed on item slot %d.", int_struct->slot_id); + LogNetcode("Titanium::ENCODE(OP_ItemPacket) Serialization failed on item slot [{}]", int_struct->slot_id); delete in; return; } @@ -1510,7 +1510,7 @@ namespace Titanium if (EntryCount == 0 || ((in->size % sizeof(Track_Struct))) != 0) { - Log(Logs::General, Logs::Netcode, "[STRUCTS] Wrong size on outbound %s: Got %d, expected multiple of %d", opcodes->EmuToName(in->GetOpcode()), in->size, sizeof(Track_Struct)); + LogNetcode("[STRUCTS] Wrong size on outbound [{}]: Got [{}], expected multiple of [{}]", opcodes->EmuToName(in->GetOpcode()), in->size, sizeof(Track_Struct)); delete in; return; } @@ -1628,7 +1628,7 @@ namespace Titanium //determine and verify length int entrycount = in->size / sizeof(Spawn_Struct); if (entrycount == 0 || (in->size % sizeof(Spawn_Struct)) != 0) { - Log(Logs::General, Logs::Netcode, "[STRUCTS] Wrong size on outbound %s: Got %d, expected multiple of %d", opcodes->EmuToName(in->GetOpcode()), in->size, sizeof(Spawn_Struct)); + LogNetcode("[STRUCTS] Wrong size on outbound [{}]: Got [{}], expected multiple of [{}]", opcodes->EmuToName(in->GetOpcode()), in->size, sizeof(Spawn_Struct)); delete in; return; } @@ -2540,7 +2540,7 @@ namespace Titanium titanium_slot = server_slot; } - Log(Logs::Detail, Logs::Netcode, "Convert Server Slot %i to Titanium Slot %i", server_slot, titanium_slot); + LogNetcode("Convert Server Slot [{}] to Titanium Slot [{}]", server_slot, titanium_slot); return titanium_slot; } @@ -2627,7 +2627,7 @@ namespace Titanium server_slot = titanium_slot; } - Log(Logs::Detail, Logs::Netcode, "Convert Titanium Slot %i to Server Slot %i", titanium_slot, server_slot); + LogNetcode("Convert Titanium Slot [{}] to Server Slot [{}]", titanium_slot, server_slot); return server_slot; } @@ -2648,7 +2648,7 @@ namespace Titanium server_slot = titanium_corpse_slot + 4; } - Log(Logs::Detail, Logs::Netcode, "Convert Titanium Corpse Slot %i to Server Corpse Slot %i", titanium_corpse_slot, server_slot); + LogNetcode("Convert Titanium Corpse Slot [{}] to Server Corpse Slot [{}]", titanium_corpse_slot, server_slot); return server_slot; } diff --git a/common/patches/uf.cpp b/common/patches/uf.cpp index b644c9554..0d44d7d1a 100644 --- a/common/patches/uf.cpp +++ b/common/patches/uf.cpp @@ -79,7 +79,7 @@ namespace UF //TODO: figure out how to support shared memory with multiple patches... opcodes = new RegularOpcodeManager(); if (!opcodes->LoadOpcodes(opfile.c_str())) { - Log(Logs::General, Logs::Netcode, "[OPCODES] Error loading opcodes file %s. Not registering patch %s.", opfile.c_str(), name); + LogNetcode("[OPCODES] Error loading opcodes file [{}]. Not registering patch [{}]", opfile.c_str(), name); return; } } @@ -105,7 +105,7 @@ namespace UF - Log(Logs::General, Logs::Netcode, "[IDENTIFY] Registered patch %s", name); + LogNetcode("[StreamIdentify] Registered patch [{}]", name); } void Reload() @@ -122,10 +122,10 @@ namespace UF opfile += name; opfile += ".conf"; if (!opcodes->ReloadOpcodes(opfile.c_str())) { - Log(Logs::General, Logs::Netcode, "[OPCODES] Error reloading opcodes file %s for patch %s.", opfile.c_str(), name); + LogNetcode("[OPCODES] Error reloading opcodes file [{}] for patch [{}]", opfile.c_str(), name); return; } - Log(Logs::General, Logs::Netcode, "[OPCODES] Reloaded opcodes for patch %s", name); + LogNetcode("[OPCODES] Reloaded opcodes for patch [{}]", name); } } @@ -330,7 +330,7 @@ namespace UF if (EntryCount == 0 || (in->size % sizeof(BazaarSearchResults_Struct)) != 0) { - Log(Logs::General, Logs::Netcode, "[STRUCTS] Wrong size on outbound %s: Got %d, expected multiple of %d", opcodes->EmuToName(in->GetOpcode()), in->size, sizeof(BazaarSearchResults_Struct)); + LogNetcode("[STRUCTS] Wrong size on outbound [{}]: Got [{}], expected multiple of [{}]", opcodes->EmuToName(in->GetOpcode()), in->size, sizeof(BazaarSearchResults_Struct)); delete in; return; } @@ -520,7 +520,7 @@ namespace UF for (int index = 0; index < item_count; ++index, ++eq) { SerializeItem(ob, (const EQEmu::ItemInstance*)eq->inst, eq->slot_id, 0); if (ob.tellp() == last_pos) - Log(Logs::General, Logs::Netcode, "UF::ENCODE(OP_CharInventory) Serialization failed on item slot %d during OP_CharInventory. Item skipped.", eq->slot_id); + LogNetcode("UF::ENCODE(OP_CharInventory) Serialization failed on item slot [{}] during OP_CharInventory. Item skipped", eq->slot_id); last_pos = ob.tellp(); } @@ -1277,7 +1277,7 @@ namespace UF SerializeItem(ob, (const EQEmu::ItemInstance*)int_struct->inst, int_struct->slot_id, 0); if (ob.tellp() == last_pos) { - Log(Logs::General, Logs::Netcode, "UF::ENCODE(OP_ItemPacket) Serialization failed on item slot %d.", int_struct->slot_id); + LogNetcode("UF::ENCODE(OP_ItemPacket) Serialization failed on item slot [{}]", int_struct->slot_id); delete in; return; } @@ -2472,7 +2472,7 @@ namespace UF if (EntryCount == 0 || ((in->size % sizeof(Track_Struct))) != 0) { - Log(Logs::General, Logs::Netcode, "[STRUCTS] Wrong size on outbound %s: Got %d, expected multiple of %d", opcodes->EmuToName(in->GetOpcode()), in->size, sizeof(Track_Struct)); + LogNetcode("[STRUCTS] Wrong size on outbound [{}]: Got [{}], expected multiple of [{}]", opcodes->EmuToName(in->GetOpcode()), in->size, sizeof(Track_Struct)); delete in; return; } @@ -2704,7 +2704,7 @@ namespace UF //determine and verify length int entrycount = in->size / sizeof(Spawn_Struct); if (entrycount == 0 || (in->size % sizeof(Spawn_Struct)) != 0) { - Log(Logs::General, Logs::Netcode, "[STRUCTS] Wrong size on outbound %s: Got %d, expected multiple of %d", opcodes->EmuToName(in->GetOpcode()), in->size, sizeof(Spawn_Struct)); + LogNetcode("[STRUCTS] Wrong size on outbound [{}]: Got [{}], expected multiple of [{}]", opcodes->EmuToName(in->GetOpcode()), in->size, sizeof(Spawn_Struct)); delete in; return; } @@ -4206,7 +4206,7 @@ namespace UF UFSlot = serverSlot; } - Log(Logs::Detail, Logs::Netcode, "Convert Server Slot %i to UF Slot %i", serverSlot, UFSlot); + LogNetcode("Convert Server Slot [{}] to UF Slot [{}]", serverSlot, UFSlot); return UFSlot; } @@ -4223,7 +4223,7 @@ namespace UF UFSlot = serverCorpseSlot - 2; } - Log(Logs::Detail, Logs::Netcode, "Convert Server Corpse Slot %i to UF Corpse Slot %i", serverCorpseSlot, UFSlot); + LogNetcode("Convert Server Corpse Slot [{}] to UF Corpse Slot [{}]", serverCorpseSlot, UFSlot); return UFSlot; } @@ -4288,7 +4288,7 @@ namespace UF ServerSlot = ufSlot; } - Log(Logs::Detail, Logs::Netcode, "Convert UF Slot %i to Server Slot %i", ufSlot, ServerSlot); + LogNetcode("Convert UF Slot [{}] to Server Slot [{}]", ufSlot, ServerSlot); return ServerSlot; } @@ -4305,7 +4305,7 @@ namespace UF ServerSlot = ufCorpseSlot + 2; } - Log(Logs::Detail, Logs::Netcode, "Convert UF Corpse Slot %i to Server Corpse Slot %i", ufCorpseSlot, ServerSlot); + LogNetcode("Convert UF Corpse Slot [{}] to Server Corpse Slot [{}]", ufCorpseSlot, ServerSlot); return ServerSlot; } diff --git a/common/struct_strategy.cpp b/common/struct_strategy.cpp index 58a7f9e76..52df20410 100644 --- a/common/struct_strategy.cpp +++ b/common/struct_strategy.cpp @@ -41,13 +41,13 @@ void StructStrategy::ErrorEncoder(EQApplicationPacket **in_p, std::shared_ptrGetOpcode())); + LogNetcode("[STRUCTS] Error encoding opcode [{}]: no encoder provided. Dropping", OpcodeManager::EmuToName(p->GetOpcode())); delete p; } void StructStrategy::ErrorDecoder(EQApplicationPacket *p) { - Log(Logs::General, Logs::Netcode, "[STRUCTS] Error decoding opcode %s: no decoder provided. Invalidating.", OpcodeManager::EmuToName(p->GetOpcode())); + LogNetcode("[STRUCTS] Error decoding opcode [{}]: no decoder provided. Invalidating", OpcodeManager::EmuToName(p->GetOpcode())); p->SetOpcode(OP_Unknown); } diff --git a/common/worldconn.cpp b/common/worldconn.cpp index 22a34a3ba..77bfa6162 100644 --- a/common/worldconn.cpp +++ b/common/worldconn.cpp @@ -44,7 +44,7 @@ bool WorldConnection::SendPacket(ServerPacket* pack) { void WorldConnection::OnConnected() { const EQEmuConfig *Config=EQEmuConfig::get(); - Log(Logs::General, Logs::Netcode, "[WORLD] Connected to World: %s:%d", Config->WorldIP.c_str(), Config->WorldTCPPort); + LogNetcode("[WORLD] Connected to World: [{}]:[{}]", Config->WorldIP.c_str(), Config->WorldTCPPort); auto pack = new ServerPacket(ServerOP_ZAAuth, 16); MD5::Generate((const uchar*) m_password.c_str(), m_password.length(), pack->pBuffer); @@ -76,7 +76,7 @@ bool WorldConnection::Connect() { if (tcpc.Connect(Config->WorldIP.c_str(), Config->WorldTCPPort, errbuf)) { return true; } else { - Log(Logs::General, Logs::Netcode, "[WORLD] WorldConnection connect: Connecting to the server %s:%d failed: %s", Config->WorldIP.c_str(), Config->WorldTCPPort, errbuf); + LogNetcode("[WORLD] WorldConnection connect: Connecting to the server [{}]:[{}] failed: [{}]", Config->WorldIP.c_str(), Config->WorldTCPPort, errbuf); } return false; }