diff --git a/generator/src/main/java/io/github/lonamiwebs/overgram/generator/Generator.java b/generator/src/main/java/io/github/lonamiwebs/overgram/generator/Generator.java index c6b1f6d..010385c 100644 --- a/generator/src/main/java/io/github/lonamiwebs/overgram/generator/Generator.java +++ b/generator/src/main/java/io/github/lonamiwebs/overgram/generator/Generator.java @@ -142,7 +142,7 @@ public class Generator { } writer.write("default:\n"); - writer.write("throw new ClassNotFoundException();\n"); + writer.write("throw new ClassNotFoundException(Integer.toHexString(id));\n"); writer.write("}\n"); writer.write("}\n"); } diff --git a/lib/src/main/java/io/github/lonamiwebs/overgram/logging/Log.java b/lib/src/main/java/io/github/lonamiwebs/overgram/logging/Log.java new file mode 100644 index 0000000..32ad012 --- /dev/null +++ b/lib/src/main/java/io/github/lonamiwebs/overgram/logging/Log.java @@ -0,0 +1,63 @@ +package io.github.lonamiwebs.overgram.logging; + +import java.io.PrintStream; +import java.util.IllegalFormatConversionException; + +public class Log { + private static final int LEVEL; + private static final PrintStream OUTPUT; + + // Level - Name + // 1 - debug + // 2 - info + // 3 - warning + // 4 - error/exception + // 5 - none + static { + LEVEL = 1; + OUTPUT = System.err; + } + + public static void debug(final Object message, final Object... args) { + if (LEVEL <= 1 && OUTPUT != null) { + show(message, args); + } + } + + public static void info(final Object message, final Object... args) { + if (LEVEL <= 2 && OUTPUT != null) { + show(message, args); + } + } + + public static void warn(final Object message, final Object... args) { + if (LEVEL <= 3 && OUTPUT != null) { + show(message, args); + } + } + + public static void error(final Object message, final Object... args) { + if (LEVEL <= 4 && OUTPUT != null) { + show(message, args); + } + } + + public static void exception(final Throwable exception, final Object message, final Object... args) { + if (LEVEL <= 4 && OUTPUT != null) { + show(message, args); + exception.printStackTrace(OUTPUT); + } + } + + private static void show(Object message, Object... args) { + if (args.length == 0) { + OUTPUT.println(message); + } else { + try { + OUTPUT.println(String.format(message.toString(), args)); + } catch (IllegalFormatConversionException ignored) { + OUTPUT.println(message); + } + } + } +} diff --git a/lib/src/main/java/io/github/lonamiwebs/overgram/network/MTProtoPlainSender.java b/lib/src/main/java/io/github/lonamiwebs/overgram/network/MTProtoPlainSender.java index 1e4a72c..b281c4e 100644 --- a/lib/src/main/java/io/github/lonamiwebs/overgram/network/MTProtoPlainSender.java +++ b/lib/src/main/java/io/github/lonamiwebs/overgram/network/MTProtoPlainSender.java @@ -1,5 +1,6 @@ package io.github.lonamiwebs.overgram.network; +import io.github.lonamiwebs.overgram.logging.Log; import io.github.lonamiwebs.overgram.network.connection.Connection; import io.github.lonamiwebs.overgram.tl.TLObject; import io.github.lonamiwebs.overgram.tl.TLRequest; @@ -26,6 +27,9 @@ public class MTProtoPlainSender { final byte[] requestBytes = writer.toBytes(); writer.clear(); + Log.debug("Sending plain message %d of %d bytes %s", + msgId, requestBytes.length, request.getClass().getName()); + writer.write(0L); writer.write(msgId); writer.write(requestBytes.length); @@ -52,6 +56,10 @@ public class MTProtoPlainSender { assert length > 0; //noinspection unchecked - return (T) reader.readTl(); + final T result = (T) reader.readTl(); + Log.debug("Received plain message %d of %d bytes %s", + serverMsgId, length, result.getClass().getName()); + + return result; } } diff --git a/lib/src/main/java/io/github/lonamiwebs/overgram/network/MTProtoSender.java b/lib/src/main/java/io/github/lonamiwebs/overgram/network/MTProtoSender.java index 7416f05..1142d31 100644 --- a/lib/src/main/java/io/github/lonamiwebs/overgram/network/MTProtoSender.java +++ b/lib/src/main/java/io/github/lonamiwebs/overgram/network/MTProtoSender.java @@ -1,6 +1,7 @@ package io.github.lonamiwebs.overgram.network; import io.github.lonamiwebs.overgram.crypto.Authenticator; +import io.github.lonamiwebs.overgram.logging.Log; import io.github.lonamiwebs.overgram.network.connection.Connection; import io.github.lonamiwebs.overgram.tl.*; import io.github.lonamiwebs.overgram.utils.BinaryReader; @@ -55,7 +56,8 @@ public class MTProtoSender { connection.connect(ip, port); success = true; break; - } catch (IOException ignored) { + } catch (IOException e) { + Log.warn("Attempt %d failed connecting to %s:%d: %s", i + 1, ip, port, e); } } if (!success) { @@ -70,7 +72,8 @@ public class MTProtoSender { Authenticator.doAuthentication(plain, state); success = true; break; - } catch (SecurityException | IOException | ClassNotFoundException ignored) { + } catch (SecurityException | IOException | ClassNotFoundException e) { + Log.warn("Attempt %d failed generating AuthKey: %s", i + 1, e); } } @@ -80,6 +83,7 @@ public class MTProtoSender { } } + Log.info("Sender connected to %s:%d. Starting send and receive threads", ip, port); sendHandle = new Thread(this::sendLoop); sendHandle.setDaemon(true); sendHandle.start(); @@ -102,9 +106,11 @@ public class MTProtoSender { pendingAck.clear(); lastAck = null; stopHandles(); + Log.info("Sender disconnected from %s:%d", ip, port); } private void stopHandles() { + Log.info("Stopping send and receive threads"); if (sendHandle != null) { sendHandle.interrupt(); try { @@ -131,6 +137,7 @@ public class MTProtoSender { } private void reconnect() { + Log.info("Starting automatic reconnection"); reconnecting = true; stopHandles(); connection.disconnect(); @@ -183,13 +190,16 @@ public class MTProtoSender { return; } + Log.debug("Packing outgoing message %d: %s", message.id, message.object.getClass().getName()); final byte[] body = state.packMessage(message); while (!message.future.isCancelled()) { try { connection.send(body); + Log.debug("Message %d sent", message.id); break; - } catch (IOException ignored) { + } catch (IOException e) { // TODO e.g. on timeout retry (loop; not done yet) + Log.warn("Failed to send message %d: %s", message.id, e); try { Thread.sleep(1000); doReconnect(); @@ -203,13 +213,14 @@ public class MTProtoSender { } } - private void recvLoop() { while (userConnected) { final byte[] body; try { + Log.debug("Receiving items from the network..."); body = connection.recv(); - } catch (IOException ignored) { + } catch (IOException e) { + Log.warn("Error while receiving items from the network: %s", e); doReconnect(); return; } @@ -217,15 +228,24 @@ public class MTProtoSender { final TLMessage message; try { message = state.unpackMessage(body); - } catch (ClassNotFoundException ignored) { + } catch (ClassNotFoundException e) { + Log.exception(e, "Failed to unpack message"); continue; } + try { + Log.debug("Processing incoming message %d: %s", + message.id, message.object.getClass().getName()); + processMessage(message); - } catch (ClassNotFoundException ignored) { + } catch (ClassNotFoundException e) { + Log.warn("Class not found while processing %d: %s", message.id, e); } catch (InterruptedException ignored) { + Log.info("Interrupted while processing message %d, stopping read loop", message.id); doDisconnect(); return; + } catch (Exception e) { + Log.exception(e, "Unhandled exception while processing %d", message.id); } } } @@ -265,11 +285,10 @@ public class MTProtoSender { } } - private void handleRpcResult(final TLMessage message) throws ClassNotFoundException { + private void handleRpcResult(final TLMessage message) { final RPCResult result = (RPCResult) message.object; final TLMessage replyMessage = pendingMessages.remove(result.reqMsgId); - boolean ok = false; try { if (result.error != null) { replyMessage.future.completeExceptionally(new RPCError(result.error)); @@ -277,11 +296,11 @@ public class MTProtoSender { final BinaryReader reader = new BinaryReader(ByteBuffer.wrap(result.result)); replyMessage.future.complete(((TLRequest) replyMessage.object).readResult(reader)); } - ok = true; - } finally { - if (!ok) { - replyMessage.future.completeExceptionally(new Exception()); - } + } catch (Exception e) { + Log.exception(e, "Unhandled exception while receiving result for %d %s", + replyMessage.id, replyMessage.object.getClass().getName()); + + replyMessage.future.completeExceptionally(e); } } diff --git a/lib/src/main/java/io/github/lonamiwebs/overgram/network/MTProtoState.java b/lib/src/main/java/io/github/lonamiwebs/overgram/network/MTProtoState.java index e095e6a..2c98427 100644 --- a/lib/src/main/java/io/github/lonamiwebs/overgram/network/MTProtoState.java +++ b/lib/src/main/java/io/github/lonamiwebs/overgram/network/MTProtoState.java @@ -2,6 +2,7 @@ package io.github.lonamiwebs.overgram.network; import io.github.lonamiwebs.overgram.crypto.AES; import io.github.lonamiwebs.overgram.crypto.AuthKey; +import io.github.lonamiwebs.overgram.logging.Log; import io.github.lonamiwebs.overgram.tl.TLMessage; import io.github.lonamiwebs.overgram.tl.TLObject; import io.github.lonamiwebs.overgram.tl.TLRequest; @@ -135,6 +136,7 @@ public class MTProtoState { final long correct = correctMsgId >> 32; timeOffset = correct - now; lastMsgId = 0; + Log.info("New time offset %d", timeOffset); } public void setTimeOffset(final long timeOffset) { diff --git a/lib/src/main/java/io/github/lonamiwebs/overgram/network/TcpClient.java b/lib/src/main/java/io/github/lonamiwebs/overgram/network/TcpClient.java index 62c5fdc..ece0b0f 100644 --- a/lib/src/main/java/io/github/lonamiwebs/overgram/network/TcpClient.java +++ b/lib/src/main/java/io/github/lonamiwebs/overgram/network/TcpClient.java @@ -1,5 +1,7 @@ package io.github.lonamiwebs.overgram.network; +import io.github.lonamiwebs.overgram.logging.Log; + import java.io.IOException; import java.io.InputStream; import java.io.OutputStream; @@ -10,11 +12,13 @@ public class TcpClient { private Socket socket; public void connect(final String ipAddress, final int port) throws IOException { + Log.info("Connecting to %s:%d", ipAddress, port); socket = new Socket(ipAddress, port); } public void close() { try { + Log.info("Closing socket connection %s", socket.getRemoteSocketAddress()); socket.close(); } catch (IOException ignored) { } @@ -27,6 +31,7 @@ public class TcpClient { int index = 0; while (true) { final int count = in.read(result, index, result.length - index); + Log.debug("Read %d more bytes out of %d", count, result.length - index); if (count == -1) { throw new IOException("Connection closed"); } @@ -40,6 +45,7 @@ public class TcpClient { public void write(final byte[] bytes) throws IOException { final OutputStream out = socket.getOutputStream(); + Log.debug("Writing %d bytes", bytes.length); out.write(bytes); out.flush(); }