//////////////////////////////////////////////////// // setCache // adds current packet to specified cache void EQPacketStream::setCache(uint16_t serverArqSeq, EQProtocolPacket& packet) { // check if the entry already exists in the cache EQPacketMap::iterator it = m_cache.find(serverArqSeq); if (it == m_cache.end()) { // entry doesn't exist, so insert an entry into the cache #ifdef PACKET_PROCESS_DIAG seqDebug("SEQ: Insert arq (%04x) stream %d into cache", serverArqSeq, m_streamid); #endif m_cache.insert(EQPacketMap::value_type(serverArqSeq, new EQProtocolPacket(packet, true))); emit cacheSize(m_cache.size(), (int)m_streamid); } else { // replacing an existing entry, make sure the new data is valid #ifdef APPLY_CRC_CHECK if (! packet.hasCRC() || calculateCRC(packet) == packet.crc()) #endif { #ifdef PACKET_PROCESS_DIAG seqDebug("SEQ: Update arq (%04x) stream %d in cache", serverArqSeq, m_streamid); #endif // Free the old packet at this place and replace with the new one. delete it->second; it->second = new EQProtocolPacket(packet, true); } #if defined(PACKET_PROCESS_DIAG) && defined(APPLY_CRC_CHECK) else seqDebug("SEQ: Not Updating arq (%04x) stream %d into cache, CRC error!", serverArqSeq, m_streamid); #endif } #ifdef PACKET_CACHE_DIAG if (m_cache.size() > m_maxCacheCount) m_maxCacheCount = m_cache.size(); #endif // PACKET_CACHE_DIAG }
///////////////////////////////////////////////////// // Handle a protocol level packet. This could be either a top-level // EQUDPIPPacket or a subpacket that is just an EQProtocolPacket. Either way // we use net opcodes here. void EQPacketStream::processPacket(EQProtocolPacket& packet, bool /*isSubpacket*/) { #if defined(PACKET_PROCESS_DIAG) && (PACKET_PROCESS_DIAG > 2) seqDebug("-->EQPacketStream::processPacket, subpacket=%s on stream %s (%d)", (isSubpacket ? "true" : "false"), EQStreamStr[m_streamid], m_streamid); #endif if (IS_APP_OPCODE(packet.getNetOpCode())) { // This is an app-opcode directly on the wire with no wrapping protocol // information. Weird, but whatever gets the stream read, right? dispatchPacket(packet.payload(), packet.payloadLength(), packet.getNetOpCode(), m_opcodeDB.find(packet.getNetOpCode())); return; } // Process the net opcode switch (packet.getNetOpCode()) { case OP_Combined: { #if defined(PACKET_PROCESS_DIAG) && (PACKET_PROCESS_DIAG > 2) seqDebug("EQPacket: found combined packet (net op: %04x, size %d) on stream %s (%d). Unrolling.", packet.getNetOpCode(), packet.payloadLength(), EQStreamStr[m_streamid], m_streamid); #endif // Rolled up multiple packets inside this packet. Need to unroll them // and process them individually. subpacket starts after the net opcode. uint8_t* subpacket = packet.payload(); while (subpacket < packet.payload() + packet.payloadLength()) { // Length specified first on the wire. uint8_t subpacketLength = subpacket[0]; // Move past the length subpacket++; // OpCode (in net order) uint16_t subOpCode = *(uint16_t*)subpacket; #if defined(PACKET_PROCESS_DIAG) && (PACKET_PROCESS_DIAG > 2) seqDebug("EQPacket: unrolling length %d bytes from combined packet on stream %s (%d). Opcode %04x", subpacketLength, EQStreamStr[m_streamid], m_streamid, subOpCode); #endif // Opcode is next. Net opcode or app opcode? if (subOpCode == 0) { // App opcode < 0x00ff. Skip the first byte and dispatch the app // opcode appropriately subpacket++; subOpCode = *(uint16_t*)subpacket; #if defined(PACKET_PROCESS_DIAG) && (PACKET_PROCESS_DIAG > 2) seqDebug("EQPacket: processing unrolled special app opcode, length %d bytes from combined packet on stream %s (%d). Opcode %04x", subpacketLength-3, EQStreamStr[m_streamid], m_streamid, subOpCode); #endif // App opcode. Dispatch it, skipping opcode. dispatchPacket(&subpacket[2], subpacketLength-2, subOpCode, m_opcodeDB.find(subOpCode)); } else if (IS_NET_OPCODE(subOpCode)) { #if defined(PACKET_PROCESS_DIAG) && (PACKET_PROCESS_DIAG > 2) seqDebug("EQPacket: processing unrolled net opcode, length %d bytes from combined packet on stream %s (%d). Opcode %04x", subpacketLength, EQStreamStr[m_streamid], m_streamid, subOpCode); #endif // Net opcode. false = copy. true = subpacket EQProtocolPacket spacket(subpacket, subpacketLength, false, true); processPacket(spacket, true); } else { #if defined(PACKET_PROCESS_DIAG) && (PACKET_PROCESS_DIAG > 2) seqDebug("EQPacket: processing unrolled app opcode, length %d bytes from combined packet on stream %s (%d). Opcode %04x", subpacketLength-2, EQStreamStr[m_streamid], m_streamid, subOpCode); #endif // App opcode. Dispatch it, skipping opcode. dispatchPacket(&subpacket[2], subpacketLength-2, subOpCode, m_opcodeDB.find(subOpCode)); } subpacket += subpacketLength; } } break; case OP_AppCombined: { #if defined(PACKET_PROCESS_DIAG) && (PACKET_PROCESS_DIAG > 2) seqDebug("EQPacket: found appcombined packet (net op: %04x, size %d) on stream %s (%d). Unrolling.", packet.getNetOpCode(), packet.payloadLength(), EQStreamStr[m_streamid], m_streamid); #endif // Multiple app op codes in the same packet. Need to unroll and dispatch // them. uint8_t* subpacket = packet.payload(); while (subpacket < packet.payload() + packet.payloadLength()) { // Length specified first on the wire. uint8_t subpacketLength = subpacket[0]; // Move past the length subpacket++; if (subpacketLength != 0xff) { // Dispatch app op code using given packet length. Net order! uint16_t subOpCode = *(uint16_t*)(subpacket); // Handle 3 byte opcodes properly if (subOpCode == 0) { // 3 byte opcode. Drop the first byte, opcode is byte 2 and 3 subpacket++; subpacketLength--; subOpCode = *(uint16_t*)(subpacket); } #if defined(PACKET_PROCESS_DIAG) && (PACKET_PROCESS_DIAG > 2) seqDebug("EQPacket: unrolling length %d bytes from combined packet on stream %s (%d). Opcode %04x", subpacketLength, EQStreamStr[m_streamid], m_streamid, subOpCode); seqDebug("EQPacket: processing unrolled app opcode, length %d bytes from combined packet on stream %s (%d). Opcode %04x", subpacketLength-2, EQStreamStr[m_streamid], m_streamid, subOpCode); #endif // Dispatch, skipping op code. dispatchPacket(&subpacket[2], subpacketLength-2, subOpCode, m_opcodeDB.find(subOpCode)); // Move ahead subpacket += subpacketLength; } else { // If original length is 0xff, it means it is a long one. The length // is 2 bytes and next. uint16_t longOne = eqntohuint16(subpacket); // Move past the 2 byte length subpacket += 2; // OpCode next. Net order for op codes. uint16_t subOpCode = *(uint16_t*)subpacket; // Handle 3 byte opcodes properly if (subOpCode == 0) { // 3 byte opcode. Drop the first byte, opcode is byte 2 and 3 subpacket++; longOne--; subOpCode = *(uint16_t*)(subpacket); } #if defined(PACKET_PROCESS_DIAG) && (PACKET_PROCESS_DIAG > 2) seqDebug("EQPacket: unrolling length %d bytes from combined packet on stream %s (%d). Opcode %04x", longOne, EQStreamStr[m_streamid], m_streamid, subOpCode); seqDebug("EQPacket: processing unrolled app opcode, length %d bytes from combined packet on stream %s (%d). Opcode %04x", longOne-2, EQStreamStr[m_streamid], m_streamid, subOpCode); #endif // Dispatch, skipping op code. dispatchPacket(&subpacket[2], longOne-2, subOpCode, m_opcodeDB.find(subOpCode)); // Move ahead subpacket += longOne; } } } break; case OP_Packet: { // Normal unfragmented sequenced packet. uint16_t seq = packet.arqSeq(); emit seqReceive(seq, (int)m_streamid); // Future packet? if (seq == m_arqSeqExp) { // Expected packet. m_arqSeqExp++; emit seqExpect(m_arqSeqExp, (int)m_streamid); // OpCode next. Net order for op codes. uint16_t subOpCode = *(uint16_t*)(packet.payload()); #if defined(PACKET_PROCESS_DIAG) && (PACKET_PROCESS_DIAG > 1) seqDebug("SEQ: Found next sequence number in data stream %s (%d), incrementing expected seq, %04x (op code %04x, sub opcode %04x)", EQStreamStr[m_streamid], m_streamid, seq, packet.getNetOpCode(), subOpCode); #endif // Opcode is next. Net opcode or app opcode? if (subOpCode == 0) { // App opcode < 0x00ff. Skip the first byte and dispatch the app // opcode appropriately subOpCode = *(uint16_t*)&packet.payload()[1]; #if defined(PACKET_PROCESS_DIAG) && (PACKET_PROCESS_DIAG > 1) seqDebug("EQPacket: special app opcode extracted for opcode 0000 on stream %s (%d). Opcode %04x", EQStreamStr[m_streamid], m_streamid, subOpCode); #endif // App opcode. Dispatch it, skipping opcode. dispatchPacket(&packet.payload()[3], packet.payloadLength()-3, subOpCode, m_opcodeDB.find(subOpCode)); } else if (IS_NET_OPCODE(subOpCode)) { // Net opcode. false = no copy. true = subpacket. EQProtocolPacket spacket(packet.payload(), packet.payloadLength(), false, true); processPacket(spacket, true); } else { // App opcode. Dispatch, skipping opcode. dispatchPacket(&packet.payload()[2], packet.payloadLength()-2, subOpCode, m_opcodeDB.find(subOpCode)); } } else if ((seq > m_arqSeqExp && seq < (uint32_t(m_arqSeqExp + arqSeqWrapCutoff))) || seq < (int32_t(m_arqSeqExp) - arqSeqWrapCutoff)) { // Yeah, future packet. Push it on the packet cache. #ifdef PACKET_PROCESS_DIAG seqDebug("SEQ: out of order sequence %04x stream %s (%d) expecting %04x, sending to cache, %04d", seq, EQStreamStr[m_streamid], m_streamid, m_arqSeqExp, m_cache.size()); #endif setCache(seq, packet); } else { #ifdef PACKET_PROCESS_DIAG // Past packet outside the cut off seqWarn("SEQ: received sequenced %spacket outside expected window on stream %s (%d) netopcode=%04x size=%d. Expecting seq=%04x got seq=%04x, window size %d, dropping packet as in the past.", (isSubpacket ? "sub" : ""), EQStreamStr[m_streamid], m_streamid, packet.getNetOpCode(), packet.payloadLength(), m_arqSeqExp, seq, arqSeqWrapCutoff); #endif } } break; case OP_Oversized: { // Fragmented sequenced data packet. uint16_t seq = packet.arqSeq(); emit seqReceive(seq, (int)m_streamid); // Future packet? if (seq == m_arqSeqExp) { // Expected packet. m_arqSeqExp++; emit seqExpect(m_arqSeqExp, (int)m_streamid); #if defined(PACKET_PROCESS_DIAG) && (PACKET_PROCESS_DIAG > 1) seqDebug("SEQ: Found next sequence number in data stream %s (%d), incrementing expected seq, %04x (op code %04x)", EQStreamStr[m_streamid], m_streamid, seq, packet.getNetOpCode()); #endif // Push the fragment on. m_fragment.addFragment(packet); if (m_fragment.isComplete()) { // OpCode from fragment. In network order. uint16_t fragOpCode = *(uint16_t*)(m_fragment.data()); #ifdef PACKET_PROCESS_DIAG seqDebug("SEQ: Completed oversized app packet on stream %s with seq %04x, total size %d opcode %04x", EQStreamStr[m_streamid], seq, m_fragment.size()-2, fragOpCode); #endif // dispatch fragment. Skip opcode. if (fragOpCode == 0) { // Special app opcode. Skip first byte and op is byte 2 and 3. fragOpCode = *(uint16_t*)(&m_fragment.data()[1]); #if defined(PACKET_PROCESS_DIAG) && (PACKET_PROCESS_DIAG > 1) seqDebug("EQPacket: special app opcode on completed fragment for opcode 0000 on stream %s (%d). Opcode %04x", EQStreamStr[m_streamid], m_streamid, fragOpCode); #endif dispatchPacket(&m_fragment.data()[3], m_fragment.size()-3, fragOpCode, m_opcodeDB.find(fragOpCode)); } else { dispatchPacket(&m_fragment.data()[2], m_fragment.size()-2, fragOpCode, m_opcodeDB.find(fragOpCode)); } m_fragment.reset(); } } else if ((seq > m_arqSeqExp && seq < (uint32_t(m_arqSeqExp + arqSeqWrapCutoff))) || seq < (int32_t(m_arqSeqExp) - arqSeqWrapCutoff)) { // Yeah, future packet. Push it on the packet cache. #ifdef PACKET_PROCESS_DIAG seqDebug("SEQ: out of order sequence %04x stream %s (%d) expecting %04x, sending to cache, %04d", seq, EQStreamStr[m_streamid], m_streamid, m_arqSeqExp, m_cache.size()); #endif setCache(seq, packet); } else { #ifdef PACKET_PROCESS_DIAG // Past packet outside the cut off seqWarn("SEQ: received sequenced %spacket outside expected window on stream %s (%d) netopcode=%04x size=%d. Expecting seq=%04x got seq=%04x, window size %d, dropping packet as in the past.", (isSubpacket ? "sub" : ""), EQStreamStr[m_streamid], m_streamid, packet.getNetOpCode(), packet.payloadLength(), m_arqSeqExp, seq, arqSeqWrapCutoff); #endif } } break; case OP_SessionRequest: { // Session request from client to server. // // Sanity check the size. Don't assume any packet we see is an EQ // session request, since we're gonna cause a huge freakin' malloc // on the maxlength of the session which for some reason some people // won't enjoy! if (packet.payloadLength() != sizeof(SessionRequestStruct)) { // Either SessionRequestStruct changed or this isn't a session // request. #if defined(PACKET_PROCESS_DIAG) || defined(PACKET_SESSION_DIAG) seqDebug("EQPacket: Ignoring SessionRequest %s:%u->%s:%u with invalid size %d.", ((EQUDPIPPacketFormat&) packet).getIPv4SourceA().ascii(), ((EQUDPIPPacketFormat&) packet).getSourcePort(), ((EQUDPIPPacketFormat&) packet).getIPv4DestA().ascii(), ((EQUDPIPPacketFormat&) packet).getDestPort(), packet.payloadLength()); #endif break; } // Pull off session request information SessionRequestStruct* request = (SessionRequestStruct*) packet.payload(); m_sessionId = eqntohuint32((uint8_t*)&(request->sessionId)); m_maxLength = eqntohuint32((uint8_t*)&(request->maxLength)); // Sanity check the max length requested if (m_maxLength > maxPacketSize) { seqWarn("EQPacket: SessionRequest wanted a max packet size of %d which is above our sane max packet size of %d. Using our max", m_maxLength, maxPacketSize); m_maxLength = maxPacketSize; } emit maxLength((int) m_maxLength, (int) m_streamid); #if defined(PACKET_PROCESS_DIAG) || defined(PACKET_SESSION_DIAG) seqDebug("EQPacket: SessionRequest found, resetting expected seq, stream %s (%d) (session tracking %s)", EQStreamStr[m_streamid], m_streamid, (m_session_tracking_enabled == 2 ? "locked on" : (m_session_tracking_enabled == 1 ? "enabled" : "disabled"))); #endif #if defined(PACKET_SESSION_DIAG) seqDebug("EQPacket: SessionRequest %s:%u->%s:%u, sessionId %u maxLength %u, awaiting key for stream %s (%d)", ((EQUDPIPPacketFormat&) packet).getIPv4SourceA().ascii(), ((EQUDPIPPacketFormat&) packet).getSourcePort(), ((EQUDPIPPacketFormat&) packet).getIPv4DestA().ascii(), ((EQUDPIPPacketFormat&) packet).getDestPort(), m_sessionId, m_maxLength, EQStreamStr[m_streamid], m_streamid); #endif #if defined(PACKET_SESSION_DIAG) && (PACKET_SESSION_DIAG > 1) seqDebug("EQPacket: SessionRequest contents: unknown %u, sessionId %u, maxLength %u", eqntohuint32((uint8_t*)&(request->unknown0000)), m_sessionId, m_maxLength); #endif #if defined(PACKET_SESSION_DIAG) && (PACKET_SESSION_DIAG > 2) seqDebug("EQPacket: Raw SessionRequest: %02x%02x %02x%02x %02x%02x %02x%02x %02x%02x %02x%02x", packet.payload()[0], packet.payload()[1], packet.payload()[2], packet.payload()[3], packet.payload()[4], packet.payload()[5], packet.payload()[6], packet.payload()[7], packet.payload()[8], packet.payload()[9], packet.payload()[10], packet.payload()[11]); #endif m_arqSeqExp = 0; m_arqSeqFound = true; if (m_session_tracking_enabled) { // Save off client port for the stream so we can match against it // later. SessionRequest should always be an outer protocol packet // so we can cast it to EQUDPIPPacketFormat to get the ip headers. m_sessionClientPort = ((EQUDPIPPacketFormat&) packet).getSourcePort(); } } break; case OP_SessionResponse: { // Session response from server // Sanity check the size. Don't assume any packet we see is an EQ // session response, since we're gonna cause a huge freakin' malloc // on the maxlength of the session which for some reason some people // won't enjoy! if (packet.payloadLength() != sizeof(SessionResponseStruct)) { // Either SessionResponseStruct changed or this isn't a session // response. #if defined(PACKET_PROCESS_DIAG) || defined(PACKET_SESSION_DIAG) seqDebug("EQPacket: Ignoring SessionResponse %s:%u->%s:%u with invalid size %d.", ((EQUDPIPPacketFormat&) packet).getIPv4SourceA().ascii(), ((EQUDPIPPacketFormat&) packet).getSourcePort(), ((EQUDPIPPacketFormat&) packet).getIPv4DestA().ascii(), ((EQUDPIPPacketFormat&) packet).getDestPort(), packet.payloadLength()); #endif break; } // Pull off session response information SessionResponseStruct* response = (SessionResponseStruct*) packet.payload(); m_maxLength = eqntohuint32((uint8_t*)&(response->maxLength)); m_sessionKey = eqntohuint32((uint8_t*)&(response->key)); m_sessionId = eqntohuint32((uint8_t*)&(response->sessionId)); // Sanity check the max length requested if (m_maxLength > maxPacketSize) { seqWarn("EQPacket: SessionResponse wanted a max packet size of %d which is above our sane max packet size of %d. Using our max", m_maxLength, maxPacketSize); m_maxLength = maxPacketSize; } emit maxLength((int) m_maxLength, (int) m_streamid); #if defined(PACKET_PROCESS_DIAG) || defined(PACKET_SESSION_DIAG) seqDebug("EQPacket: SessionResponse found %s:%u->%s:%u, resetting expected seq, stream %s (%d) (session tracking %s)", ((EQUDPIPPacketFormat&) packet).getIPv4SourceA().ascii(), ((EQUDPIPPacketFormat&) packet).getSourcePort(), ((EQUDPIPPacketFormat&) packet).getIPv4DestA().ascii(), ((EQUDPIPPacketFormat&) packet).getDestPort(), EQStreamStr[m_streamid], m_streamid, (m_session_tracking_enabled == 2 ? "locked on" : (m_session_tracking_enabled == 1 ? "enabled" : "disabled"))); #endif #if defined(PACKET_SESSION_DIAG) seqDebug("EQPacket: SessionResponse sessionId %u maxLength %u, key is %u for stream %s (%d)", m_sessionId, m_maxLength, m_sessionKey, EQStreamStr[m_streamid], m_streamid); #endif #if defined(PACKET_SESSION_DIAG) && (PACKET_SESSION_DIAG > 1) seqDebug("EQPacket: SessionResponse contents: sessionId %u, key %u, unknown %u, unknown %u, maxLength %u, unknown %u", m_sessionId, m_sessionKey, eqntohuint16((uint8_t*)&(response->unknown0008)), response->unknown0010, m_maxLength, eqntohuint32((uint8_t*) &(response->unknown0015))); #endif #if defined(PACKET_SESSION_DIAG) && (PACKET_SESSION_DIAG > 2) seqDebug("EQPacket: Raw SessionResponse: %02x%02x %02x%02x %02x%02x %02x%02x %02x%02x %02x%02x %02x%02x %02x%02x %02x%02x %02x", packet.payload()[0], packet.payload()[1], packet.payload()[2], packet.payload()[3], packet.payload()[4], packet.payload()[5], packet.payload()[6], packet.payload()[7], packet.payload()[8], packet.payload()[9], packet.payload()[10], packet.payload()[11], packet.payload()[12], packet.payload()[13], packet.payload()[14], packet.payload()[15], packet.payload()[16], packet.payload()[17], packet.payload()[18]); #endif // Provide key to corresponding stream from this session/stream emit sessionKey(m_sessionId, m_streamid, m_sessionKey); m_arqSeqExp = 0; m_arqSeqFound = true; // Session tracking if (m_session_tracking_enabled) { // Save off client port for the stream so we can match against it // later. SessionRequest should always be an outer protocol packet // so we can cast it to EQUDPIPPacketFormat to get the ip headers. m_sessionClientPort = ((EQUDPIPPacketFormat&) packet).getDestPort(); // If this is the world server talking to us, reset session tracking if // it is on so we unlatch the client in case of getting kicked. if (m_streamid == world2client) { m_session_tracking_enabled = 1; emit sessionTrackingChanged(m_session_tracking_enabled); } // If this is the zone server talking to us, close the latch and lock else if (m_streamid == zone2client) { // SessionResponse should always be an outer protocol packet, so // the EQProtocolPacket passed in can be cast back to // EQUDPIPPacketFormat, which we need to go to get access to the IP // headers! m_session_tracking_enabled = 2; emit lockOnClient(((EQUDPIPPacketFormat&) packet).getSourcePort(), ((EQUDPIPPacketFormat&) packet).getDestPort()); emit sessionTrackingChanged(m_session_tracking_enabled); } } } break; case OP_SessionDisconnect: { #if defined(PACKET_PROCESS_DIAG) || defined(PACKET_SESSION_DIAG) seqDebug("EQPacket: SessionDisconnect found %s:%u->%s:%u, resetting expected seq, stream %s (%d) (session tracking %s)", ((EQUDPIPPacketFormat&) packet).getIPv4SourceA().ascii(), ((EQUDPIPPacketFormat&) packet).getSourcePort(), ((EQUDPIPPacketFormat&) packet).getIPv4DestA().ascii(), ((EQUDPIPPacketFormat&) packet).getDestPort(), EQStreamStr[m_streamid], m_streamid, (m_session_tracking_enabled == 2 ? "locked on" : (m_session_tracking_enabled == 1 ? "enabled" : "disabled"))); #endif #if defined(PACKET_SESSION_DIAG) && (PACKET_SESSION_DIAG > 2) seqDebug("EQPacket: Raw SessionDisconnect: %02x%02x %02x%02x %02x%02x %02x%02x", packet.payload()[0], packet.payload()[1], packet.payload()[2], packet.payload()[3], packet.payload()[4], packet.payload()[5], packet.payload()[6], packet.payload()[7]); #endif m_arqSeqExp = 0; // Clear cache resetCache(); // Signal closing. Unlatch session tracking if it is on. if (m_session_tracking_enabled) { m_session_tracking_enabled = 1; emit sessionTrackingChanged(m_session_tracking_enabled); m_sessionClientPort = 0; } emit closing(m_sessionId, m_streamid); } break; case OP_Ack: case OP_AckFuture: case OP_AckAfterDisconnect: { #if defined(PACKET_PROCESS_DIAG) && (PACKET_PROCESS_DIAG > 2) seqDebug("EQPacket: no-op on ACK for net opcode %04x seq %04x, stream %s (%d)", packet.getNetOpCode(), eqntohuint16(packet.payload()), EQStreamStr[m_streamid], m_streamid); #endif } break; case OP_KeepAlive: case OP_SessionStatRequest: case OP_SessionStatResponse: { #if defined(PACKET_PROCESS_DIAG) && (PACKET_PROCESS_DIAG > 2) seqDebug("EQPacket: no-op on stats for net opcode %04x, stream %s (%d)", packet.getNetOpCode(), EQStreamStr[m_streamid], m_streamid); #endif } break; default : { seqWarn("EQPacket: Unhandled net opcode %04x, stream %s, size %d", packet.getNetOpCode(), EQStreamStr[m_streamid], packet.payloadLength()); } } }
//////////////////////////////////////////////////// // Cache processing void EQPacketStream::processCache() { #if defined(PACKET_CACHE_DIAG) seqDebug("SEQ: START checking stream %s cache, arq %04x, cache count %04d", EQStreamStr[m_streamid], m_arqSeqExp, m_cache.size()); #endif EQPacketMap::iterator it; EQPacketMap::iterator eraseIt; EQProtocolPacket* packet; // check if the cache has grown large enough that we should give up // on seeing the current serverArqSeqExp // // If people see this a lot, they either have pathetic network cards, or // are having problems keeping up with packets (slow computer? Too much // net traffic?). Some possible solutions to this are to turn on session // tracking to filter out more PF_PACKET packets from getting passed out of // the kernel and to up the socket receive buffer sizes. See FAQ for // more information. if (m_cache.size() >= m_arqSeqGiveUp) { // ok, if the expected server arq sequence isn't here yet, give up // attempt to find the current expencted arq seq it = m_cache.find(m_arqSeqExp); // keep trying to find a new serverArqSeqExp if we haven't found a good // one yet... while(it == m_cache.end()) { seqWarn("SEQ: Giving up on finding arq %04x in stream %s cache, skipping!", m_arqSeqExp, EQStreamStr[m_streamid]); // incremente the expected arq sequence number m_arqSeqExp++; emit seqExpect(m_arqSeqExp, (int)m_streamid); // attempt to find the new current expencted arq seq it = m_cache.find(m_arqSeqExp); } } else { // haven't given up yet, just try to find the current serverArqSeqExp // attempt to find the current expected ARQ seq it = m_cache.find(m_arqSeqExp); } // iterate over cache until we reach the end or run out of // immediate followers while (it != m_cache.end()) { // get the PacketFormat for the iterator packet = it->second; // make sure this is the expected packet // (we might have incremented to the one after the one returned // by find above). if (packet->arqSeq() != m_arqSeqExp) break; #ifdef PACKET_CACHE_DIAG seqDebug("SEQ: found next arq %04x in stream %s cache, cache count %04d", m_arqSeqExp, EQStreamStr[m_streamid], m_cache.size()); #endif // validate the packet with a crc check. If the packet is for an old // session, we probably shouldn't be using it! #ifdef APPLY_CRC_CHECK if (packet->hasCRC() && packet->crc() != calculateCRC(*packet)) { #if defined (PACKET_CACHE_DIAG) // Something's screwed up seqDebug("SEQ: INVALID PACKET: Bad CRC in packet in stream %s cache with arq %04x! Droping it, but leaving expected seq as %04x", EQStreamStr[m_streamid], packet->arqSeq(), m_arqSeqExp); #endif // Need to drop from the cache eraseIt = it; // increment the current position iterator it++; // erase the packet from the cache m_cache.erase(eraseIt); emit cacheSize(m_cache.size(), (int)m_streamid); #ifdef PACKET_CACHE_DIAG seqDebug("SEQ: REMOVING arq %04x from stream %s cache, cache count %04d", packet->arqSeq(), EQStreamStr[m_streamid], m_cache.size()); #endif // delete the packet delete packet; // No sense looping some more. break; } else #endif /* APPLY_CRC_CHECK */ { #if defined (PACKET_CACHE_DIAG) && (PACKET_CACHE_DIAG > 2) seqDebug("SEQ: Found next arq in stream %s cache, incrementing arq seq, %04x", EQStreamStr[m_streamid], packet->arqSeq()); #endif // Process the packet since it's next in the sequence and was just // received out of order processPacket(*packet, packet->isSubpacket()); // Need to drop from the cache eraseIt = it; // increment the current position iterator it++; // erase the packet from the cache m_cache.erase(eraseIt); emit cacheSize(m_cache.size(), (int)m_streamid); #ifdef PACKET_CACHE_DIAG seqDebug("SEQ: REMOVING arq %04x from stream %s cache, cache count %04d", packet->arqSeq(), EQStreamStr[m_streamid], m_cache.size()); #endif // delete the packet delete packet; if (m_arqSeqExp == 0) it = m_cache.begin(); } } #ifdef PACKET_CACHE_DIAG seqDebug("SEQ: FINISHED checking stream %s cache, arq %04x, cache count %04d", EQStreamStr[m_streamid], m_arqSeqExp, m_cache.size()); #endif }
/////////////////////////////////////////////////////////////// // Calculate the CRC on the given packet using this stream's key uint16_t EQPacketStream::calculateCRC(EQProtocolPacket& packet) { // CRC is at the end of the raw payload, 2 bytes. return ::calcCRC16(packet.rawPacket(), packet.rawPacketLength()-2, m_sessionKey); }
///////////////////////////////////////////////////// // Handle a protocol level packet. This could be either a top-level // EQUDPIPPacket or a subpacket that is just an EQProtocolPacket. Either way // we use net opcodes here. void EQPacketStream::processPacket(EQProtocolPacket& packet, bool isSubpacket) { #if defined(PACKET_PROCESS_DIAG) && (PACKET_PROCESS_DIAG > 2) seqDebug("-->EQPacketStream::processPacket, subpacket=%s on stream %s (%d)", (isSubpacket ? "true" : "false"), EQStreamStr[m_streamid], m_streamid); #endif if (IS_APP_OPCODE(packet.getNetOpCode())) { // This is an app-opcode directly on the wire with no wrapping protocol // information. Weird, but whatever gets the stream read, right? dispatchPacket(packet.payload(), packet.payloadLength(), packet.getNetOpCode(), m_opcodeDB.find(packet.getNetOpCode())); return; } // Process the net opcode switch (packet.getNetOpCode()) { case OP_Combined: { #if defined(PACKET_PROCESS_DIAG) && (PACKET_PROCESS_DIAG > 2) seqDebug("EQPacket: found combined packet (net op: %04x, size %d) on stream %s (%d). Unrolling.", packet.getNetOpCode(), packet.payloadLength(), EQStreamStr[m_streamid], m_streamid); #endif // Rolled up multiple packets inside this packet. Need to unroll them // and process them individually. subpacket starts after the net opcode. uint8_t* subpacket = packet.payload(); while (subpacket < packet.payload() + packet.payloadLength()) { // Length specified first on the wire. uint8_t subpacketLength = subpacket[0]; // Move past the length subpacket++; // OpCode (in net order) uint16_t subOpCode = *(uint16_t*)subpacket; #if defined(PACKET_PROCESS_DIAG) && (PACKET_PROCESS_DIAG > 2) seqDebug("EQPacket: unrolling length %d bytes from combined packet on stream %s (%d). Opcode %04x", subpacketLength, EQStreamStr[m_streamid], m_streamid, subOpCode); #endif // Opcode is next. Net opcode or app opcode? if (IS_NET_OPCODE(subOpCode)) { #if defined(PACKET_PROCESS_DIAG) && (PACKET_PROCESS_DIAG > 2) seqDebug("EQPacket: processing unrolled net opcode, length %d bytes from combined packet on stream %s (%d). Opcode %04x", subpacketLength, EQStreamStr[m_streamid], m_streamid, subOpCode); #endif // Net opcode. false = copy. true = subpacket EQProtocolPacket spacket(subpacket, subpacketLength, false, true); processPacket(spacket, true); } else { #if defined(PACKET_PROCESS_DIAG) && (PACKET_PROCESS_DIAG > 2) seqDebug("EQPacket: processing unrolled app opcode, length %d bytes from combined packet on stream %s (%d). Opcode %04x", subpacketLength-2, EQStreamStr[m_streamid], m_streamid, subOpCode); #endif // App opcode. Dispatch it, skipping opcode. dispatchPacket(&subpacket[2], subpacketLength-2, subOpCode, m_opcodeDB.find(subOpCode)); } subpacket += subpacketLength; } } break; case OP_AppCombined: { #if defined(PACKET_PROCESS_DIAG) && (PACKET_PROCESS_DIAG > 2) seqDebug("EQPacket: found appcombined packet (net op: %04x, size %d) on stream %s (%d). Unrolling.", packet.getNetOpCode(), packet.payloadLength(), EQStreamStr[m_streamid], m_streamid); #endif // Multiple app op codes in the same packet. Need to unroll and dispatch // them. uint8_t* subpacket = packet.payload(); while (subpacket < packet.payload() + packet.payloadLength()) { // Length specified first on the wire. uint8_t subpacketLength = subpacket[0]; // Move past the length subpacket++; if (subpacketLength != 0xff) { // Dispatch app op code using given packet length. Net order! uint16_t subOpCode = *(uint16_t*)(subpacket); #if defined(PACKET_PROCESS_DIAG) && (PACKET_PROCESS_DIAG > 2) seqDebug("EQPacket: unrolling length %d bytes from combined packet on stream %s (%d). Opcode %04x", subpacketLength, EQStreamStr[m_streamid], m_streamid, subOpCode); seqDebug("EQPacket: processing unrolled app opcode, length %d bytes from combined packet on stream %s (%d). Opcode %04x", subpacketLength-2, EQStreamStr[m_streamid], m_streamid, subOpCode); #endif // Dispatch, skipping op code. dispatchPacket(&subpacket[2], subpacketLength-2, subOpCode, m_opcodeDB.find(subOpCode)); // Move ahead subpacket += subpacketLength; } else { // If original length is 0xff, it means it is a long one. The length // is 2 bytes and next. uint16_t longOne = eqntohuint16(subpacket); // Move past the 2 byte length subpacket += 2; // OpCode next. Net order for op codes. uint16_t subOpCode = *(uint16_t*)subpacket; #if defined(PACKET_PROCESS_DIAG) && (PACKET_PROCESS_DIAG > 2) seqDebug("EQPacket: unrolling length %d bytes from combined packet on stream %s (%d). Opcode %04x", longOne, EQStreamStr[m_streamid], m_streamid, subOpCode); seqDebug("EQPacket: processing unrolled app opcode, length %d bytes from combined packet on stream %s (%d). Opcode %04x", longOne-2, EQStreamStr[m_streamid], m_streamid, subOpCode); #endif // Dispatch, skipping op code. dispatchPacket(&subpacket[2], longOne-2, subOpCode, m_opcodeDB.find(subOpCode)); // Move ahead subpacket += longOne; } } } break; case OP_Packet: { // Normal unfragmented sequenced packet. uint16_t seq = eqntohuint16(packet.payload()); emit seqReceive(seq, (int)m_streamid); if (seq >= m_arqSeqExp) { // Future packet? if (seq == m_arqSeqExp) { // Expected packet. m_arqSeqExp++; emit seqExpect(m_arqSeqExp, (int)m_streamid); // OpCode next. Net order for op codes. uint16_t subOpCode = *(uint16_t*)(&packet.payload()[2]); #if defined(PACKET_PROCESS_DIAG) && (PACKET_PROCESS_DIAG > 1) seqDebug("SEQ: Found next sequence number in data stream %s (%d), incrementing expected seq, %04x (op code %04x, sub opcode %04x)", EQStreamStr[m_streamid], m_streamid, seq, packet.getNetOpCode(), subOpCode); #endif // App opcode or net opcode? if (IS_NET_OPCODE(subOpCode)) { // Net opcode. false = no copy. true = subpacket. EQProtocolPacket spacket(&packet.payload()[2], packet.payloadLength()-2, false, true); processPacket(spacket, true); } else { // App opcode. Dispatch, skipping seq and opcode. dispatchPacket(&packet.payload()[4], packet.payloadLength()-4, subOpCode, m_opcodeDB.find(subOpCode)); } } else if (seq < (uint32_t(m_arqSeqExp + arqSeqWrapCutoff)) || seq < (int32_t(m_arqSeqExp - arqSeqWrapCutoff))) { // Yeah, future packet. Push it on the packet cache. #ifdef PACKET_PROCESS_DIAG seqDebug("SEQ: out of order sequence %04x stream %s (%d) expecting %04x, sending to cache, %04d", seq, EQStreamStr[m_streamid], m_streamid, m_arqSeqExp, m_cache.size()); #endif setCache(seq, packet); } else { // Past packet outside the cut off seqWarn("SEQ: received sequenced %spacket outside the bounds of reasonableness. Expecting seq=%04x got seq=%04x, reasonableness being %d in the future.", (isSubpacket ? "sub" : ""), m_arqSeqExp, seq, arqSeqWrapCutoff); } } else { // Spooky packet from the past. Boo! #if defined(PACKET_PROCESS_DIAG) && (PACKET_PROCESS_DIAG > 1) seqDebug("discarding %spacket netopcode=%04x seq=%d size=%d on stream %s (%d). Packet is in the past. We've moved on.", (isSubpacket ? "sub" : ""), packet.getNetOpCode(), seq, packet.payloadLength(), EQStreamStr[m_streamid], m_streamid); #endif } } break; case OP_Oversized: { // Fragmented sequenced data packet. uint16_t seq = eqntohuint16(packet.payload()); emit seqReceive(seq, (int)m_streamid); if (seq >= m_arqSeqExp) { // Future packet? if (seq > m_arqSeqExp) { // Yeah, future packet. Push it on the packet cache. #if defined(PACKET_PROCESS_DIAG) && (PACKET_PROCESS_DIAG > 1) seqDebug("SEQ: out of order sequence %04x stream %s (%d) expecting %04x, sending to cache, %04d", seq, EQStreamStr[m_streamid], m_streamid, m_arqSeqExp, m_cache.size()); #endif setCache(seq, packet); } else { // Expected packet. m_arqSeqExp++; emit seqExpect(m_arqSeqExp, (int)m_streamid); #if defined(PACKET_PROCESS_DIAG) && (PACKET_PROCESS_DIAG > 1) seqDebug("SEQ: Found next sequence number in data stream %s (%d), incrementing expected seq, %04x (op code %04x)", EQStreamStr[m_streamid], m_streamid, seq, packet.getNetOpCode()); #endif // Push the fragment on. m_fragment.addFragment(packet); if (m_fragment.isComplete()) { // OpCode from fragment. In network order. uint16_t fragOpCode = *(uint16_t*)(m_fragment.data()); #ifdef PACKET_PROCESS_DIAG seqDebug("SEQ: Completed oversized app packet on stream %s with seq %04x, total size %d opcode %04x", EQStreamStr[m_streamid], seq, m_fragment.size()-2, fragOpCode); #endif // dispatch fragment. Skip opcode. dispatchPacket(&m_fragment.data()[2], m_fragment.size()-2, fragOpCode, m_opcodeDB.find(fragOpCode)); m_fragment.reset(); } } } else { // Spooky packet from the past. Boo! #if defined(PACKET_PROCESS_DIAG) && (PACKET_PROCESS_DIAG > 1) seqDebug("discarding packet netopcode=%04x seq=%d size=%d on stream %s (%d). Packet is in the past. We've moved on.", packet.getNetOpCode(), seq, packet.payloadLength(), EQStreamStr[m_streamid], m_streamid); #endif } } break; case OP_SessionRequest: { // Session request from client to server. #if defined(PACKET_PROCESS_DIAG) || defined(PACKET_SESSION_DIAG) seqDebug("EQPacket: SessionRequest found, resetting expected seq, stream %s (%d) (session tracking %s)", EQStreamStr[m_streamid], m_streamid, (m_session_tracking_enabled == 2 ? "locked on" : (m_session_tracking_enabled == 1 ? "enabled" : "disabled"))); #endif // Pull off session request information SessionRequestStruct* request = (SessionRequestStruct*) packet.payload(); m_sessionId = eqntohuint32((uint8_t*)&(request->sessionId)); m_maxLength = eqntohuint32((uint8_t*)&(request->maxLength)); #if defined(PACKET_SESSION_DIAG) seqDebug("EQPacket: SessionRequest sessionId %u maxLength %u, awaiting key for stream %s (%d)", m_sessionId, m_maxLength, EQStreamStr[m_streamid], m_streamid); #endif #if defined(PACKET_SESSION_DIAG) && (PACKET_SESSION_DIAG > 1) seqDebug("EQPacket: SessionRequest contents: unknown %u, sessionId %u, maxLength %u", eqntohuint32((uint8_t*)&(request->unknown0000)), m_sessionId, m_maxLength); #endif m_arqSeqExp = 0; m_arqSeqFound = true; } break; case OP_SessionResponse: { // Session response from server #if defined(PACKET_PROCESS_DIAG) || defined(PACKET_SESSION_DIAG) seqDebug("EQPacket: SessionResponse found, resetting expected seq, stream %s (%d) (session tracking %s)", EQStreamStr[m_streamid], m_streamid, (m_session_tracking_enabled == 2 ? "locked on" : (m_session_tracking_enabled == 1 ? "enabled" : "disabled"))); #endif // Pull off session response information SessionResponseStruct* response = (SessionResponseStruct*) packet.payload(); m_maxLength = eqntohuint32((uint8_t*)&(response->maxLength)); m_sessionKey = eqntohuint32((uint8_t*)&(response->key)); m_sessionId = eqntohuint32((uint8_t*)&(response->sessionId)); #if defined(PACKET_SESSION_DIAG) seqDebug("EQPacket: SessionResponse sessionId %u maxLength %u, key is %u for stream %s (%d)", m_sessionId, m_maxLength, m_sessionKey, EQStreamStr[m_streamid], m_streamid); #endif #if defined(PACKET_SESSION_DIAG) && (PACKET_SESSION_DIAG > 1) seqDebug("EQPacket: SessionResponse contents: sessionId %u, key %u, unknown %u, unknown %u, maxLength %u, unknown %u", m_sessionId, m_sessionKey, eqntohuint16((uint8_t*)&(response->unknown0008)), response->unknown0010, m_maxLength, eqntohuint32((uint8_t*) &(response->unknown0015))); #endif // Provide key to corresponding stream from this session/stream emit sessionKey(m_sessionId, m_streamid, m_sessionKey); m_arqSeqExp = 0; m_arqSeqFound = true; // Session tracking if (m_session_tracking_enabled) { // If this is the world server talking to us, reset session tracking if // it is on so we unlatch the client in case of getting kicked. if (m_streamid == world2client) { m_session_tracking_enabled = 1; emit sessionTrackingChanged(m_session_tracking_enabled); } // If this is the zone server talking to us, close the latch and lock else if (m_streamid == zone2client) { // SessionResponse should always be an outer protocol packet, so // the EQProtocolPacket passed in can be cast back to // EQUDPIPPacketFormat, which we need to go to get access to the IP // headers! m_session_tracking_enabled = 2; emit lockOnClient(((EQUDPIPPacketFormat&) packet).getSourcePort(), ((EQUDPIPPacketFormat&) packet).getDestPort()); emit sessionTrackingChanged(m_session_tracking_enabled); } } } break; case OP_SessionDisconnect: { #if defined(PACKET_PROCESS_DIAG) || defined(PACKET_SESSION_DIAG) seqDebug("EQPacket: SessionDisconnect found, resetting expected seq, stream %s (%d) (session tracking %s)", EQStreamStr[m_streamid], m_streamid, (m_session_tracking_enabled == 2 ? "locked on" : (m_session_tracking_enabled == 1 ? "enabled" : "disabled"))); #endif m_arqSeqExp = 0; // Clear cache resetCache(); // Signal closing. Unlatch session tracking if it is on. if (m_session_tracking_enabled) { m_session_tracking_enabled = 1; emit sessionTrackingChanged(m_session_tracking_enabled); } emit closing(); } break; case OP_Ack: case OP_Resend: { #if defined(PACKET_PROCESS_DIAG) && (PACKET_PROCESS_DIAG > 2) seqDebug("EQPacket: no-op on for net opcode %04x seq %04x, stream %s (%d)", packet.getNetOpCode(), eqntohuint16(packet.payload()), EQStreamStr[m_streamid], m_streamid); #endif } break; case OP_KeepAlive: case OP_SessionStatRequest: case OP_SessionStatResponse: { #if defined(PACKET_PROCESS_DIAG) && (PACKET_PROCESS_DIAG > 2) seqDebug("EQPacket: no-op on for net opcode %04x, stream %s (%d)", packet.getNetOpCode(), EQStreamStr[m_streamid], m_streamid); #endif } break; default : { seqWarn("EQPacket: Unhandled net opcode %04x, stream %s, size %d", packet.getNetOpCode(), EQStreamStr[m_streamid], packet.payloadLength()); } } }
//////////////////////////////////////////////////// // Cache processing void EQPacketStream::processCache() { #if defined(PACKET_CACHE_DIAG) seqDebug("SEQ: START checking stream %s cache, arq %04x, cache count %04d", EQStreamStr[m_streamid], m_arqSeqExp, m_cache.size()); #endif EQPacketMap::iterator it; EQPacketMap::iterator eraseIt; EQProtocolPacket* packet; // check if the cache has grown large enough that we should give up // on seeing the current serverArqSeqExp // this should really only kick in for people with pathetic // network cards that missed the packet. if (m_cache.size() >= m_arqSeqGiveUp) { // ok, if the expected server arq sequence isn't here yet, give up // attempt to find the current expencted arq seq it = m_cache.find(m_arqSeqExp); // keep trying to find a new serverArqSeqExp if we haven't found a good // one yet... while(it == m_cache.end()) { seqDebug("SEQ: Giving up on finding arq %04x in stream %s cache, skipping!", m_arqSeqExp, EQStreamStr[m_streamid]); // incremente the expected arq sequence number m_arqSeqExp++; emit seqExpect(m_arqSeqExp, (int)m_streamid); // attempt to find the new current expencted arq seq it = m_cache.find(m_arqSeqExp); } } else { // haven't given up yet, just try to find the current serverArqSeqExp // attempt to find the current expected ARQ seq it = m_cache.find(m_arqSeqExp); } // iterate over cache until we reach the end or run out of // immediate followers while (it != m_cache.end()) { // get the PacketFormat for the iterator packet = it->second; // make sure this is the expected packet // (we might have incremented to the one after the one returned // by find above). if (packet->arqSeq() != m_arqSeqExp) break; #ifdef PACKET_CACHE_DIAG seqDebug("SEQ: found next arq %04x in stream %s cache, cache count %04d", m_arqSeqExp, EQStreamStr[m_streamid], m_cache.size()); #endif #if defined (PACKET_CACHE_DIAG) && (PACKET_CACHE_DIAG > 2) // validate the packet against a memory corruption if (!packet->isValid()) { // Something's screwed up seqDebug("SEQ: INVALID PACKET: Bad CRC in packet in stream %s cache with arq %04x!", EQStreamStr[m_streamid], packet->arqSeq()); } #endif #if defined (PACKET_CACHE_DIAG) && (PACKET_CACHE_DIAG > 2) seqDebug("SEQ: Found next arq in stream %s cache, incrementing arq seq, %04x", EQStreamStr[m_streamid], packet->arqSeq()); #endif // Process the packet since it's next in the sequence and was just // received out of order processPacket(*packet, packet->isSubpacket()); // Need to drop from the cache eraseIt = it; // increment the current position iterator it++; // erase the packet from the cache m_cache.erase(eraseIt); emit cacheSize(m_cache.size(), (int)m_streamid); #ifdef PACKET_CACHE_DIAG seqDebug("SEQ: REMOVING arq %04x from stream %s cache, cache count %04d", packet->arqSeq(), EQStreamStr[m_streamid], m_cache.size()); #endif // delete the packet delete packet; if (m_arqSeqExp == 0) it = m_cache.begin(); } #ifdef PACKET_CACHE_DIAG seqDebug("SEQ: FINISHED checking stream %s cache, arq %04x, cache count %04d", EQStreamStr[m_streamid], m_arqSeqExp, m_cache.size()); #endif }