Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Added operation duration to the finishing log. #356

Merged
merged 6 commits into from
Jan 16, 2018
Merged

Added operation duration to the finishing log. #356

Show file tree
Hide file tree
Changes from 2 commits
Commits
Show all changes
6 commits
Select commit Hold shift + click to select a range
d7876e4
Added operation duration to the finishing log.
uKL Jan 16, 2018
8be4388
Calculate operation duration only on demand if log level is higher th…
uKL Jan 16, 2018
a144686
Review changes.
uKL Jan 16, 2018
cbdb871
Review changes.
uKL Jan 16, 2018
0ede6b7
Review changes.
uKL Jan 16, 2018
0618d70
Review changes.
uKL Jan 16, 2018
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Jump to
Jump to file
Failed to load files.
Diff view
Diff view
25 changes: 9 additions & 16 deletions ...c/main/java/com/polidea/rxandroidble/internal/serialization/ClientOperationQueueImpl.java
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,9 +1,11 @@
package com.polidea.rxandroidble.internal.serialization;

import android.support.annotation.RestrictTo;

Copy link
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We should include the formatting configuration into the repository so these kind of changes would not happen.

import com.polidea.rxandroidble.ClientComponent;
import com.polidea.rxandroidble.internal.RxBleLog;
import com.polidea.rxandroidble.internal.operations.Operation;

import bleshadow.javax.inject.Inject;
import bleshadow.javax.inject.Named;
import rx.Emitter;
Expand All @@ -13,6 +15,8 @@
import rx.functions.Action1;
import rx.functions.Cancellable;

import static com.polidea.rxandroidble.internal.util.OperationLogger.*;

public class ClientOperationQueueImpl implements ClientOperationQueue {

private OperationPriorityFifoBlockingQueue queue = new OperationPriorityFifoBlockingQueue();
Expand All @@ -27,20 +31,19 @@ public void run() {
try {
final FIFORunnableEntry<?> entry = queue.take();
final Operation<?> operation = entry.operation;
log("STARTED", operation);
final long startedAtTime = System.currentTimeMillis();
logOperationStarted(operation);

/*
* Calling bluetooth calls before the previous one returns in a callback usually finishes with a failure
* status. Below a QueueSemaphore is passed to the RxBleCustomOperation and is meant to be released
* at appropriate time when the next operation should be able to start successfully.
*/
final QueueSemaphore clientOperationSemaphore = new QueueSemaphore();

Subscription subscription = entry.run(clientOperationSemaphore, callbackScheduler);
entry.emitter.setSubscription(subscription);

clientOperationSemaphore.awaitRelease();
log("FINISHED", operation);
logOperationFinished(operation, startedAtTime, System.currentTimeMillis());
} catch (InterruptedException e) {
RxBleLog.e(e, "Error while processing client operation queue");
}
Expand All @@ -56,27 +59,17 @@ public <T> Observable<T> queue(final Operation<T> operation) {
@Override
public void call(Emitter<T> tEmitter) {
final FIFORunnableEntry entry = new FIFORunnableEntry<>(operation, tEmitter);

tEmitter.setCancellation(new Cancellable() {
@Override
public void cancel() throws Exception {
if (queue.remove(entry)) {
log("REMOVED", operation);
logOperationRemoved(operation);
}
}
});

log("QUEUED", operation);
logOperationQueued(operation);
queue.add(entry);
}
}, Emitter.BackpressureMode.NONE);
}

@RestrictTo(RestrictTo.Scope.SUBCLASSES)
void log(String prefix, Operation operation) {

if (RxBleLog.isAtLeast(RxBleLog.DEBUG)) {
RxBleLog.d("%8s %s(%d)", prefix, operation.getClass().getSimpleName(), System.identityHashCode(operation));
}
}
}
23 changes: 11 additions & 12 deletions ...in/java/com/polidea/rxandroidble/internal/serialization/ConnectionOperationQueueImpl.java
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,6 +1,7 @@
package com.polidea.rxandroidble.internal.serialization;

import android.support.annotation.RestrictTo;

import com.polidea.rxandroidble.ClientComponent;
import com.polidea.rxandroidble.exceptions.BleDisconnectedException;
import com.polidea.rxandroidble.exceptions.BleException;
Expand All @@ -10,8 +11,11 @@
import com.polidea.rxandroidble.internal.connection.ConnectionSubscriptionWatcher;
import com.polidea.rxandroidble.internal.connection.DisconnectionRouterOutput;
import com.polidea.rxandroidble.internal.operations.Operation;

