You are viewing a plain text version of this content. The canonical link for it is here.
Posted to reviews@aurora.apache.org by Kai Huang <te...@hotmail.com> on 2017/01/04 17:59:55 UTC
Re: Review Request 55105: AURORA-1870 Add finer grained timings to the
Snapshot process
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/55105/#review160517
-----------------------------------------------------------
src/main/java/org/apache/aurora/scheduler/storage/log/SnapshotStoreImpl.java (line 521)
<https://reviews.apache.org/r/55105/#comment231657>
If we need this elsewhere, can we make the timing part more reusable like:
Stats.time("statsName", () -> {#function to time})
- Kai Huang
On Dec. 30, 2016, 9:18 p.m., Mehrdad Nurolahzade wrote:
>
> -----------------------------------------------------------
> This is an automatically generated e-mail. To reply, visit:
> https://reviews.apache.org/r/55105/
> -----------------------------------------------------------
>
> (Updated Dec. 30, 2016, 9:18 p.m.)
>
>
> Review request for Aurora, David McLaughlin and Joshua Cohen.
>
>
> Bugs: AURORA-1870
> https://issues.apache.org/jira/browse/AURORA-1870
>
>
> Repository: aurora
>
>
> Description
> -------
>
> AURORA-1870 Add finer grained timings to the Snapshot process
>
> I gave up on `@Timed` interceptor approach because major refactoring is required in order to have snapshot fields instantiated by Guice through `Provider` or `@Provides` interfaces. The abstract class approach is much easier/cleaner.
>
>
> Diffs
> -----
>
> src/main/java/org/apache/aurora/scheduler/storage/log/SnapshotStoreImpl.java 7aa111ec14696ae40f518c42f3c7f45d8ab0e94c
> src/test/java/org/apache/aurora/scheduler/storage/log/SnapshotStoreImplIT.java f56a1624c7188da175ad3e6de323c3442802f2ea
>
> Diff: https://reviews.apache.org/r/55105/diff/
>
>
> Testing
> -------
>
> ```
> $ curl localhost:8081/vars | grep snapshot_restore
> % Total % Received % Xferd Average Speed Time Time Time Current
> Dload Upload Total Spent Left Speed
> 0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0
> snapshot_restore_crons_events 1
> snapshot_restore_crons_events_per_sec 0.0
> snapshot_restore_crons_nanos_per_event 0.0
> snapshot_restore_crons_nanos_total 73648
> snapshot_restore_crons_nanos_total_per_sec 0.0
> snapshot_restore_dbscript_events 1
> snapshot_restore_dbscript_events_per_sec 0.0
> snapshot_restore_dbscript_nanos_per_event 0.0
> snapshot_restore_dbscript_nanos_total 1148842021
> snapshot_restore_dbscript_nanos_total_per_sec 0.0
> snapshot_restore_hosts_events 1
> snapshot_restore_hosts_events_per_sec 0.0
> snapshot_restore_hosts_nanos_per_event 0.0
> snapshot_restore_hosts_nanos_total 76166
> snapshot_restore_hosts_nanos_total_per_sec 0.0
> snapshot_restore_job_updates_events 1
> snapshot_restore_job_updates_events_per_sec 0.0
> snapshot_restore_job_updates_nanos_per_event 0.0
> snapshot_restore_job_updates_nanos_total 49482
> snapshot_restore_job_updates_nanos_total_per_sec 0.0
> snapshot_restore_locks_events 1
> snapshot_restore_locks_events_per_sec 0.0
> snapshot_restore_locks_nanos_per_event 0.0
> snapshot_restore_locks_nanos_total 125084
> snapshot_restore_locks_nanos_total_per_sec 0.0
> snapshot_restore_quota_events 1
> snapshot_restore_quota_events_per_sec 0.0
> snapshot_restore_quota_nanos_per_event 0.0
> snapshot_restore_quota_nanos_total 52305
> snapshot_restore_quota_nanos_total_per_sec 0.0
> snapshot_restore_scheduler_metadata_events 1
> snapshot_restore_scheduler_metadata_events_per_sec 0.0
> snapshot_restore_scheduler_metadata_nanos_per_event 0.0
> snapshot_restore_scheduler_metadata_nanos_total 70816
> snapshot_restore_scheduler_metadata_nanos_total_per_sec 0.0
> snapshot_restore_tasks_events 1
> snapshot_restore_tasks_events_per_sec 0.0
> snapshot_restore_tasks_nanos_per_event 0.0
> snapshot_restore_tasks_nanos_total 91377
> snapshot_restore_tasks_nanos_total_per_sec 0.0
> ```
>
> ```
> $ aurora_admin scheduler_snapshot devcluster
> INFO] Response from scheduler: OK (message: )
>
> $ curl localhost:8081/vars | grep snapshot_save
> % Total % Received % Xferd Average Speed Time Time Time Current
> Dload Upload Total Spent Left Speed
> 100 48226 0 48226 0 0 3266k 0 --:--:-- --:--:-- --:--:-- 3363k
> snapshot_save_crons_events 1
> snapshot_save_crons_events_per_sec 0.0
> snapshot_save_crons_nanos_per_event 0.0
> snapshot_save_crons_nanos_total 466181
> snapshot_save_crons_nanos_total_per_sec 0.0
> snapshot_save_dbscript_events 1
> snapshot_save_dbscript_events_per_sec 0.0
> snapshot_save_dbscript_nanos_per_event 0.0
> snapshot_save_dbscript_nanos_total 18201542
> snapshot_save_dbscript_nanos_total_per_sec 0.0
> snapshot_save_hosts_events 1
> snapshot_save_hosts_events_per_sec 0.0
> snapshot_save_hosts_nanos_per_event 0.0
> snapshot_save_hosts_nanos_total 1286180
> snapshot_save_hosts_nanos_total_per_sec 0.0
> snapshot_save_job_updates_events 1
> snapshot_save_job_updates_events_per_sec 0.0
> snapshot_save_job_updates_nanos_per_event 0.0
> snapshot_save_job_updates_nanos_total 123760632
> snapshot_save_job_updates_nanos_total_per_sec 0.0
> snapshot_save_locks_events 1
> snapshot_save_locks_events_per_sec 0.0
> snapshot_save_locks_nanos_per_event 0.0
> snapshot_save_locks_nanos_total 1523926
> snapshot_save_locks_nanos_total_per_sec 0.0
> snapshot_save_quota_events 1
> snapshot_save_quota_events_per_sec 0.0
> snapshot_save_quota_nanos_per_event 0.0
> snapshot_save_quota_nanos_total 5725489
> snapshot_save_quota_nanos_total_per_sec 0.0
> snapshot_save_scheduler_metadata_events 1
> snapshot_save_scheduler_metadata_events_per_sec 0.0
> snapshot_save_scheduler_metadata_nanos_per_event 0.0
> snapshot_save_scheduler_metadata_nanos_total 2142
> snapshot_save_scheduler_metadata_nanos_total_per_sec 0.0
> snapshot_save_tasks_events 1
> snapshot_save_tasks_events_per_sec 0.0
> snapshot_save_tasks_nanos_per_event 0.0
> snapshot_save_tasks_nanos_total 6939463
> snapshot_save_tasks_nanos_total_per_sec 0.0
> ```
>
>
> Thanks,
>
> Mehrdad Nurolahzade
>
>
Re: Review Request 55105: AURORA-1870 Add finer grained timings to the
Snapshot process
Posted by Mehrdad Nurolahzade <me...@nurolahzade.com>.
> On Jan. 4, 2017, 9:59 a.m., Kai Huang wrote:
> > src/main/java/org/apache/aurora/scheduler/storage/log/SnapshotStoreImpl.java, line 521
> > <https://reviews.apache.org/r/55105/diff/1/?file=1594663#file1594663line521>
> >
> > If we need this elsewhere, can we make the timing part more reusable like:
> >
> > Stats.time("statsName", () -> {#function to time})
>
> Mehrdad Nurolahzade wrote:
> Currently, in Java 8, only `Supplier`, `Function`, and `BiFunction` functional interfaces are supported (e.g., 0, 1, and 2 argument functions). There is no way to represent a multi-argument function with an unknown argument list. That's why we are using AOP to intercept method calls and perform timing on them.
Actually, I retract that comment, this can be implemented using either `Supplier` or `Callable` interfaces. For example like:
```
static <T> T time(SlidingStats stat, Callable<T> callable) throws Exception {
long start = System.nanoTime();
try {
return callable.call();
} finally {
stat.accumulate(System.nanoTime() - start);
}
}
```
then it can be used like:
```
SlidingStats stat = new SlidingStats("someName", "nanos");
Stats.time(stat, () -> {
Thread.sleep(100);
return "HelloWorld";
});
```
Thanks for pointing it out.
cc @shirchen
- Mehrdad
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/55105/#review160517
-----------------------------------------------------------
On Dec. 30, 2016, 1:18 p.m., Mehrdad Nurolahzade wrote:
>
> -----------------------------------------------------------
> This is an automatically generated e-mail. To reply, visit:
> https://reviews.apache.org/r/55105/
> -----------------------------------------------------------
>
> (Updated Dec. 30, 2016, 1:18 p.m.)
>
>
> Review request for Aurora, David McLaughlin and Joshua Cohen.
>
>
> Bugs: AURORA-1870
> https://issues.apache.org/jira/browse/AURORA-1870
>
>
> Repository: aurora
>
>
> Description
> -------
>
> AURORA-1870 Add finer grained timings to the Snapshot process
>
> I gave up on `@Timed` interceptor approach because major refactoring is required in order to have snapshot fields instantiated by Guice through `Provider` or `@Provides` interfaces. The abstract class approach is much easier/cleaner.
>
>
> Diffs
> -----
>
> src/main/java/org/apache/aurora/scheduler/storage/log/SnapshotStoreImpl.java 7aa111ec14696ae40f518c42f3c7f45d8ab0e94c
> src/test/java/org/apache/aurora/scheduler/storage/log/SnapshotStoreImplIT.java f56a1624c7188da175ad3e6de323c3442802f2ea
>
> Diff: https://reviews.apache.org/r/55105/diff/
>
>
> Testing
> -------
>
> ```
> $ curl localhost:8081/vars | grep snapshot_restore
> % Total % Received % Xferd Average Speed Time Time Time Current
> Dload Upload Total Spent Left Speed
> 0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0
> snapshot_restore_crons_events 1
> snapshot_restore_crons_events_per_sec 0.0
> snapshot_restore_crons_nanos_per_event 0.0
> snapshot_restore_crons_nanos_total 73648
> snapshot_restore_crons_nanos_total_per_sec 0.0
> snapshot_restore_dbscript_events 1
> snapshot_restore_dbscript_events_per_sec 0.0
> snapshot_restore_dbscript_nanos_per_event 0.0
> snapshot_restore_dbscript_nanos_total 1148842021
> snapshot_restore_dbscript_nanos_total_per_sec 0.0
> snapshot_restore_hosts_events 1
> snapshot_restore_hosts_events_per_sec 0.0
> snapshot_restore_hosts_nanos_per_event 0.0
> snapshot_restore_hosts_nanos_total 76166
> snapshot_restore_hosts_nanos_total_per_sec 0.0
> snapshot_restore_job_updates_events 1
> snapshot_restore_job_updates_events_per_sec 0.0
> snapshot_restore_job_updates_nanos_per_event 0.0
> snapshot_restore_job_updates_nanos_total 49482
> snapshot_restore_job_updates_nanos_total_per_sec 0.0
> snapshot_restore_locks_events 1
> snapshot_restore_locks_events_per_sec 0.0
> snapshot_restore_locks_nanos_per_event 0.0
> snapshot_restore_locks_nanos_total 125084
> snapshot_restore_locks_nanos_total_per_sec 0.0
> snapshot_restore_quota_events 1
> snapshot_restore_quota_events_per_sec 0.0
> snapshot_restore_quota_nanos_per_event 0.0
> snapshot_restore_quota_nanos_total 52305
> snapshot_restore_quota_nanos_total_per_sec 0.0
> snapshot_restore_scheduler_metadata_events 1
> snapshot_restore_scheduler_metadata_events_per_sec 0.0
> snapshot_restore_scheduler_metadata_nanos_per_event 0.0
> snapshot_restore_scheduler_metadata_nanos_total 70816
> snapshot_restore_scheduler_metadata_nanos_total_per_sec 0.0
> snapshot_restore_tasks_events 1
> snapshot_restore_tasks_events_per_sec 0.0
> snapshot_restore_tasks_nanos_per_event 0.0
> snapshot_restore_tasks_nanos_total 91377
> snapshot_restore_tasks_nanos_total_per_sec 0.0
> ```
>
> ```
> $ aurora_admin scheduler_snapshot devcluster
> INFO] Response from scheduler: OK (message: )
>
> $ curl localhost:8081/vars | grep snapshot_save
> % Total % Received % Xferd Average Speed Time Time Time Current
> Dload Upload Total Spent Left Speed
> 100 48226 0 48226 0 0 3266k 0 --:--:-- --:--:-- --:--:-- 3363k
> snapshot_save_crons_events 1
> snapshot_save_crons_events_per_sec 0.0
> snapshot_save_crons_nanos_per_event 0.0
> snapshot_save_crons_nanos_total 466181
> snapshot_save_crons_nanos_total_per_sec 0.0
> snapshot_save_dbscript_events 1
> snapshot_save_dbscript_events_per_sec 0.0
> snapshot_save_dbscript_nanos_per_event 0.0
> snapshot_save_dbscript_nanos_total 18201542
> snapshot_save_dbscript_nanos_total_per_sec 0.0
> snapshot_save_hosts_events 1
> snapshot_save_hosts_events_per_sec 0.0
> snapshot_save_hosts_nanos_per_event 0.0
> snapshot_save_hosts_nanos_total 1286180
> snapshot_save_hosts_nanos_total_per_sec 0.0
> snapshot_save_job_updates_events 1
> snapshot_save_job_updates_events_per_sec 0.0
> snapshot_save_job_updates_nanos_per_event 0.0
> snapshot_save_job_updates_nanos_total 123760632
> snapshot_save_job_updates_nanos_total_per_sec 0.0
> snapshot_save_locks_events 1
> snapshot_save_locks_events_per_sec 0.0
> snapshot_save_locks_nanos_per_event 0.0
> snapshot_save_locks_nanos_total 1523926
> snapshot_save_locks_nanos_total_per_sec 0.0
> snapshot_save_quota_events 1
> snapshot_save_quota_events_per_sec 0.0
> snapshot_save_quota_nanos_per_event 0.0
> snapshot_save_quota_nanos_total 5725489
> snapshot_save_quota_nanos_total_per_sec 0.0
> snapshot_save_scheduler_metadata_events 1
> snapshot_save_scheduler_metadata_events_per_sec 0.0
> snapshot_save_scheduler_metadata_nanos_per_event 0.0
> snapshot_save_scheduler_metadata_nanos_total 2142
> snapshot_save_scheduler_metadata_nanos_total_per_sec 0.0
> snapshot_save_tasks_events 1
> snapshot_save_tasks_events_per_sec 0.0
> snapshot_save_tasks_nanos_per_event 0.0
> snapshot_save_tasks_nanos_total 6939463
> snapshot_save_tasks_nanos_total_per_sec 0.0
> ```
>
>
> Thanks,
>
> Mehrdad Nurolahzade
>
>
Re: Review Request 55105: AURORA-1870 Add finer grained timings to the
Snapshot process
Posted by Mehrdad Nurolahzade <me...@nurolahzade.com>.
> On Jan. 4, 2017, 9:59 a.m., Kai Huang wrote:
> > src/main/java/org/apache/aurora/scheduler/storage/log/SnapshotStoreImpl.java, line 521
> > <https://reviews.apache.org/r/55105/diff/1/?file=1594663#file1594663line521>
> >
> > If we need this elsewhere, can we make the timing part more reusable like:
> >
> > Stats.time("statsName", () -> {#function to time})
Currently, in Java 8, only `Supplier`, `Function`, and `BiFunction` functional interfaces are supported (e.g., 0, 1, and 2 argument functions). There is no way to represent a multi-argument function with an unknown argument list. That's why we are using AOP to intercept method calls and perform timing on them.
- Mehrdad
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/55105/#review160517
-----------------------------------------------------------
On Dec. 30, 2016, 1:18 p.m., Mehrdad Nurolahzade wrote:
>
> -----------------------------------------------------------
> This is an automatically generated e-mail. To reply, visit:
> https://reviews.apache.org/r/55105/
> -----------------------------------------------------------
>
> (Updated Dec. 30, 2016, 1:18 p.m.)
>
>
> Review request for Aurora, David McLaughlin and Joshua Cohen.
>
>
> Bugs: AURORA-1870
> https://issues.apache.org/jira/browse/AURORA-1870
>
>
> Repository: aurora
>
>
> Description
> -------
>
> AURORA-1870 Add finer grained timings to the Snapshot process
>
> I gave up on `@Timed` interceptor approach because major refactoring is required in order to have snapshot fields instantiated by Guice through `Provider` or `@Provides` interfaces. The abstract class approach is much easier/cleaner.
>
>
> Diffs
> -----
>
> src/main/java/org/apache/aurora/scheduler/storage/log/SnapshotStoreImpl.java 7aa111ec14696ae40f518c42f3c7f45d8ab0e94c
> src/test/java/org/apache/aurora/scheduler/storage/log/SnapshotStoreImplIT.java f56a1624c7188da175ad3e6de323c3442802f2ea
>
> Diff: https://reviews.apache.org/r/55105/diff/
>
>
> Testing
> -------
>
> ```
> $ curl localhost:8081/vars | grep snapshot_restore
> % Total % Received % Xferd Average Speed Time Time Time Current
> Dload Upload Total Spent Left Speed
> 0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0
> snapshot_restore_crons_events 1
> snapshot_restore_crons_events_per_sec 0.0
> snapshot_restore_crons_nanos_per_event 0.0
> snapshot_restore_crons_nanos_total 73648
> snapshot_restore_crons_nanos_total_per_sec 0.0
> snapshot_restore_dbscript_events 1
> snapshot_restore_dbscript_events_per_sec 0.0
> snapshot_restore_dbscript_nanos_per_event 0.0
> snapshot_restore_dbscript_nanos_total 1148842021
> snapshot_restore_dbscript_nanos_total_per_sec 0.0
> snapshot_restore_hosts_events 1
> snapshot_restore_hosts_events_per_sec 0.0
> snapshot_restore_hosts_nanos_per_event 0.0
> snapshot_restore_hosts_nanos_total 76166
> snapshot_restore_hosts_nanos_total_per_sec 0.0
> snapshot_restore_job_updates_events 1
> snapshot_restore_job_updates_events_per_sec 0.0
> snapshot_restore_job_updates_nanos_per_event 0.0
> snapshot_restore_job_updates_nanos_total 49482
> snapshot_restore_job_updates_nanos_total_per_sec 0.0
> snapshot_restore_locks_events 1
> snapshot_restore_locks_events_per_sec 0.0
> snapshot_restore_locks_nanos_per_event 0.0
> snapshot_restore_locks_nanos_total 125084
> snapshot_restore_locks_nanos_total_per_sec 0.0
> snapshot_restore_quota_events 1
> snapshot_restore_quota_events_per_sec 0.0
> snapshot_restore_quota_nanos_per_event 0.0
> snapshot_restore_quota_nanos_total 52305
> snapshot_restore_quota_nanos_total_per_sec 0.0
> snapshot_restore_scheduler_metadata_events 1
> snapshot_restore_scheduler_metadata_events_per_sec 0.0
> snapshot_restore_scheduler_metadata_nanos_per_event 0.0
> snapshot_restore_scheduler_metadata_nanos_total 70816
> snapshot_restore_scheduler_metadata_nanos_total_per_sec 0.0
> snapshot_restore_tasks_events 1
> snapshot_restore_tasks_events_per_sec 0.0
> snapshot_restore_tasks_nanos_per_event 0.0
> snapshot_restore_tasks_nanos_total 91377
> snapshot_restore_tasks_nanos_total_per_sec 0.0
> ```
>
> ```
> $ aurora_admin scheduler_snapshot devcluster
> INFO] Response from scheduler: OK (message: )
>
> $ curl localhost:8081/vars | grep snapshot_save
> % Total % Received % Xferd Average Speed Time Time Time Current
> Dload Upload Total Spent Left Speed
> 100 48226 0 48226 0 0 3266k 0 --:--:-- --:--:-- --:--:-- 3363k
> snapshot_save_crons_events 1
> snapshot_save_crons_events_per_sec 0.0
> snapshot_save_crons_nanos_per_event 0.0
> snapshot_save_crons_nanos_total 466181
> snapshot_save_crons_nanos_total_per_sec 0.0
> snapshot_save_dbscript_events 1
> snapshot_save_dbscript_events_per_sec 0.0
> snapshot_save_dbscript_nanos_per_event 0.0
> snapshot_save_dbscript_nanos_total 18201542
> snapshot_save_dbscript_nanos_total_per_sec 0.0
> snapshot_save_hosts_events 1
> snapshot_save_hosts_events_per_sec 0.0
> snapshot_save_hosts_nanos_per_event 0.0
> snapshot_save_hosts_nanos_total 1286180
> snapshot_save_hosts_nanos_total_per_sec 0.0
> snapshot_save_job_updates_events 1
> snapshot_save_job_updates_events_per_sec 0.0
> snapshot_save_job_updates_nanos_per_event 0.0
> snapshot_save_job_updates_nanos_total 123760632
> snapshot_save_job_updates_nanos_total_per_sec 0.0
> snapshot_save_locks_events 1
> snapshot_save_locks_events_per_sec 0.0
> snapshot_save_locks_nanos_per_event 0.0
> snapshot_save_locks_nanos_total 1523926
> snapshot_save_locks_nanos_total_per_sec 0.0
> snapshot_save_quota_events 1
> snapshot_save_quota_events_per_sec 0.0
> snapshot_save_quota_nanos_per_event 0.0
> snapshot_save_quota_nanos_total 5725489
> snapshot_save_quota_nanos_total_per_sec 0.0
> snapshot_save_scheduler_metadata_events 1
> snapshot_save_scheduler_metadata_events_per_sec 0.0
> snapshot_save_scheduler_metadata_nanos_per_event 0.0
> snapshot_save_scheduler_metadata_nanos_total 2142
> snapshot_save_scheduler_metadata_nanos_total_per_sec 0.0
> snapshot_save_tasks_events 1
> snapshot_save_tasks_events_per_sec 0.0
> snapshot_save_tasks_nanos_per_event 0.0
> snapshot_save_tasks_nanos_total 6939463
> snapshot_save_tasks_nanos_total_per_sec 0.0
> ```
>
>
> Thanks,
>
> Mehrdad Nurolahzade
>
>