Kaladaran/briar
0
0
Fork 0
mirror of https://code.briarproject.org/briar/briar.git synced 2026-02-13 11:19:04 +01:00
Code Issues Projects Releases Wiki Activity

Move timing measurements down to FINE log level.

Browse Source
This commit is contained in:
akwizgran
2018-06-15 11:36:20 +01:00
parent a47a1cf442
commit ccee1febbc
20 changed files with 116 additions and 115 deletions
Download Patch File Download Diff File Expand all files Collapse all files

7
bramble-core/src/main/java/org/briarproject/bramble/PoliteExecutor.java
View File

@@ -5,7 +5,6 @@ import org.briarproject.bramble.api.nullsafety.NotNullByDefault;
import java.util.LinkedList;
import java.util.Queue;
import java.util.concurrent.Executor;
import java.util.logging.Level;
import java.util.logging.Logger;
import javax.annotation.concurrent.GuardedBy;
@@ -20,8 +19,6 @@ import static java.util.logging.Level.FINE;
@NotNullByDefault
public class PoliteExecutor implements Executor {
private static final Level LOG_LEVEL = FINE;
private final Object lock = new Object();
@GuardedBy("lock")
private final Queue<Runnable> queue = new LinkedList<>();
@@ -51,9 +48,9 @@ public class PoliteExecutor implements Executor {
public void execute(Runnable r) {
long submitted = System.currentTimeMillis();
Runnable wrapped = () -> {
if (log.isLoggable(LOG_LEVEL)) {
if (log.isLoggable(FINE)) {
long queued = System.currentTimeMillis() - submitted;
log.log(LOG_LEVEL, "Queue time " + queued + " ms");
log.fine("Queue time " + queued + " ms");
}
try {
r.run();

9
bramble-core/src/main/java/org/briarproject/bramble/TimeLoggingExecutor.java
View File

@@ -6,7 +6,6 @@ import java.util.concurrent.BlockingQueue;
import java.util.concurrent.RejectedExecutionHandler;
import java.util.concurrent.ThreadPoolExecutor;
import java.util.concurrent.TimeUnit;
import java.util.logging.Level;
import java.util.logging.Logger;
import static java.util.logging.Level.FINE;
@@ -14,8 +13,6 @@ import static java.util.logging.Level.FINE;
@NotNullByDefault
public class TimeLoggingExecutor extends ThreadPoolExecutor {
private static final Level LOG_LEVEL = FINE;
private final Logger log;
public TimeLoggingExecutor(String tag, int corePoolSize, int maxPoolSize,
@@ -29,15 +26,15 @@ public class TimeLoggingExecutor extends ThreadPoolExecutor {
@Override
public void execute(Runnable r) {
if (log.isLoggable(LOG_LEVEL)) {
if (log.isLoggable(FINE)) {
long submitted = System.currentTimeMillis();
super.execute(() -> {
long started = System.currentTimeMillis();
long queued = started - submitted;
log.log(LOG_LEVEL, "Queue time " + queued + " ms");
log.fine("Queue time " + queued + " ms");
r.run();
long executing = System.currentTimeMillis() - started;
log.log(LOG_LEVEL, "Execution time " + executing + " ms");
log.fine("Execution time " + executing + " ms");
});
} else {
super.execute(r);

5
bramble-core/src/main/java/org/briarproject/bramble/crypto/CryptoComponentImpl.java
View File

@@ -30,6 +30,7 @@ import java.util.logging.Logger;
import javax.annotation.Nullable;
import javax.inject.Inject;
import static java.util.logging.Level.FINE;
import static java.util.logging.Level.INFO;
import static org.briarproject.bramble.util.ByteUtils.INT_32_BYTES;
@@ -135,8 +136,8 @@ class CryptoComponentImpl implements CryptoComponent {
for (byte b : secret) allZero |= b;
if (allZero == 0) throw new GeneralSecurityException();
long duration = System.currentTimeMillis() - now;
if (LOG.isLoggable(INFO))
LOG.info("Deriving shared secret took " + duration + " ms");
if (LOG.isLoggable(FINE))
LOG.fine("Deriving shared secret took " + duration + " ms");
return secret;
}

5
bramble-core/src/main/java/org/briarproject/bramble/crypto/ScryptKdf.java
View File

@@ -9,6 +9,7 @@ import java.util.logging.Logger;
import javax.inject.Inject;
import static java.util.logging.Level.FINE;
import static java.util.logging.Level.INFO;
class ScryptKdf implements PasswordBasedKdf {
@@ -55,8 +56,8 @@ class ScryptKdf implements PasswordBasedKdf {
SecretKey k = new SecretKey(SCrypt.generate(passwordBytes, salt, cost,
BLOCK_SIZE, PARALLELIZATION, SecretKey.LENGTH));
long duration = System.currentTimeMillis() - start;
if (LOG.isLoggable(INFO))
LOG.info("Deriving key from password took " + duration + " ms");
if (LOG.isLoggable(FINE))
LOG.fine("Deriving key from password took " + duration + " ms");
return k;
}
}

10
bramble-core/src/main/java/org/briarproject/bramble/crypto/Sec1KeyParser.java
View File

@@ -16,7 +16,7 @@ import java.util.logging.Logger;
import javax.annotation.concurrent.Immutable;
import static java.util.logging.Level.INFO;
import static java.util.logging.Level.FINE;
/**
* A key parser that uses the encoding defined in "SEC 1: Elliptic Curve
@@ -81,8 +81,8 @@ class Sec1KeyParser implements KeyParser {
ECPublicKeyParameters k = new ECPublicKeyParameters(pub, params);
PublicKey p = new Sec1PublicKey(k);
long duration = System.currentTimeMillis() - now;
if (LOG.isLoggable(INFO))
LOG.info("Parsing public key took " + duration + " ms");
if (LOG.isLoggable(FINE))
LOG.fine("Parsing public key took " + duration + " ms");
return p;
}
@@ -100,8 +100,8 @@ class Sec1KeyParser implements KeyParser {
ECPrivateKeyParameters k = new ECPrivateKeyParameters(d, params);
PrivateKey p = new Sec1PrivateKey(k, keyBits);
long duration = System.currentTimeMillis() - now;
if (LOG.isLoggable(INFO))
LOG.info("Parsing private key took " + duration + " ms");
if (LOG.isLoggable(FINE))
LOG.fine("Parsing private key took " + duration + " ms");
return p;
}
}

35
bramble-core/src/main/java/org/briarproject/bramble/lifecycle/LifecycleManagerImpl.java
View File

@@ -30,6 +30,7 @@ import javax.annotation.Nullable;
import javax.annotation.concurrent.ThreadSafe;
import javax.inject.Inject;
import static java.util.logging.Level.FINE;
import static java.util.logging.Level.INFO;
import static java.util.logging.Level.WARNING;
import static org.briarproject.bramble.api.lifecycle.LifecycleManager.LifecycleState.MIGRATING_DATABASE;
@@ -108,8 +109,8 @@ class LifecycleManagerImpl implements LifecycleManager, MigrationListener {
LocalAuthor localAuthor = authorFactory
.createLocalAuthor(nickname, publicKey, privateKey);
long duration = System.currentTimeMillis() - now;
if (LOG.isLoggable(INFO))
LOG.info("Creating local author took " + duration + " ms");
if (LOG.isLoggable(FINE))
LOG.fine("Creating local author took " + duration + " ms");
return localAuthor;
}
@@ -117,8 +118,8 @@ class LifecycleManagerImpl implements LifecycleManager, MigrationListener {
long now = System.currentTimeMillis();
identityManager.registerLocalAuthor(author);
long duration = System.currentTimeMillis() - now;
if (LOG.isLoggable(INFO))
LOG.info("Registering local author took " + duration + " ms");
if (LOG.isLoggable(FINE))
LOG.fine("Registering local author took " + duration + " ms");
}
@Override
@@ -133,10 +134,10 @@ class LifecycleManagerImpl implements LifecycleManager, MigrationListener {
boolean reopened = db.open(this);
long duration = System.currentTimeMillis() - start;
if (LOG.isLoggable(INFO)) {
if (LOG.isLoggable(FINE)) {
if (reopened)
LOG.info("Reopening database took " + duration + " ms");
else LOG.info("Creating database took " + duration + " ms");
LOG.fine("Reopening database took " + duration + " ms");
else LOG.fine("Creating database took " + duration + " ms");
}
if (nickname != null) {
@@ -153,8 +154,8 @@ class LifecycleManagerImpl implements LifecycleManager, MigrationListener {
start = System.currentTimeMillis();
c.createLocalState(txn);
duration = System.currentTimeMillis() - start;
if (LOG.isLoggable(INFO)) {
LOG.info("Starting client "
if (LOG.isLoggable(FINE)) {
LOG.fine("Starting client "
+ c.getClass().getSimpleName()
+ " took " + duration + " ms");
}
@@ -167,8 +168,8 @@ class LifecycleManagerImpl implements LifecycleManager, MigrationListener {
start = System.currentTimeMillis();
s.startService();
duration = System.currentTimeMillis() - start;
if (LOG.isLoggable(INFO)) {
LOG.info("Starting service " + s.getClass().getSimpleName()
if (LOG.isLoggable(FINE)) {
LOG.fine("Starting service " + s.getClass().getSimpleName()
+ " took " + duration + " ms");
}
}
@@ -216,14 +217,14 @@ class LifecycleManagerImpl implements LifecycleManager, MigrationListener {
long start = System.currentTimeMillis();
s.stopService();
long duration = System.currentTimeMillis() - start;
if (LOG.isLoggable(INFO)) {
LOG.info("Stopping service " + s.getClass().getSimpleName()
if (LOG.isLoggable(FINE)) {
LOG.fine("Stopping service " + s.getClass().getSimpleName()
+ " took " + duration + " ms");
}
}
for (ExecutorService e : executors) {
if (LOG.isLoggable(INFO)) {
LOG.info("Stopping executor "
if (LOG.isLoggable(FINE)) {
LOG.fine("Stopping executor "
+ e.getClass().getSimpleName());
}
e.shutdownNow();
@@ -231,8 +232,8 @@ class LifecycleManagerImpl implements LifecycleManager, MigrationListener {
long start = System.currentTimeMillis();
db.close();
long duration = System.currentTimeMillis() - start;
if (LOG.isLoggable(INFO))
LOG.info("Closing database took " + duration + " ms");
if (LOG.isLoggable(FINE))
LOG.fine("Closing database took " + duration + " ms");
shutdownLatch.countDown();
} catch (DbException | ServiceException e) {
if (LOG.isLoggable(WARNING)) LOG.log(WARNING, e.toString(), e);

9
bramble-core/src/main/java/org/briarproject/bramble/plugin/PluginManagerImpl.java
View File

@@ -49,6 +49,7 @@ import java.util.logging.Logger;
import javax.annotation.concurrent.ThreadSafe;
import javax.inject.Inject;
import static java.util.logging.Level.FINE;
import static java.util.logging.Level.INFO;
import static java.util.logging.Level.WARNING;
@@ -208,8 +209,8 @@ class PluginManagerImpl implements PluginManager, Service {
long start = System.currentTimeMillis();
plugin.start();
long duration = System.currentTimeMillis() - start;
if (LOG.isLoggable(INFO)) {
LOG.info("Starting plugin " + plugin.getId() + " took " +
if (LOG.isLoggable(FINE)) {
LOG.fine("Starting plugin " + plugin.getId() + " took " +
duration + " ms");
}
} catch (PluginException e) {
@@ -246,8 +247,8 @@ class PluginManagerImpl implements PluginManager, Service {
long start = System.currentTimeMillis();
plugin.stop();
long duration = System.currentTimeMillis() - start;
if (LOG.isLoggable(INFO)) {
LOG.info("Stopping plugin " + plugin.getId()
if (LOG.isLoggable(FINE)) {
LOG.fine("Stopping plugin " + plugin.getId()
+ " took " + duration + " ms");
}
} catch (InterruptedException e) {