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.

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

1588452: Don't crash TimingDistribution.start() prior to Glean.init #400

Merged
merged 4 commits into from
Oct 24, 2019
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
3 changes: 3 additions & 0 deletions CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -2,6 +2,9 @@

[Full changelog](https://github.com/mozilla/glean/compare/v19.0.0...master)

* Fixed a crash calling `start` on a timing distribution metric before Glean is initialized.
Timings are always measured, but only recorded when upload is enabled.

# v19.0.0 (2019-10-22)

[Full changelog](https://github.com/mozilla/glean/compare/v0.0.1-TESTING6...v19.0.0)
Expand Down
4 changes: 4 additions & 0 deletions docs/user/metrics/timing_distribution.md
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,10 @@ To measure the distribution of single timespans, see [Timespans](timespan.md). T
Timing distributions are recorded in a histogram where the buckets have an exponential distribution, specifically with 8 buckets for every power of 2.
This makes them suitable for measuring timings on a number of time scales without any configuration.

Timings always span the full length between `start` and `stopAndAccumulate`.
If the Glean upload is disabled when calling `start`, the timer is still started.
If the Glean upload is disabled at the time `stopAndAccumulate` is called, nothing is recorded.

## Configuration

If you wanted to create a timing distribution to measure page load times, first you need to add an entry for it to the `metrics.yaml` file:
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -82,9 +82,9 @@ class TimingDistributionMetricType internal constructor(

// No dispatcher, we need the return value
return LibGleanFFI.INSTANCE.glean_timing_distribution_set_start(
Glean.handle,
[email protected],
startTime)
this@TimingDistributionMetricType.handle,
startTime
)
}

/**
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -313,7 +313,7 @@ internal interface LibGleanFFI : Library {

fun glean_destroy_timing_distribution_metric(handle: Long)

fun glean_timing_distribution_set_start(glean_handle: Long, metric_id: Long, start_time: Long): GleanTimerId
fun glean_timing_distribution_set_start(metric_id: Long, start_time: Long): GleanTimerId

fun glean_timing_distribution_set_stop_and_accumulate(
glean_handle: Long,
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -4,8 +4,11 @@

package mozilla.telemetry.glean.private

import android.content.Context
import androidx.test.core.app.ApplicationProvider
import androidx.test.ext.junit.runners.AndroidJUnit4
import mozilla.telemetry.glean.Dispatchers
import mozilla.telemetry.glean.Glean
import mozilla.telemetry.glean.testing.GleanTestRule
import org.junit.Assert.assertEquals
import org.junit.Assert.assertTrue
Expand All @@ -20,6 +23,9 @@ import org.mockito.Mockito.`when`
@RunWith(AndroidJUnit4::class)
class TimingDistributionMetricTypeTest {

val context: Context
get() = ApplicationProvider.getApplicationContext()

@get:Rule
val gleanRule = GleanTestRule(ApplicationProvider.getApplicationContext())

Expand Down Expand Up @@ -139,7 +145,7 @@ class TimingDistributionMetricTypeTest {

@Test
fun `The accumulateSamples API correctly stores timing values`() {
// Define a timing distribution metric which will be stored in multiple stores
// Define a timing distribution metric
val metric = TimingDistributionMetricType(
disabled = false,
category = "telemetry",
Expand Down Expand Up @@ -168,4 +174,48 @@ class TimingDistributionMetricTypeTest {
assertEquals(1L, snapshot.values[1969251187])
assertEquals(1L, snapshot.values[2784941737])
}

@Test
fun `Starting a timer before initialization doesn't crash`() {
Glean.testDestroyGleanHandle()
@Suppress("EXPERIMENTAL_API_USAGE")
Dispatchers.API.setTaskQueueing(true)

val metric = TimingDistributionMetricType(
disabled = false,
category = "telemetry",
lifetime = Lifetime.Ping,
name = "timing_distribution_samples",
sendInPings = listOf("store1"),
timeUnit = TimeUnit.Second
)

val timerId = metric.start()
Glean.initialize(context)
metric.stopAndAccumulate(timerId)

metric.testGetValue().sum >= 0
}

@Test
fun `Starting and stopping a timer before initialization doesn't crash`() {
Glean.testDestroyGleanHandle()
@Suppress("EXPERIMENTAL_API_USAGE")
Dispatchers.API.setTaskQueueing(true)

val metric = TimingDistributionMetricType(
disabled = false,
category = "telemetry",
lifetime = Lifetime.Ping,
name = "timing_distribution_samples",
sendInPings = listOf("store1"),
timeUnit = TimeUnit.Second
)

val timerId = metric.start()
metric.stopAndAccumulate(timerId)
Glean.initialize(context)

metric.testGetValue().sum >= 0
}
}
3 changes: 1 addition & 2 deletions glean-core/ffi/glean.h
Original file line number Diff line number Diff line change
Expand Up @@ -401,8 +401,7 @@ void glean_timing_distribution_accumulate_samples(uint64_t glean_handle,

void glean_timing_distribution_cancel(uint64_t metric_id, TimerId timer_id);

TimerId glean_timing_distribution_set_start(uint64_t glean_handle,
uint64_t metric_id,
TimerId glean_timing_distribution_set_start(uint64_t metric_id,
uint64_t start_time);

void glean_timing_distribution_set_stop_and_accumulate(uint64_t glean_handle,
Expand Down
12 changes: 3 additions & 9 deletions glean-core/ffi/src/timing_distribution.rs
Original file line number Diff line number Diff line change
Expand Up @@ -17,15 +17,9 @@ define_metric!(TimingDistributionMetric => TIMING_DISTRIBUTION_METRICS {
});

#[no_mangle]
pub extern "C" fn glean_timing_distribution_set_start(
glean_handle: u64,
metric_id: u64,
start_time: u64,
) -> TimerId {
GLEAN.call_infallible(glean_handle, |glean| {
TIMING_DISTRIBUTION_METRICS
.call_infallible_mut(metric_id, |metric| metric.set_start(glean, start_time))
})
pub extern "C" fn glean_timing_distribution_set_start(metric_id: u64, start_time: u64) -> TimerId {
TIMING_DISTRIBUTION_METRICS
.call_infallible_mut(metric_id, |metric| metric.set_start(start_time))
}

#[no_mangle]
Expand Down
4 changes: 1 addition & 3 deletions glean-core/ios/Glean/GleanFfi.h
Original file line number Diff line number Diff line change
Expand Up @@ -401,9 +401,7 @@ void glean_timing_distribution_accumulate_samples(uint64_t glean_handle,

void glean_timing_distribution_cancel(uint64_t metric_id, TimerId timer_id);

TimerId glean_timing_distribution_set_start(uint64_t glean_handle,
uint64_t metric_id,
uint64_t start_time);
TimerId glean_timing_distribution_set_start(uint64_t metric_id, uint64_t start_time);

void glean_timing_distribution_set_stop_and_accumulate(uint64_t glean_handle,
uint64_t metric_id,
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -59,7 +59,7 @@ public class TimingDistributionMetricType {
let startTime = timestampNanos()

// No dispatcher, we need the return value
return glean_timing_distribution_set_start(Glean.shared.handle, self.handle, startTime)
return glean_timing_distribution_set_start(self.handle, startTime)
}

/// Stop tracking time for the provided metric and associated timer id. Add a
Expand Down
6 changes: 1 addition & 5 deletions glean-core/src/metrics/timing_distribution.rs
Original file line number Diff line number Diff line change
Expand Up @@ -145,11 +145,7 @@ impl TimingDistributionMetric {
/// ## Return value
///
/// Returns a unique `TimerId` for the new timer.
pub fn set_start(&mut self, glean: &Glean, start_time: u64) -> TimerId {
if !self.should_record(glean) {
return 0;
}

pub fn set_start(&mut self, start_time: u64) -> TimerId {
self.timings.set_start(start_time)
}

Expand Down
8 changes: 4 additions & 4 deletions glean-core/tests/timing_distribution.rs
Original file line number Diff line number Diff line change
Expand Up @@ -45,7 +45,7 @@ fn serializer_should_correctly_serialize_timing_distribution() {
time_unit,
);

let id = metric.set_start(&glean, 0);
let id = metric.set_start(0);
metric.set_stop_and_accumulate(&glean, id, duration);

let val = metric
Expand Down Expand Up @@ -89,7 +89,7 @@ fn set_value_properly_sets_the_value_in_all_stores() {
TimeUnit::Nanosecond,
);

let id = metric.set_start(&glean, 0);
let id = metric.set_start(0);
metric.set_stop_and_accumulate(&glean, id, duration);

for store_name in store_names {
Expand Down Expand Up @@ -129,7 +129,7 @@ fn timing_distributions_must_not_accumulate_negative_values() {

// Flip around the timestamps, this should result in a negative value which should be
// discarded.
let id = metric.set_start(&glean, duration);
let id = metric.set_start(duration);
metric.set_stop_and_accumulate(&glean, id, 0);

assert!(metric.test_get_value(&glean, "store1").is_none());
Expand Down Expand Up @@ -256,7 +256,7 @@ fn large_nanoseconds_values() {
let time = Duration::from_secs(10).as_nanos() as u64;
assert!(time > u64::from(u32::max_value()));

let id = metric.set_start(&glean, 0);
let id = metric.set_start(0);
metric.set_stop_and_accumulate(&glean, id, time);

let val = metric
Expand Down