Added support for varying log levels configurable in the server config (see log_level in default.conf)

Error logs now properly print to stderr when possible
Colour-coded logs
Addressed a scenario in which outgoing packet writes could get hung up
Fixed interface incorrect definition message on server startup
This commit is contained in:
Ceikry
2023-03-01 08:01:14 +00:00
committed by Ryan
parent e1faa64af7
commit 88a2f354b4
171 changed files with 723 additions and 475 deletions
+4 -1
View File
@@ -72,7 +72,10 @@ public class IoEventHandler {
session.disconnect();
if (session.getPlayer() != null)
session.getPlayer().clear(true);
} else e.printStackTrace();
} else {
key.cancel();
return;
}
}
buffer.flip();
if (session == null) {
@@ -1,5 +1,6 @@
package core.net.amsc;
import core.tools.Log;
import core.tools.SystemLogger;
import core.net.IoEventHandler;
import core.net.IoSession;
@@ -10,6 +11,8 @@ import java.nio.channels.Selector;
import java.nio.channels.SocketChannel;
import java.util.concurrent.Executors;
import static core.api.ContentAPIKt.log;
/**
* Handles the management server events.
* @author Emperor
@@ -38,7 +41,7 @@ public final class MSEventHandler extends IoEventHandler {
} catch (Throwable t) {
t.printStackTrace();
}
SystemLogger.logErr(this.getClass(), "Failed connecting to Management Server!");
log(this.getClass(), Log.ERR, "Failed connecting to Management Server!");
WorldCommunicator.terminate();
}
@@ -67,7 +67,6 @@ public final class WorldCommunicator {
*/
public static void connect() {
try {
SystemLogger.logInfo(WorldCommunicator.class, "Attempting to connect to management server...");
setState(ManagementServerState.CONNECTING);
/*if (isLocallyHosted()) {
SystemLogger.log("Management server is hosted on local machine!");
@@ -77,7 +76,6 @@ public final class WorldCommunicator {
//}
reactor.start();
} catch (Throwable e) {
SystemLogger.logErr(WorldCommunicator.class, "Unable to connect to management server");
e.printStackTrace();
terminate();
}
@@ -187,7 +185,6 @@ public final class WorldCommunicator {
if (WorldCommunicator.state != state) {
WorldCommunicator.state = state;
state.set();
SystemLogger.logInfo(WorldCommunicator.class, "Management server status: " + state + ".");
}
}
@@ -1,5 +1,6 @@
package core.net.event;
import core.tools.Log;
import core.tools.SystemLogger;
import core.net.IoReadEvent;
import core.net.IoSession;
@@ -10,6 +11,8 @@ import core.net.packet.in.Packet;
import java.nio.ByteBuffer;
import static core.api.ContentAPIKt.log;
/**
* Handles game packet reading.
* @author Emperor
@@ -65,9 +68,6 @@ public final class GameReadEvent extends IoReadEvent {
if (session == null || session.getPlayer() == null) {
continue;
}
if (opcode >= PACKET_SIZES.length) {
break;
}
int header = PACKET_SIZES[opcode];
int size = header;
if (header < 0) {
@@ -93,16 +93,20 @@ public final class GameReadEvent extends IoReadEvent {
byte[] data = new byte[size];
buffer.get(data);
IoBuffer buf = new IoBuffer(opcode, null, ByteBuffer.wrap(data));
//SystemLogger.log("Packet opcode " + opcode + "received.");
//IncomingPacket packet = PacketRepository.getIncoming(opcode);
session.setLastPing(System.currentTimeMillis());
last = opcode;
//Authentic per-player per-tick limit on inbound packets
if (session.getPlayer().opCounts[opcode]++ >= 10) {
log(this.getClass(), Log.FINE, "Skipping packet " + opcode + " because already received more than 10!");
return;
}
Packet processed = Decoders530.process(session.getPlayer(), opcode, buf);
if (processed instanceof Packet.UnhandledOp) {
SystemLogger.logWarn(this.getClass(), "Unhandled opcode: " + opcode);
log(this.getClass(), Log.WARN, "Unhandled opcode: " + opcode);
} else if (processed instanceof Packet.DecodingError) {
SystemLogger.logErr(this.getClass(), ((Packet.DecodingError) processed).getMessage());
log(this.getClass(), Log.ERR, ((Packet.DecodingError) processed).getMessage());
} else if (!(processed instanceof Packet.NoProcess)) {
PacketProcessor.enqueue(processed);
}
@@ -133,9 +137,9 @@ public final class GameReadEvent extends IoReadEvent {
return buffer.getShort() & 0xFFFF;
}
if(header == -3){
System.out.println(buffer.remaining());
}
SystemLogger.logErr(this.getClass(), "Invalid packet [opcode=" + opcode + ", last=" + last + ", queued=" + usedQueuedBuffer + "], header=" + header+"!");
log(this.getClass(), Log.ERR, "Invalid packet [opcode=" + opcode + ", last=" + last + ", queued=" + usedQueuedBuffer + "], header=" + header+"!");
return -1;
}
@@ -4,6 +4,7 @@ import core.net.IoReadEvent;
import core.net.IoSession;
import core.net.lobby.WorldList;
import core.net.registry.AccountRegister;
import core.tools.Log;
import core.tools.RandomFunction;
import core.tools.SystemLogger;
@@ -11,6 +12,8 @@ import java.nio.ByteBuffer;
import java.util.HashMap;
import java.util.Map;
import static core.api.ContentAPIKt.log;
/**
* Handles handshake read events.
* @author Emperor
@@ -47,7 +50,7 @@ public final class HSReadEvent extends IoReadEvent {
int revision = buffer.getInt();
//int sub_revision = buffer.getInt();
buffer.flip();
System.out.println(buffer.limit());
if (revision != 530 ){//|| sub_revision != Constants.CLIENT_BUILD) {
session.disconnect();
break;
@@ -64,7 +67,7 @@ public final class HSReadEvent extends IoReadEvent {
WorldList.sendUpdate(session, updateStamp);
break;
default:
SystemLogger.logInfo(this.getClass(), "PKT " + opcode);
log(this.getClass(), Log.FINE, "PKT " + opcode);
session.disconnect();
break;
}
@@ -25,7 +25,7 @@ public final class JS5ReadEvent extends IoReadEvent {
public void read(IoSession session, ByteBuffer buffer) {
while (buffer.hasRemaining()) {
int opcode = buffer.get() & 0xFF;
//System.out.println("JS5 initiated! Opcode: " + opcode);
if (buffer.remaining() < 3) {
queueBuffer(opcode);
return;
@@ -34,11 +34,11 @@ public final class JS5ReadEvent extends IoReadEvent {
case 0:
case 1:
int request = ByteBufferUtils.getMedium(buffer);
//System.out.println("Requested file " + request);
int container = request >> 16 & 0xFF;
//System.out.println("In container " + container);
int archive = request & 0xFFFF;
//System.out.println("In archive " + archive);
session.getJs5Queue().queue(container, archive, opcode == 1);
break;
case 2: // music
@@ -71,7 +71,7 @@ public final class JS5ReadEvent extends IoReadEvent {
session.disconnect();
return;
default:
System.out.println("Unhandled JS5 opcode " + opcode + "!");
buffer.get();
buffer.getShort();
break;
@@ -1,11 +1,14 @@
package core.net.event;
import core.tools.Log;
import core.tools.SystemLogger;
import core.net.IoReadEvent;
import core.net.IoSession;
import java.nio.ByteBuffer;
import static core.api.ContentAPIKt.log;
/**
* Handles reading Management server packets.
* @author Emperor
@@ -85,7 +88,7 @@ public final class MSReadEvent extends IoReadEvent {
}
return buffer.getShort() & 0xFFFF;
}
SystemLogger.logErr(this.getClass(), "Invalid packet [opcode=" + opcode + ", last=" + last + ", queued=" + usedQueuedBuffer + "]!");
log(this.getClass(), Log.ERR, "Invalid packet [opcode=" + opcode + ", last=" + last + ", queued=" + usedQueuedBuffer + "]!");
return -1;
}
@@ -1,5 +1,6 @@
package core.net.event;
import core.tools.Log;
import core.tools.SystemLogger;
import core.game.world.GameWorld;
import core.net.IoReadEvent;
@@ -10,6 +11,8 @@ import core.net.producer.MSEventProducer;
import java.nio.ByteBuffer;
import static core.api.ContentAPIKt.log;
/**
* Handles world registry read events.
* @author Emperor
@@ -36,23 +39,18 @@ public final class RegistryReadEvent extends IoReadEvent {
switch (opcode) {
case 0:
WorldCommunicator.setState(ManagementServerState.NOT_AVAILABLE);
SystemLogger.logErr(this.getClass(), "Failed registering world to AMS - [id=" + GameWorld.getSettings().getWorldId() + ", cause=World id out of bounds]!");
log(this.getClass(), Log.ERR, "Failed registering world to AMS - [id=" + GameWorld.getSettings().getWorldId() + ", cause=World id out of bounds]!");
break;
case 1:
session.setProducer(PRODUCER);
WorldCommunicator.setState(ManagementServerState.AVAILABLE);
SystemLogger.logInfo(this.getClass(), "Successfully registered world to AMS - [id=" + GameWorld.getSettings().getWorldId() + "]!");
break;
case 2:
WorldCommunicator.setState(ManagementServerState.NOT_AVAILABLE);
SystemLogger.logErr(this.getClass(), "Failed registering world to AMS - [id=" + GameWorld.getSettings().getWorldId() + ", cause=World id already in use]!");
case 3:
WorldCommunicator.setState(ManagementServerState.NOT_AVAILABLE);
break;
case 3:
WorldCommunicator.setState(ManagementServerState.NOT_AVAILABLE);
SystemLogger.logErr(this.getClass(), "Failed registering world to AMS - [id=" + GameWorld.getSettings().getWorldId() + ", cause=Exception in AMS]!");
break;
default:
System.out.println("??" + opcode);
default:
break;
}
}
@@ -42,6 +42,7 @@ import content.global.handlers.iface.ge.StockMarket
import content.global.skill.magic.SpellListener
import content.global.skill.magic.SpellListeners
import content.global.skill.magic.SpellUtils
import core.api.log
import core.game.interaction.*
import core.game.node.entity.player.info.LogType
import core.game.node.entity.player.info.PlayerMonitor
@@ -52,6 +53,7 @@ import core.game.world.GameWorld
import core.game.world.repository.Repository
import core.net.packet.`in`.Packet
import core.net.packet.`in`.RunScript
import core.tools.Log
import core.worker.ManagementEvents
import java.io.PrintWriter
import java.io.StringWriter
@@ -71,7 +73,7 @@ object PacketProcessor {
val pw = PrintWriter(sw)
var pkt: Packet
while (countThisCycle-- > 0) {
pkt = queue.tryPop(Packet.NoProcess())
pkt = queue.tryPop(Packet.NoProcess()) ?: return
if (pkt is Packet.NoProcess) {
queue.clear()
return
@@ -80,7 +82,7 @@ object PacketProcessor {
process(pkt)
} catch (e: Exception) {
e.printStackTrace(pw)
SystemLogger.logErr(this::class.java, "Error Processing ${pkt::class.java.simpleName}: $sw")
log(this::class.java, Log.ERR, "Error Processing ${pkt::class.java.simpleName}: $sw")
}
}
}
@@ -286,7 +288,7 @@ object PacketProcessor {
}
else -> SystemLogger.logWarn(this::class.java, "Unprocessed Packet: ${pkt::class.java.simpleName}")
else -> log(this::class.java, Log.WARN, "Unprocessed Packet: ${pkt::class.java.simpleName}")
}
}
@@ -2,11 +2,16 @@ package core.net.packet;
import core.net.packet.out.GrandExchangePacket;
import core.net.packet.out.*;
import core.tools.Log;
import core.tools.SystemLogger;
import java.io.PrintWriter;
import java.io.StringWriter;
import java.util.HashMap;
import java.util.Map;
import static core.api.ContentAPIKt.log;
/**
* The packet repository.
* @author Emperor
@@ -82,11 +87,18 @@ public final class PacketRepository {
if(context.getPlayer().getSession() == null) return;
OutgoingPacket p = OUTGOING_PACKETS.get(clazz);
if (p == null) {
SystemLogger.logErr(PacketRepository.class, "Invalid outgoing packet [handler=" + clazz + ", context=" + context + "].");
log(PacketRepository.class, Log.ERR, "Invalid outgoing packet [handler=" + clazz + ", context=" + context + "].");
return;
}
if(!context.getPlayer().isArtificial()) {
PacketWriteQueue.handle(p, context);
try {
PacketWriteQueue.handle(p, context);
} catch (Exception e) {
StringWriter sw = new StringWriter();
PrintWriter pw = new PrintWriter(sw);
e.printStackTrace(pw);
log(PacketRepository.class, Log.ERR, "Error writing packet out: " + sw);
}
}
}
@@ -1,7 +1,9 @@
package core.net.packet
import core.api.log
import core.api.tryPop
import core.net.packet.out.*
import core.tools.Log
import core.tools.SystemLogger
import java.io.PrintWriter
import java.io.StringWriter
@@ -10,7 +12,7 @@ import java.util.concurrent.locks.ReentrantLock
class PacketWriteQueue {
companion object {
private val packetsToWrite = LinkedList<QueuedPacket<*>?>()
private val packetsToWrite = LinkedList<QueuedPacket<*>>()
@JvmStatic
fun <T> handle(packet: OutgoingPacket<T>, context: T) {
@@ -27,6 +29,10 @@ class PacketWriteQueue {
@JvmStatic
fun <T> push(packet: OutgoingPacket<T>, context: T) {
if (context == null) {
log(this::class.java, Log.ERR, "${packet::class.java.simpleName} tried to queue with a null context!")
return
}
packetsToWrite.add(QueuedPacket(packet, context))
}
@@ -41,7 +47,7 @@ class PacketWriteQueue {
write(pkt.out, pkt.context)
} catch (e: Exception) {
e.printStackTrace(pw)
SystemLogger.logErr(this::class.java, "Error flushing packet ${pkt.out::class.java}: $sw")
log(this::class.java, Log.ERR, "Error flushing packet ${pkt.out::class.java}: $sw")
continue
}
}
@@ -1,8 +1,10 @@
package core.net.packet.`in`
import core.api.log
import core.Util.clamp
import core.game.node.entity.player.Player
import core.net.packet.IoBuffer
import core.tools.Log
import core.tools.StringUtils
import core.tools.SystemLogger
import java.io.PrintWriter
@@ -692,7 +694,7 @@ enum class Decoders530(val opcode: Int) {
3,4 -> QCPacketType.STANDARD
5 -> QCPacketType.SINGLE
7 -> QCPacketType.DOUBLE
else -> QCPacketType.UNHANDLED.also { SystemLogger.logWarn(this::class.java, "UNHANDLED QC PACKET TYPE Size ${x.array().size}") }
else -> QCPacketType.UNHANDLED.also { log(this::class.java, Log.WARN, "UNHANDLED QC PACKET TYPE Size ${x.array().size}") }
}
val forClan = (buffer.get() and 0xFF) == 1
@@ -711,7 +713,7 @@ enum class Decoders530(val opcode: Int) {
buffer.get() //discard
selection_b_index = buffer.get()
}
QCPacketType.UNHANDLED -> SystemLogger.logWarn(this::class.java, "Unhandled packet type, skipping remaining buffer contents.")
QCPacketType.UNHANDLED -> log(this::class.java, Log.WARN, "Unhandled packet type, skipping remaining buffer contents.")
else -> {}
}
return Packet.QuickChat(player, selection_a_index, selection_b_index, forClan, multiplier, offset, packetType)
+4 -2
View File
@@ -15,12 +15,14 @@ import core.ServerConstants
import core.ServerStore
import core.ServerStore.Companion.addToList
import core.ServerStore.Companion.getList
import core.api.log
import core.auth.AuthResponse
import core.game.node.entity.player.info.*
import core.game.node.entity.player.info.login.LoginParser
import core.tools.SystemLogger
import core.game.world.GameWorld
import core.game.world.repository.Repository
import core.tools.Log
import core.worker.ManagementEvents.publish
import java.math.BigInteger
import java.nio.BufferUnderflowException
@@ -45,7 +47,7 @@ object Login {
return Pair(AuthResponse.Updated, null)
}
if (info.opcode != NORMAL_LOGIN_OP && info.opcode != RECONNECT_LOGIN_OP) {
SystemLogger.logInfo(this::class.java, "Invalid Login Opcode: ${info.opcode}")
log(this::class.java, Log.WARN, "Invalid Login Opcode: ${info.opcode}")
return Pair(AuthResponse.InvalidLoginServer, null)
}
@@ -82,7 +84,7 @@ object Login {
return Pair(AuthResponse.Success, info)
} catch (e: Exception) {
SystemLogger.logErr(this::class.java, "Exception encountered during login packet parsing! See stack trace below.")
log(this::class.java, Log.ERR, "Exception encountered during login packet parsing! See stack trace below.")
e.printStackTrace()
return Pair(AuthResponse.UnexpectedError, null)
}
@@ -1,11 +1,13 @@
package core.net.packet.`in`
import core.api.log
import core.game.node.entity.player.Player
import core.net.packet.IncomingPacket
import core.net.packet.IoBuffer
import core.net.packet.QCRepository
import core.tools.SystemLogger
import core.game.world.GameWorld
import core.tools.Log
/**
* Decodes the quick chat packet
@@ -31,7 +33,7 @@ class QuickChatPacketHandler : IncomingPacket {
3,4 -> QCPacketType.STANDARD
5 -> QCPacketType.SINGLE
7 -> QCPacketType.DOUBLE
else -> QCPacketType.UNHANDLED.also { SystemLogger.logWarn(this::class.java, "UNHANDLED QC PACKET TYPE Size ${x.array().size}") }
else -> QCPacketType.UNHANDLED.also { log(this::class.java, Log.WARN, "UNHANDLED QC PACKET TYPE Size ${x.array().size}") }
}
val forClan = (buffer.get() and 0xFF) == 1
@@ -50,7 +52,7 @@ class QuickChatPacketHandler : IncomingPacket {
buffer.get() //discard
selection_b_index = buffer.get()
}
QCPacketType.UNHANDLED -> SystemLogger.logWarn(this::class.java, "Unhandled packet type, skipping remaining buffer contents.")
QCPacketType.UNHANDLED -> log(this::class.java, Log.WARN, "Unhandled packet type, skipping remaining buffer contents.")
else -> {}
}
@@ -58,12 +60,12 @@ class QuickChatPacketHandler : IncomingPacket {
//Prints the values of each byte in the buffer to server log
//If the world is in dev mode
if(GameWorld.settings?.isDevMode == true) {
SystemLogger.logInfo(this::class.java, "Begin QuickChat Packet Buffer Dump---------")
SystemLogger.logInfo(this::class.java, "Packet Type: ${packetType.name} Chat Type: ${if(forClan) "Clan" else "Public"}")
log(this::class.java, Log.FINE, "Begin QuickChat Packet Buffer Dump---------")
log(this::class.java, Log.FINE, "Packet Type: ${packetType.name} Chat Type: ${if(forClan) "Clan" else "Public"}")
x?.array()?.forEach {
SystemLogger.logInfo(this::class.java, "$it")
log(this::class.java, Log.FINE, "$it")
}
SystemLogger.logInfo(this::class.java, "End QuickChat Packet Buffer Dump-----------")
log(this::class.java, Log.FINE, "End QuickChat Packet Buffer Dump-----------")
}
QCRepository.sendQC(player,multiplier,offset,packetType,selection_a_index,selection_b_index,forClan)
@@ -41,7 +41,6 @@ public final class CommunicationMessage implements OutgoingPacket<MessageContext
case MessageContext.CLAN_MESSAGE:
ClanRepository clan = player.getCommunication().getClan();
if (clan == null) {
System.out.println("Player " + player.getUsername() + " was no longer in clan!");
return;
}
bytes = new byte[256];
@@ -23,8 +23,11 @@ public final class UpdateSceneGraph implements OutgoingPacket<SceneGraphContext>
for (int regionX = (player.getLocation().getRegionX() - 6) / 8; regionX <= ((player.getLocation().getRegionX() + 6) / 8); regionX++) {
for (int regionY = (player.getLocation().getRegionY() - 6) / 8; regionY <= ((player.getLocation().getRegionY() + 6) / 8); regionY++) {
int[] keys = XteaParser.Companion.getRegionXTEA(regionX << 8 | regionY);
for (int i = 0; i < keys.length; i++) {
buffer.putIntB(keys[i]);
for (int i = 0; i < 4; i++) {
if (keys != null)
buffer.putIntB(keys[i]);
else
buffer.putIntB(0);
}
}
}
@@ -6,6 +6,7 @@ import core.net.Constants;
import core.net.IoSession;
import core.ServerConstants;
import core.auth.UserAccountInfo;
import core.tools.Log;
import core.tools.SystemLogger;
import core.game.world.GameWorld;
import core.net.packet.in.Login;
@@ -14,6 +15,8 @@ import java.nio.ByteBuffer;
import java.util.regex.Matcher;
import java.util.regex.Pattern;
import static core.api.ContentAPIKt.log;
/**
* Handles the registry of new accounts.
* @author Vexia
@@ -50,11 +53,11 @@ public class AccountRegister {
break;
}
if (invalidUsername(username)) {
System.out.println("AHAHHA " + username);
response(session,RegistryResponse.INVALID_USERNAME);
break;
}
System.out.println(username);
if (!GameWorld.getAuthenticator().canCreateAccountWith(info)) {
response(session, RegistryResponse.NOT_AVAILBLE_USER);
return;
@@ -62,11 +65,10 @@ public class AccountRegister {
response(session, RegistryResponse.SUCCESS);
break;
case 36://Register details
SystemLogger.logInfo(AccountRegister.class, "Made it to final stage");
buffer.get(); //Useless size being written that is already written in the RSA block
buffer = Login.decryptRSABuffer(buffer, ServerConstants.EXPONENT, ServerConstants.MODULUS);
if(buffer.get() != 10){ //RSA header (aka did this decrypt properly)
SystemLogger.logInfo(AccountRegister.class, "Decryption failed during registration :(");
log(AccountRegister.class, Log.ERR, "Decryption failed during registration :(");
response(session, RegistryResponse.CANNOT_CREATE);
break;
}
@@ -115,7 +117,7 @@ public class AccountRegister {
});
break;
default:
SystemLogger.logErr(AccountRegister.class, "Unhandled account registry opcode = " + opcode);
log(AccountRegister.class, Log.ERR, "Unhandled account registry opcode = " + opcode);
break;
}
}