Move Tracer to core-util.

This commit is contained in:
Greyson Parrelli
2020-12-20 00:44:26 -05:00
committed by Alan Evans
parent e10284bd13
commit 4b8d02fdba
9 changed files with 57 additions and 22 deletions

View File

@@ -128,7 +128,6 @@ android {
buildConfigField "String", "ZKGROUP_SERVER_PUBLIC_PARAMS", "\"AMhf5ywVwITZMsff/eCyudZx9JDmkkkbV6PInzG4p8x3VqVJSFiMvnvlEKWuRob/1eaIetR31IYeAbm0NdOuHH8Qi+Rexi1wLlpzIo1gstHWBfZzy1+qHRV5A4TqPp15YzBPm0WSggW6PbSn+F4lf57VCnHF7p8SvzAA2ZZJPYJURt8X7bbg+H3i+PEjH9DXItNEqs2sNcug37xZQDLm7X0=\""
buildConfigField "String[]", "LANGUAGES", "new String[]{\"" + autoResConfig().collect { s -> s.replace('-r', '_') }.join('", "') + '"}'
buildConfigField "int", "CANONICAL_VERSION_CODE", "$canonicalVersionCode"
buildConfigField "int", "TRACE_EVENT_MAX", "3500"
ndk {
abiFilters 'armeabi-v7a', 'arm64-v8a', 'x86', 'x86_64'
@@ -229,7 +228,6 @@ android {
ext.websiteUpdateUrl = "null"
buildConfigField "boolean", "PLAY_STORE_DISABLED", "false"
buildConfigField "String", "NOPLAY_UPDATE_URL", "$ext.websiteUpdateUrl"
buildConfigField "int", "TRACE_EVENT_MAX", "30_000"
}
prod {

View File

@@ -36,6 +36,7 @@ import org.signal.core.util.concurrent.SignalExecutors;
import org.signal.core.util.logging.AndroidLogger;
import org.signal.core.util.logging.Log;
import org.signal.core.util.logging.PersistentLogger;
import org.signal.core.util.tracing.Tracer;
import org.signal.glide.SignalGlideCodecs;
import org.signal.ringrtc.CallManager;
import org.thoughtcrime.securesms.database.DatabaseFactory;
@@ -68,7 +69,6 @@ import org.thoughtcrime.securesms.service.RotateSenderCertificateListener;
import org.thoughtcrime.securesms.service.RotateSignedPreKeyListener;
import org.thoughtcrime.securesms.service.UpdateApkRefreshListener;
import org.thoughtcrime.securesms.storage.StorageSyncHelper;
import org.thoughtcrime.securesms.tracing.Tracer;
import org.thoughtcrime.securesms.util.DynamicTheme;
import org.thoughtcrime.securesms.util.FeatureFlags;
import org.thoughtcrime.securesms.util.SignalUncaughtExceptionHandler;
@@ -109,8 +109,13 @@ public class ApplicationContext extends MultiDexApplication implements DefaultLi
@Override
public void onCreate() {
Tracer.getInstance().start("Application#onCreate()");
long startTime = System.currentTimeMillis();
if (FeatureFlags.internalUser()) {
Tracer.getInstance().setMaxBufferSize(35_000);
}
super.onCreate();
initializeSecurityProvider();

View File

@@ -12,6 +12,7 @@ import androidx.annotation.Nullable;
import androidx.fragment.app.Fragment;
import org.signal.core.util.logging.Log;
import org.signal.core.util.tracing.Tracer;
import org.thoughtcrime.securesms.crypto.MasterSecretUtil;
import org.thoughtcrime.securesms.dependencies.ApplicationDependencies;
import org.thoughtcrime.securesms.jobs.PushNotificationReceiveJob;
@@ -25,7 +26,6 @@ import org.thoughtcrime.securesms.push.SignalServiceNetworkAccess;
import org.thoughtcrime.securesms.recipients.Recipient;
import org.thoughtcrime.securesms.registration.RegistrationNavigationActivity;
import org.thoughtcrime.securesms.service.KeyCachingService;
import org.thoughtcrime.securesms.tracing.Tracer;
import org.thoughtcrime.securesms.util.TextSecurePreferences;
import java.util.Locale;
@@ -63,6 +63,7 @@ public abstract class PassphraseRequiredActivity extends BaseActivity implements
initializeClearKeyReceiver();
onCreate(savedInstanceState, true);
}
Tracer.getInstance().end(Log.tag(getClass()) + "#onCreate()");
}

View File

@@ -3,17 +3,14 @@ package org.thoughtcrime.securesms.database;
import android.content.ContentValues;
import androidx.annotation.Nullable;
import com.google.android.gms.vision.Tracker;
import net.sqlcipher.Cursor;
import net.sqlcipher.SQLException;
import net.sqlcipher.database.SQLiteQueryStats;
import net.sqlcipher.database.SQLiteStatement;
import net.sqlcipher.database.SQLiteTransactionListener;
import org.thoughtcrime.securesms.tracing.Tracer;
import org.signal.core.util.tracing.Tracer;
import org.thoughtcrime.securesms.dependencies.ApplicationDependencies;
import java.util.HashMap;
import java.util.Locale;

View File

@@ -5,6 +5,7 @@ import android.app.Application;
import androidx.annotation.MainThread;
import androidx.annotation.NonNull;
import org.signal.core.util.tracing.Tracer;
import org.thoughtcrime.securesms.KbsEnclave;
import org.thoughtcrime.securesms.components.TypingStatusRepository;
import org.thoughtcrime.securesms.components.TypingStatusSender;
@@ -23,6 +24,7 @@ import org.thoughtcrime.securesms.push.SignalServiceNetworkAccess;
import org.thoughtcrime.securesms.recipients.LiveRecipientCache;
import org.thoughtcrime.securesms.service.TrimThreadsByDateManager;
import org.thoughtcrime.securesms.util.EarlyMessageCache;
import org.thoughtcrime.securesms.util.FeatureFlags;
import org.thoughtcrime.securesms.util.FrameRateTracker;
import org.thoughtcrime.securesms.util.Hex;
import org.thoughtcrime.securesms.util.IasKeyStore;
@@ -68,6 +70,7 @@ public class ApplicationDependencies {
private static volatile TypingStatusRepository typingStatusRepository;
private static volatile TypingStatusSender typingStatusSender;
private static volatile DatabaseObserver databaseObserver;
private static volatile Tracer tracer;
@MainThread
public static void init(@NonNull Application application, @NonNull Provider provider) {

View File

@@ -10,7 +10,8 @@ import androidx.lifecycle.ViewModelProvider;
import com.annimon.stream.Stream;
import org.thoughtcrime.securesms.tracing.Tracer;
import org.signal.core.util.tracing.Tracer;
import org.thoughtcrime.securesms.dependencies.ApplicationDependencies;
import org.thoughtcrime.securesms.util.DefaultValueLiveData;
import org.whispersystems.libsignal.util.guava.Optional;

View File

@@ -1,229 +0,0 @@
package org.thoughtcrime.securesms.tracing;
import android.os.SystemClock;
import androidx.annotation.NonNull;
import androidx.annotation.Nullable;
import com.google.protobuf.ByteString;
import org.thoughtcrime.securesms.BuildConfig;
import org.thoughtcrime.securesms.trace.TraceProtos;
import org.thoughtcrime.securesms.trace.TraceProtos.Trace;
import org.thoughtcrime.securesms.trace.TraceProtos.TracePacket;
import org.thoughtcrime.securesms.trace.TraceProtos.TrackDescriptor;
import org.thoughtcrime.securesms.trace.TraceProtos.TrackEvent;
import org.whispersystems.signalservice.api.util.UuidUtil;
import java.util.Collections;
import java.util.Map;
import java.util.Queue;
import java.util.UUID;
import java.util.concurrent.ConcurrentHashMap;
import java.util.concurrent.ConcurrentLinkedQueue;
import java.util.concurrent.TimeUnit;
import java.util.concurrent.atomic.AtomicInteger;
/**
* A class to create Perfetto-compatible traces. Currently keeps the entire trace in memory to
* avoid weirdness with synchronizing to disk.
*
* Some general info on how the Perfetto format works:
* - The file format is just a Trace proto (see Trace.proto)
* - The Trace proto is just a series of TracePackets
* - TracePackets can describe:
* - Threads
* - Start of a method
* - End of a method
* - (And a bunch of other stuff that's not relevant to use at this point)
*
* We keep a circular buffer of TracePackets for method calls, and we keep a separate list of
* TracePackets for threads so we don't lose any of those.
*
* Serializing is just a matter of throwing all the TracePackets we have into a proto.
*
* Note: This class aims to be largely-thread-safe, but prioritizes speed and memory efficiency
* above all else. These methods are going to be called very quickly from every thread imaginable,
* and we want to create as little overhead as possible. The idea being that it's ok if we don't,
* for example, keep a perfect circular buffer size if it allows us to reduce overhead. The only
* cost of screwing up would be dropping a trace packet or something, which, while sad, won't affect
* how the app functions.
*/
public final class Tracer {
public static final class TrackId {
public static final long DB_LOCK = -8675309;
private static final String DB_LOCK_NAME = "Database Lock";
}
private static final Tracer INSTANCE = new Tracer();
private static final int TRUSTED_SEQUENCE_ID = 1;
private static final byte[] SYNCHRONIZATION_MARKER = UuidUtil.toByteArray(UUID.fromString("82477a76-b28d-42ba-81dc-33326d57a079"));
private static final long SYNCHRONIZATION_INTERVAL = TimeUnit.SECONDS.toNanos(3);
private final Clock clock;
private final Map<Long, TracePacket> threadPackets;
private final Queue<TracePacket> eventPackets;
private final AtomicInteger eventCount;
private long lastSyncTime;
Tracer() {
this.clock = SystemClock::elapsedRealtimeNanos;
this.threadPackets = new ConcurrentHashMap<>();
this.eventPackets = new ConcurrentLinkedQueue<>();
this.eventCount = new AtomicInteger(0);
}
public static @NonNull Tracer getInstance() {
return INSTANCE;
}
public void start(@NonNull String methodName) {
start(methodName, Thread.currentThread().getId(), null);
}
public void start(@NonNull String methodName, long trackId) {
start(methodName, trackId, null);
}
public void start(@NonNull String methodName, @NonNull String key, @Nullable String value) {
start(methodName, Thread.currentThread().getId(), key, value);
}
public void start(@NonNull String methodName, long trackId, @NonNull String key, @Nullable String value) {
start(methodName, trackId, Collections.singletonMap(key, value));
}
public void start(@NonNull String methodName, @Nullable Map<String, String> values) {
start(methodName, Thread.currentThread().getId(), values);
}
public void start(@NonNull String methodName, long trackId, @Nullable Map<String, String> values) {
long time = clock.getTimeNanos();
if (time - lastSyncTime > SYNCHRONIZATION_INTERVAL) {
addPacket(forSynchronization(time));
lastSyncTime = time;
}
if (!threadPackets.containsKey(trackId)) {
threadPackets.put(trackId, forTrackId(trackId));
}
addPacket(forMethodStart(methodName, time, trackId, values));
}
public void end(@NonNull String methodName) {
addPacket(forMethodEnd(methodName, clock.getTimeNanos(), Thread.currentThread().getId()));
}
public void end(@NonNull String methodName, long trackId) {
addPacket(forMethodEnd(methodName, clock.getTimeNanos(), trackId));
}
public @NonNull byte[] serialize() {
Trace.Builder trace = Trace.newBuilder();
for (TracePacket thread : threadPackets.values()) {
trace.addPacket(thread);
}
for (TracePacket event : eventPackets) {
trace.addPacket(event);
}
trace.addPacket(forSynchronization(clock.getTimeNanos()));
return trace.build().toByteArray();
}
/**
* Attempts to add a packet to our list while keeping the size of our circular buffer in-check.
* The tracking of the event count is not perfectly thread-safe, but doing it in a thread-safe
* way would likely involve adding a lock, which we really don't want to do, since it'll add
* unnecessary overhead.
*
* Note that we keep track of the event count separately because
* {@link ConcurrentLinkedQueue#size()} is NOT a constant-time operation.
*/
private void addPacket(@NonNull TracePacket packet) {
eventPackets.add(packet);
int size = eventCount.incrementAndGet();
for (int i = size; i > BuildConfig.TRACE_EVENT_MAX; i--) {
eventPackets.poll();
eventCount.decrementAndGet();
}
}
private TracePacket forTrackId(long id) {
if (id == TrackId.DB_LOCK) {
return forTrack(id, TrackId.DB_LOCK_NAME);
} else {
Thread currentThread = Thread.currentThread();
return forTrack(currentThread.getId(), currentThread.getName());
}
}
private static TracePacket forTrack(long id, String name) {
return TracePacket.newBuilder()
.setTrustedPacketSequenceId(TRUSTED_SEQUENCE_ID)
.setTrackDescriptor(TrackDescriptor.newBuilder()
.setUuid(id)
.setName(name))
.build();
}
private static TracePacket forMethodStart(@NonNull String name, long time, long threadId, @Nullable Map<String, String> values) {
TrackEvent.Builder event = TrackEvent.newBuilder()
.setTrackUuid(threadId)
.setName(name)
.setType(TrackEvent.Type.TYPE_SLICE_BEGIN);
if (values != null) {
for (Map.Entry<String, String> entry : values.entrySet()) {
event.addDebugAnnotations(debugAnnotation(entry.getKey(), entry.getValue()));
}
}
return TracePacket.newBuilder()
.setTrustedPacketSequenceId(TRUSTED_SEQUENCE_ID)
.setTimestamp(time)
.setTrackEvent(event)
.build();
}
private static TraceProtos.DebugAnnotation debugAnnotation(@NonNull String key, @Nullable String value) {
return TraceProtos.DebugAnnotation.newBuilder()
.setName(key)
.setStringValue(value != null ? value : "")
.build();
}
private static TracePacket forMethodEnd(@NonNull String name, long time, long threadId) {
return TracePacket.newBuilder()
.setTrustedPacketSequenceId(TRUSTED_SEQUENCE_ID)
.setTimestamp(time)
.setTrackEvent(TrackEvent.newBuilder()
.setTrackUuid(threadId)
.setName(name)
.setType(TrackEvent.Type.TYPE_SLICE_END))
.build();
}
private static TracePacket forSynchronization(long time) {
return TracePacket.newBuilder()
.setTrustedPacketSequenceId(TRUSTED_SEQUENCE_ID)
.setTimestamp(time)
.setSynchronizationMarker(ByteString.copyFrom(SYNCHRONIZATION_MARKER))
.build();
}
private interface Clock {
long getTimeNanos();
}
}

View File

@@ -1,151 +0,0 @@
/*
* Copyright (C) 2018 The Android Open Source Project
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS,
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
* See the License for the specific language governing permissions and
* limitations under the License.
*/
syntax = "proto2";
package signal;
option java_package = "org.thoughtcrime.securesms.trace";
option java_outer_classname = "TraceProtos";
/*
* Minimal interface needed to work with Perfetto.
*
* https://cs.android.com/android/platform/superproject/+/master:external/perfetto/protos/perfetto/trace/trace.proto
*/
message Trace {
repeated TracePacket packet = 1;
}
message TracePacket {
optional uint64 timestamp = 8;
optional uint32 timestamp_clock_id = 58;
oneof data {
TrackEvent track_event = 11;
TrackDescriptor track_descriptor = 60;
bytes synchronization_marker = 36;
}
oneof optional_trusted_packet_sequence_id {
uint32 trusted_packet_sequence_id = 10;
}
}
message TrackEvent {
repeated uint64 category_iids = 3;
repeated string categories = 22;
repeated DebugAnnotation debug_annotations = 4;
oneof name_field {
uint64 name_iid = 10;
string name = 23;
}
enum Type {
TYPE_UNSPECIFIED = 0;
TYPE_SLICE_BEGIN = 1;
TYPE_SLICE_END = 2;
TYPE_INSTANT = 3;
TYPE_COUNTER = 4;
}
optional Type type = 9;
optional uint64 track_uuid = 11;
optional int64 counter_value = 30;
oneof timestamp {
int64 timestamp_delta_us = 1;
int64 timestamp_absolute_us = 16;
}
oneof thread_time {
int64 thread_time_delta_us = 2;
int64 thread_time_absolute_us = 17;
}
}
message TrackDescriptor {
optional uint64 uuid = 1;
optional uint64 parent_uuid = 5;
optional string name = 2;
optional ThreadDescriptor thread = 4;
optional CounterDescriptor counter = 8;
}
message ThreadDescriptor {
optional int32 pid = 1;
optional int32 tid = 2;
optional string thread_name = 5;
}
message CounterDescriptor {
enum BuiltinCounterType {
COUNTER_UNSPECIFIED = 0;
COUNTER_THREAD_TIME_NS = 1;
COUNTER_THREAD_INSTRUCTION_COUNT = 2;
}
enum Unit {
UNIT_UNSPECIFIED = 0;
UNIT_TIME_NS = 1;
UNIT_COUNT = 2;
UNIT_SIZE_BYTES = 3;
}
optional BuiltinCounterType type = 1;
repeated string categories = 2;
optional Unit unit = 3;
optional int64 unit_multiplier = 4;
optional bool is_incremental = 5;
}
message DebugAnnotation {
message NestedValue {
enum NestedType {
UNSPECIFIED = 0;
DICT = 1;
ARRAY = 2;
}
optional NestedType nested_type = 1;
repeated string dict_keys = 2;
repeated NestedValue dict_values = 3;
repeated NestedValue array_values = 4;
optional int64 int_value = 5;
optional double double_value = 6;
optional bool bool_value = 7;
optional string string_value = 8;
}
oneof name_field {
uint64 name_iid = 1;
string name = 10;
}
oneof value {
bool bool_value = 2;
uint64 uint_value = 3;
int64 int_value = 4;
double double_value = 5;
string string_value = 6;
uint64 pointer_value = 7;
NestedValue nested_value = 8;
}
}