import java.util.Locale;
import java.util.concurrent.ExecutorService;
import java.util.concurrent.Future;

import bleshadow.javax.inject.Inject;
import bleshadow.javax.inject.Named;
import rx.Emitter;
Expand All @@ -21,6 +25,8 @@
import rx.functions.Action1;
import rx.functions.Cancellable;

import static com.polidea.rxandroidble.internal.util.OperationLogger.*;

@ConnectionScope
public class ConnectionOperationQueueImpl implements ConnectionOperationQueue, ConnectionSubscriptionWatcher {

Expand Down Expand Up @@ -49,7 +55,8 @@ public void run() {
try {
final FIFORunnableEntry<?> entry = queue.take();
final Operation<?> operation = entry.operation;
log("STARTED", operation);
final long startedAtTime = System.currentTimeMillis();
logOperationStarted(operation);

/*
* Calling bluetooth calls before the previous one returns in a callback usually finishes with a failure
Expand All @@ -62,7 +69,7 @@ public void run() {
entry.emitter.setSubscription(subscription);

currentSemaphore.awaitRelease();
log("FINISHED", operation);
logOperationFinished(operation, startedAtTime, System.currentTimeMillis());
} catch (InterruptedException e) {
synchronized (ConnectionOperationQueueImpl.this) {
if (!shouldRun) {
Expand Down Expand Up @@ -101,12 +108,12 @@ public void call(Emitter<T> tEmitter) {
@Override
public void cancel() throws Exception {
if (queue.remove(entry)) {
log("REMOVED", operation);
logOperationRemoved(operation);
}
}
});

log("QUEUED", operation);
logOperationQueued(operation);
queue.add(entry);
}
}, Emitter.BackpressureMode.NONE);
Expand All @@ -124,14 +131,6 @@ public synchronized void terminate(BleException disconnectException) {
runnableFuture.cancel(true);
}

@RestrictTo(RestrictTo.Scope.SUBCLASSES)
void log(String prefix, Operation operation) {

if (RxBleLog.isAtLeast(RxBleLog.DEBUG)) {
RxBleLog.d("%8s %s(%d)", prefix, operation.getClass().getSimpleName(), System.identityHashCode(operation));
}
}

@Override
public void onConnectionSubscribed() {
disconnectionThrowableSubscription = disconnectionRouterOutput.asValueOnlyObservable().subscribe(new Action1<BleException>() {
Expand Down
37 changes: 37 additions & 0 deletions rxandroidble/src/main/java/com/polidea/rxandroidble/internal/util/OperationLogger.java
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -0,0 +1,37 @@
package com.polidea.rxandroidble.internal.util;

import android.support.annotation.RestrictTo;

import com.polidea.rxandroidble.internal.RxBleLog;
import com.polidea.rxandroidble.internal.operations.Operation;

public class OperationLogger {

@RestrictTo(RestrictTo.Scope.LIBRARY)
Copy link
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Not really needed since it is under internal package

public static void logOperationStarted(Operation operation) {
if (RxBleLog.isAtLeast(RxBleLog.DEBUG)) {
RxBleLog.d("STARTED %s(%d)", operation.getClass().getSimpleName(), System.identityHashCode(operation));
}
}

@RestrictTo(RestrictTo.Scope.LIBRARY)
public static void logOperationRemoved(Operation operation) {
if (RxBleLog.isAtLeast(RxBleLog.DEBUG)) {
RxBleLog.d("REMOVED %s(%d)", operation.getClass().getSimpleName(), System.identityHashCode(operation));
}
}

@RestrictTo(RestrictTo.Scope.LIBRARY)
public static void logOperationQueued(Operation operation) {
if (RxBleLog.isAtLeast(RxBleLog.DEBUG)) {
RxBleLog.d("QUEUED %s(%d)", operation.getClass().getSimpleName(), System.identityHashCode(operation));
}
}

@RestrictTo(RestrictTo.Scope.LIBRARY)
public static void logOperationFinished(Operation operation, long startTime, long endTime) {
if (RxBleLog.isAtLeast(RxBleLog.DEBUG)) {
RxBleLog.d("FINISHED in %d %s(%d)", (endTime - startTime), operation.getClass().getSimpleName(), System.identityHashCode(operation));
}
}
}