Skip to content

Commit

Permalink
Minor logging improvements
Browse files Browse the repository at this point in the history
  • Loading branch information
@ex3ndr
ex3ndr committed Apr 10, 2014
1 parent d1278ec commit 4a1e6fd
Show file tree
Hide file tree
Showing 5 changed files with 47 additions and 15 deletions.
14 changes: 10 additions & 4 deletions src/main/java/org/telegram/mtproto/MTProto.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -187,7 +187,7 @@ public boolean isClosed() {

public int sendRpcMessage(TLMethod request, long timeout, boolean highPriority) {
int id = scheduller.postMessage(request, true, timeout, highPriority);
Logger.d(TAG, "sendMessage #" + id + " " + request.toString());
Logger.d(TAG, "sendMessage #" + id + " " + request.toString() + " with timeout " + timeout + " ms");
return id;
}

Expand Down Expand Up @@ -339,7 +339,7 @@ private void onMTProtoMessage(long msgId, TLObject object) {
error.getErrorTag().equals("USER_DEACTIVATED") ||
error.getErrorTag().equals("SESSION_REVOKED") ||
error.getErrorTag().equals("SESSION_EXPIRED")) {
Logger.w(TAG, "Auth key invalidated");
Logger.w(TAG, "Auth key invalidated: " + error.getErrorTag());
callback.onAuthInvalidated(this);
close();
return;
Expand Down Expand Up @@ -467,6 +467,8 @@ public String toString() {

private class InternalActionsActor extends ReflectedActor {

private int lastPingMessage = -1;

public InternalActionsActor(ActorSystem system) {
super(system, "internal_actions", "scheduller");
}
Expand Down Expand Up @@ -499,13 +501,17 @@ public void onRequestSaltsMessage() {
}

public void onPingDelayMessage() {
if (lastPingMessage >= 0) {
forgetMessage(lastPingMessage);
lastPingMessage = -1;
}
if (mode == MODE_GENERAL) {
Logger.d(TAG, "Ping delay disconnect for " + PING_INTERVAL + " sec");
scheduller.postMessage(new MTPingDelayDisconnect(Entropy.generateRandomId(), PING_INTERVAL),
lastPingMessage = scheduller.postMessage(new MTPingDelayDisconnect(Entropy.generateRandomId(), PING_INTERVAL),
false, PING_INTERVAL_REQUEST);
messenger().pingDelayed(PING_INTERVAL_REQUEST);
} else if (mode == MODE_PUSH) {
scheduller.postMessage(new MTPing(Entropy.generateRandomId()), false, PING_PUSH_REQUEST);
lastPingMessage = scheduller.postMessage(new MTPing(Entropy.generateRandomId()), false, PING_INTERVAL_REQUEST);
messenger().pingDelayed(PING_PUSH_REQUEST);
}
}
Expand Down
2 changes: 1 addition & 1 deletion src/main/java/org/telegram/mtproto/log/Logger.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -8,7 +8,7 @@
*/
public class Logger {

public static final boolean LOG_THREADS = false;
public static final boolean LOG_THREADS = true;
public static final boolean LOG_IGNORED = true;
public static final boolean LOG_PING = true;

Expand Down
3 changes: 2 additions & 1 deletion src/main/java/org/telegram/mtproto/schedule/Scheduller.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -30,7 +30,8 @@ public class Scheduller {
private static final AtomicInteger messagesIds = new AtomicInteger(1);
private static final ConcurrentHashMap<Long, Long> idGenerationTime = new ConcurrentHashMap<Long, Long>();

private static final int SCHEDULLER_TIMEOUT = 15 * 1000;//15 sec
// private static final int SCHEDULLER_TIMEOUT = 15 * 1000;//15 sec
private static final int SCHEDULLER_TIMEOUT = 24 * 60 * 60 * 1000;//24 hours

private static final long CONFIRM_TIMEOUT = 60 * 1000;//60 sec

Expand Down
13 changes: 11 additions & 2 deletions src/main/java/org/telegram/mtproto/transport/TcpContext.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -19,6 +19,7 @@
* Created: 13.08.13 14:56
*/
public class TcpContext {
private static final boolean LOG_OPERATIONS = false;
private static final int MAX_PACKED_SIZE = 1024 * 1024 * 1024;//1 MB

private class Package {
Expand Down Expand Up @@ -211,7 +212,7 @@ private ReaderThread() {
public void run() {
try {
while (!isClosed && !isInterrupted()) {
if (Logger.LOG_THREADS) {
if (LOG_OPERATIONS) {
Logger.d(TAG, "Reader Iteration");
}
try {
Expand Down Expand Up @@ -359,7 +360,7 @@ public void pushPackage(Package p) {
@Override
public void run() {
while (!isBroken) {
if (Logger.LOG_THREADS) {
if (LOG_OPERATIONS) {
Logger.d(TAG, "Writer Iteration");
}
Package p;
Expand All @@ -383,6 +384,10 @@ public void run() {
}
}

if (LOG_OPERATIONS) {
Logger.d(TAG, "Writing data");
}

try {

byte[] data = p.data;
Expand Down Expand Up @@ -439,6 +444,10 @@ public void run() {
Logger.e(TAG, e);
breakContext();
}

if (LOG_OPERATIONS) {
Logger.d(TAG, "End writing data");
}
}
}
}
Expand Down
30 changes: 23 additions & 7 deletions src/main/java/org/telegram/mtproto/transport/TransportTcpPool.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -25,6 +25,8 @@
*/
public class TransportTcpPool extends TransportPool {

private static final boolean LOG_SCHEDULLER = true;

private final String TAG;
private static final boolean USE_CHECKSUM = false;
private static final int LOW_TIME_DIE_CHECK = 30 * 1000; // 30 sec
Expand Down Expand Up @@ -68,6 +70,9 @@ public TransportTcpPool(MTProto proto, TransportPoolCallback callback, int conne

@Override
public void onSchedullerUpdated(Scheduller scheduller) {
if (LOG_SCHEDULLER) {
Logger.d(TAG, "onSchedullerUpdated");
}
scheduleActor.schedule();
synchronized (contexts) {
if (contexts.size() == 0) {
Expand Down Expand Up @@ -136,18 +141,20 @@ protected void onCheckDestroyMessage() throws Exception {
protected void onCheckMessage() throws Exception {
if (mode == MODE_LOWMODE) {
if (!scheduller.hasRequests()) {
Logger.d(TAG, "Ignoring context check: scheduller is empty in low mode.");
return;
}
}

synchronized (contexts) {
if (contexts.size() >= desiredConnectionCount) {
Logger.d(TAG, "Ignoring context check: already created enough contexts.");
return;
}
}

Logger.d(TAG, "Creating context...");
ConnectionType type = connectionRate.tryConnection();
Logger.d(TAG, "Creating context for #" + type.getId() + " " + type.getHost() + ":" + type.getPort());
try {
TcpContext context = new TcpContext(proto, type.getHost(), type.getPort(), USE_CHECKSUM, tcpListener);
Logger.d(TAG, "Context created.");
Expand All @@ -157,6 +164,7 @@ protected void onCheckMessage() throws Exception {
}
scheduller.postMessageDelayed(new MTPing(Entropy.generateRandomId()), false, PING_TIMEOUT, 0, context.getContextId(), false);
} catch (IOException e) {
Logger.d(TAG, "Context create failure.");
connectionRate.onConnectionFailure(type.getId());
throw e;
}
Expand Down Expand Up @@ -203,10 +211,11 @@ public Messenger messenger() {

@Override
protected void registerMethods() {
registerMethod("schedule").enableSingleShot();
registerMethod("schedule");
}

public void onScheduleMessage() {
Logger.d(TAG, "onScheduleMessage");
int[] contextIds;
synchronized (contexts) {
TcpContext[] currentContexts = contexts.toArray(new TcpContext[0]);
Expand All @@ -218,7 +227,7 @@ public void onScheduleMessage() {

scheduller.prepareScheduller(prepareSchedule, contextIds);
if (prepareSchedule.isDoWait()) {
if (Logger.LOG_THREADS) {
if (LOG_SCHEDULLER) {
Logger.d(TAG, "Scheduller:wait " + prepareSchedule.getDelay());
}
messenger().scheduleDelayed(prepareSchedule.getDelay());
Expand Down Expand Up @@ -246,28 +255,31 @@ public void onScheduleMessage() {
}

if (context == null) {
if (Logger.LOG_THREADS) {
if (LOG_SCHEDULLER) {
Logger.d(TAG, "Scheduller: no context");
}
messenger().schedule();
return;
}

if (Logger.LOG_THREADS) {
if (LOG_SCHEDULLER) {
Logger.d(TAG, "doSchedule");
}

long start = System.currentTimeMillis();
PreparedPackage preparedPackage = scheduller.doSchedule(context.getContextId(), initedContext.contains(context.getContextId()));
if (Logger.LOG_THREADS) {
if (LOG_SCHEDULLER) {
Logger.d(TAG, "Schedulled in " + (System.currentTimeMillis() - start) + " ms");
}
if (preparedPackage == null) {
if (LOG_SCHEDULLER) {
Logger.d(TAG, "No packages for scheduling");
}
messenger().schedule();
return;
}

if (Logger.LOG_THREADS) {
if (LOG_SCHEDULLER) {
Logger.d(TAG, "MessagePushed (#" + context.getContextId() + "): time:" + getUnixTime(preparedPackage.getMessageId()));
Logger.d(TAG, "MessagePushed (#" + context.getContextId() + "): seqNo:" + preparedPackage.getSeqNo() + ", msgId" + preparedPackage.getMessageId());
}
Expand All @@ -287,6 +299,10 @@ public void onScheduleMessage() {
Logger.e(TAG, e);
}

if (LOG_SCHEDULLER) {
Logger.d(TAG, "doSchedule end");
}

messenger().schedule();
}

Expand Down

0 comments on commit 4a1e6fd

Please sign in to comment.