Reimplemented profiler to use tracing.
This commit is contained in:
Samuel Guerra
parent
5101fd74e6
commit
3026c13e44
|
|
@ -1,7 +1,4 @@
|
|||
{
|
||||
"rust.features": [
|
||||
"app_profiler"
|
||||
],
|
||||
"spellright.language": [
|
||||
"en"
|
||||
],
|
||||
|
|
|
|||
|
|
@ -10,13 +10,6 @@ readme = "README.md"
|
|||
path = "zero-ui/lib.rs"
|
||||
|
||||
[features]
|
||||
# Enable the zero_ui::core::profiler module.
|
||||
#
|
||||
# USAGE:
|
||||
#
|
||||
# `#[cfg(feature = "app_profiler")` or just use the `profile_scope!` macro.
|
||||
app_profiler = ["zero-ui-core/app_profiler"]
|
||||
|
||||
# # Other Features
|
||||
#
|
||||
# ## `doc_nightly`
|
||||
|
|
|
|||
|
|
@ -4,11 +4,14 @@ use zero_ui::prelude::*;
|
|||
use zero_ui_view_prebuilt as zero_ui_view;
|
||||
|
||||
fn main() {
|
||||
examples_util::print_info();
|
||||
//examples_util::print_info();
|
||||
let rec = examples_util::record_profile("profile-gradient.json");
|
||||
// zero_ui_view::run_same_process(app_main);
|
||||
|
||||
zero_ui_view::init();
|
||||
app_main();
|
||||
|
||||
rec.finish();
|
||||
}
|
||||
|
||||
fn app_main() {
|
||||
|
|
@ -32,9 +35,6 @@ fn app_main() {
|
|||
};
|
||||
}
|
||||
});
|
||||
|
||||
#[cfg(feature = "app_profiler")]
|
||||
zero_ui::core::profiler::write_profile("profile-gradient.json", false);
|
||||
}
|
||||
|
||||
fn title(title: &'static str) -> impl Widget {
|
||||
|
|
|
|||
|
|
@ -22,9 +22,6 @@ fn app_main() {
|
|||
};
|
||||
}
|
||||
});
|
||||
|
||||
#[cfg(feature = "app_profiler")]
|
||||
zero_ui::core::profiler::write_profile("same_process-profile.json", false);
|
||||
}
|
||||
|
||||
fn click_counter() -> impl Widget {
|
||||
|
|
|
|||
|
|
@ -5,4 +5,7 @@ edition = "2021"
|
|||
|
||||
[dependencies]
|
||||
tracing = "0.1"
|
||||
tracing-subscriber = "0.3"
|
||||
tracing-subscriber = "0.3"
|
||||
flume = "0.10"
|
||||
rustc-hash = "1"
|
||||
v_jsonescape = "0.6"
|
||||
|
|
@ -1,31 +1,46 @@
|
|||
use tracing::{Level, Subscriber};
|
||||
use tracing_subscriber::{layer::Layer, prelude::*};
|
||||
|
||||
/// Prints `tracing` and `log` events of level INFO and above.
|
||||
mod profiler;
|
||||
pub use profiler::*;
|
||||
|
||||
/// Prints `tracing` and `log` events of levels INFO, WARN and ERROR.
|
||||
pub fn print_info() {
|
||||
tracing_print(Level::INFO)
|
||||
}
|
||||
|
||||
/// Prints `tracing` and `log` events of all levels.
|
||||
pub fn print_trace() {
|
||||
tracing_print(Level::TRACE)
|
||||
}
|
||||
|
||||
fn tracing_print(max: Level) {
|
||||
tracing_subscriber::registry()
|
||||
.with(CustomFilter)
|
||||
.with(FilterLayer(max))
|
||||
.with(tracing_subscriber::fmt::layer().without_time().pretty())
|
||||
.init();
|
||||
}
|
||||
|
||||
struct CustomFilter;
|
||||
impl<S: Subscriber> Layer<S> for CustomFilter {
|
||||
struct FilterLayer(Level);
|
||||
impl<S: Subscriber> Layer<S> for FilterLayer {
|
||||
fn enabled(&self, metadata: &tracing::Metadata<'_>, _: tracing_subscriber::layer::Context<'_, S>) -> bool {
|
||||
if metadata.level() > &Level::INFO {
|
||||
return false;
|
||||
}
|
||||
|
||||
// suppress webrender vertex debug-only warnings.
|
||||
// see: https://bugzilla.mozilla.org/show_bug.cgi?id=1615342
|
||||
if metadata.target() == "webrender::device::gl" && metadata.line() == Some(2331) {
|
||||
return false;
|
||||
}
|
||||
|
||||
true
|
||||
filter(&self.0, metadata)
|
||||
}
|
||||
|
||||
fn max_level_hint(&self) -> Option<tracing::metadata::LevelFilter> {
|
||||
Some(tracing::metadata::LevelFilter::INFO)
|
||||
Some(self.0.into())
|
||||
}
|
||||
}
|
||||
fn filter(level: &Level, metadata: &tracing::Metadata) -> bool {
|
||||
if metadata.level() > level {
|
||||
return false;
|
||||
}
|
||||
|
||||
// suppress webrender vertex debug-only warnings.
|
||||
// see: https://bugzilla.mozilla.org/show_bug.cgi?id=1615342
|
||||
if metadata.target() == "webrender::device::gl" && metadata.line() == Some(2331) {
|
||||
return false;
|
||||
}
|
||||
|
||||
true
|
||||
}
|
||||
|
|
|
|||
|
|
@ -0,0 +1,293 @@
|
|||
use std::{
|
||||
cell::Cell,
|
||||
fs::File,
|
||||
io::{BufWriter, Write},
|
||||
path::Path,
|
||||
sync::atomic::{AtomicU64, Ordering},
|
||||
thread::{self, ThreadId},
|
||||
};
|
||||
|
||||
use rustc_hash::FxHashMap;
|
||||
use tracing::{span, Level, Subscriber};
|
||||
use v_jsonescape::escape;
|
||||
|
||||
/// Start recording trace level spans and events.
|
||||
///
|
||||
/// Call [`Recording::finish`] to stop recording and wait flush.
|
||||
///
|
||||
/// Profiles can be viewed using the `chrome://tracing` app.
|
||||
pub fn record_profile(path: impl AsRef<Path>) -> Recording {
|
||||
let mut file = BufWriter::new(File::create(path).unwrap());
|
||||
let (sender, recv) = flume::unbounded();
|
||||
|
||||
let worker = thread::spawn(move || {
|
||||
let mut threads = FxHashMap::<ThreadId, String>::default();
|
||||
let mut spans = FxHashMap::<span::Id, Span>::default();
|
||||
|
||||
struct Span {
|
||||
name: &'static str,
|
||||
target: &'static str,
|
||||
file: Option<&'static str>,
|
||||
line: Option<u32>,
|
||||
}
|
||||
|
||||
let pid = std::process::id();
|
||||
|
||||
// specs: https://docs.google.com/document/d/1CvAClvFfyA5R-PhYUmn5OOQtYMH4h6I0nSsKchNAySU/preview#heading=h.lpfof2aylapb
|
||||
|
||||
write!(&mut file, "[").unwrap();
|
||||
let mut comma = "";
|
||||
loop {
|
||||
match recv.recv().unwrap() {
|
||||
Msg::Event {
|
||||
tid,
|
||||
name,
|
||||
target,
|
||||
file: c_file,
|
||||
line,
|
||||
ts,
|
||||
} => {
|
||||
let tid = threads.get(&tid).unwrap();
|
||||
write!(
|
||||
&mut file,
|
||||
r#"{}{{"pid":"{}","tid":"{}","ts":{},"ph":"i","name":"{}","args":{{"target":"{}""#,
|
||||
comma,
|
||||
pid,
|
||||
tid,
|
||||
ts,
|
||||
escape(name),
|
||||
escape(target)
|
||||
)
|
||||
.unwrap();
|
||||
if let Some(f) = c_file {
|
||||
write!(&mut file, r#","file":"{}""#, escape(f)).unwrap();
|
||||
}
|
||||
if let Some(l) = line {
|
||||
write!(&mut file, r#","line":{}"#, l).unwrap();
|
||||
}
|
||||
write!(&mut file, "}}}}").unwrap();
|
||||
comma = ",";
|
||||
}
|
||||
Msg::Enter { id, tid, ts } => {
|
||||
let span = spans.get(&id).unwrap();
|
||||
let tid = threads.get(&tid).unwrap();
|
||||
write!(
|
||||
&mut file,
|
||||
r#"{}{{"pid":"{}","tid":"{}","name":"{}","ph":"B","ts":{},"args":{{"target":"{}""#,
|
||||
comma,
|
||||
pid,
|
||||
tid,
|
||||
escape(span.name),
|
||||
ts,
|
||||
escape(span.target)
|
||||
)
|
||||
.unwrap();
|
||||
if let Some(f) = span.file {
|
||||
write!(&mut file, r#","file":"{}""#, escape(f)).unwrap();
|
||||
}
|
||||
if let Some(l) = span.line {
|
||||
write!(&mut file, r#","line":{}"#, l).unwrap();
|
||||
}
|
||||
write!(&mut file, "}}}}").unwrap();
|
||||
comma = ",";
|
||||
}
|
||||
Msg::Exit { id, tid, ts } => {
|
||||
let _ = id;
|
||||
let tid = threads.get(&tid).unwrap();
|
||||
write!(
|
||||
&mut file,
|
||||
r#"{}{{"pid":"{}","tid":"{}","ph":"E","ts":{}}}"#,
|
||||
comma,
|
||||
pid,
|
||||
escape(tid),
|
||||
ts
|
||||
)
|
||||
.unwrap();
|
||||
comma = ",";
|
||||
}
|
||||
Msg::NewSpan {
|
||||
id,
|
||||
name,
|
||||
target,
|
||||
file,
|
||||
line,
|
||||
} => {
|
||||
spans.insert(id, Span { name, target, file, line });
|
||||
}
|
||||
Msg::ThreadInfo { id, name } => {
|
||||
threads.insert(id, name);
|
||||
}
|
||||
Msg::Finish => break,
|
||||
}
|
||||
}
|
||||
write!(&mut file, "]").unwrap();
|
||||
|
||||
file.flush().unwrap();
|
||||
});
|
||||
|
||||
tracing::dispatcher::set_global_default(tracing::Dispatch::new(Profiler::new(sender.clone()))).unwrap();
|
||||
|
||||
Recording { sender, worker }
|
||||
}
|
||||
|
||||
/// A running recording operation.
|
||||
pub struct Recording {
|
||||
sender: flume::Sender<Msg>,
|
||||
worker: thread::JoinHandle<()>,
|
||||
}
|
||||
impl Recording {
|
||||
/// Stop recording and wait flush.
|
||||
pub fn finish(self) {
|
||||
self.sender.send(Msg::Finish).unwrap();
|
||||
self.worker.join().unwrap();
|
||||
}
|
||||
}
|
||||
|
||||
enum Msg {
|
||||
ThreadInfo {
|
||||
id: ThreadId,
|
||||
name: String,
|
||||
},
|
||||
|
||||
NewSpan {
|
||||
id: span::Id,
|
||||
name: &'static str,
|
||||
target: &'static str,
|
||||
file: Option<&'static str>,
|
||||
line: Option<u32>,
|
||||
},
|
||||
|
||||
Event {
|
||||
tid: ThreadId,
|
||||
name: &'static str,
|
||||
target: &'static str,
|
||||
file: Option<&'static str>,
|
||||
line: Option<u32>,
|
||||
ts: u64,
|
||||
},
|
||||
|
||||
Enter {
|
||||
id: span::Id,
|
||||
tid: ThreadId,
|
||||
ts: u64,
|
||||
},
|
||||
Exit {
|
||||
id: span::Id,
|
||||
tid: ThreadId,
|
||||
ts: u64,
|
||||
},
|
||||
|
||||
Finish,
|
||||
}
|
||||
|
||||
struct Profiler {
|
||||
id: AtomicU64,
|
||||
sender: flume::Sender<Msg>,
|
||||
}
|
||||
impl Profiler {
|
||||
fn new(sender: flume::Sender<Msg>) -> Self {
|
||||
Profiler {
|
||||
id: AtomicU64::new(1),
|
||||
sender,
|
||||
}
|
||||
}
|
||||
|
||||
fn thread_id(&self) -> ThreadId {
|
||||
let thread = thread::current();
|
||||
let tid = thread.id();
|
||||
|
||||
THREAD_INFO.with(|sent| {
|
||||
if !sent.get() {
|
||||
sent.set(true);
|
||||
|
||||
self.sender
|
||||
.send(Msg::ThreadInfo {
|
||||
id: tid,
|
||||
name: thread
|
||||
.name()
|
||||
.map(|n| escape(n).to_string())
|
||||
.unwrap_or_else(|| format!("<{:?}>", tid)),
|
||||
})
|
||||
.unwrap();
|
||||
}
|
||||
});
|
||||
|
||||
tid
|
||||
}
|
||||
}
|
||||
impl Subscriber for Profiler {
|
||||
fn enabled(&self, metadata: &tracing::Metadata<'_>) -> bool {
|
||||
crate::filter(&Level::TRACE, metadata)
|
||||
}
|
||||
|
||||
fn new_span(&self, span: &span::Attributes<'_>) -> span::Id {
|
||||
let id = span::Id::from_u64(self.id.fetch_add(1, Ordering::Relaxed));
|
||||
|
||||
let meta = span.metadata();
|
||||
|
||||
self.sender
|
||||
.send(Msg::NewSpan {
|
||||
id: id.clone(),
|
||||
name: meta.name(),
|
||||
target: meta.target(),
|
||||
file: meta.file(),
|
||||
line: meta.line(),
|
||||
})
|
||||
.unwrap();
|
||||
|
||||
id
|
||||
}
|
||||
|
||||
fn record(&self, span: &span::Id, values: &span::Record<'_>) {
|
||||
let _ = (span, values);
|
||||
}
|
||||
|
||||
fn record_follows_from(&self, span: &span::Id, follows: &span::Id) {
|
||||
let _ = (span, follows);
|
||||
}
|
||||
|
||||
fn event(&self, event: &tracing::Event<'_>) {
|
||||
let ts = time_ns();
|
||||
|
||||
let tid = self.thread_id();
|
||||
let meta = event.metadata();
|
||||
|
||||
self.sender
|
||||
.send(Msg::Event {
|
||||
tid,
|
||||
name: meta.name(),
|
||||
target: meta.target(),
|
||||
file: meta.file(),
|
||||
line: meta.line(),
|
||||
ts,
|
||||
})
|
||||
.unwrap();
|
||||
}
|
||||
|
||||
fn enter(&self, span: &span::Id) {
|
||||
let ts = time_ns();
|
||||
|
||||
let tid = self.thread_id();
|
||||
|
||||
self.sender.send(Msg::Enter { id: span.clone(), tid, ts }).unwrap();
|
||||
}
|
||||
|
||||
fn exit(&self, span: &span::Id) {
|
||||
let ts = time_ns();
|
||||
|
||||
let tid = self.thread_id();
|
||||
|
||||
self.sender.send(Msg::Exit { id: span.clone(), tid, ts }).unwrap();
|
||||
}
|
||||
}
|
||||
|
||||
fn time_ns() -> u64 {
|
||||
std::time::SystemTime::now()
|
||||
.duration_since(std::time::UNIX_EPOCH)
|
||||
.unwrap()
|
||||
.as_micros() as u64
|
||||
}
|
||||
|
||||
thread_local! {
|
||||
static THREAD_INFO: Cell<bool> = Cell::new(false);
|
||||
}
|
||||
|
|
@ -116,9 +116,6 @@ fn app_main() {
|
|||
};
|
||||
}
|
||||
});
|
||||
|
||||
#[cfg(feature = "app_profiler")]
|
||||
zero_ui::core::profiler::write_profile("window-profile.json", false);
|
||||
}
|
||||
|
||||
fn property_stack(header: &'static str, items: impl WidgetList) -> impl Widget {
|
||||
|
|
|
|||
|
|
@ -195,15 +195,13 @@ fn test(mut args: Vec<&str>) {
|
|||
}
|
||||
}
|
||||
|
||||
// do run, r EXAMPLE [-p, --profile] [-b, --backtrace] [<cargo-run-args>]
|
||||
// Run an example in ./examples. If profiling builds in release with app_profiler.
|
||||
// do run, r EXAMPLE [-b, --backtrace] [<cargo-run-args>]
|
||||
// Run an example in ./examples.
|
||||
// USAGE:
|
||||
// run some_example
|
||||
// Runs the example in debug mode.
|
||||
// run some_example --release
|
||||
// Runs the example in release mode.
|
||||
// run some_example --profile
|
||||
// Runs the example "app_profiler" feature.
|
||||
// run some_example --backtrace
|
||||
// Runs the "some_example" with `RUST_BACKTRACE=1`.
|
||||
// run *
|
||||
|
|
@ -215,18 +213,7 @@ fn run(mut args: Vec<&str>) {
|
|||
("", "")
|
||||
};
|
||||
|
||||
if take_flag(&mut args, &["-p", "--profile"]) {
|
||||
let release = take_flag(&mut args, &["--release"]);
|
||||
let rust_flags = release_rust_flags(release);
|
||||
let rust_flags = &[(rust_flags.0, rust_flags.1.as_str()), trace];
|
||||
let release = if release { "--release" } else { "" };
|
||||
cmd_env(
|
||||
"cargo",
|
||||
&["run", "--features", "app_profiler", release, "--example"],
|
||||
&args,
|
||||
rust_flags,
|
||||
);
|
||||
} else if let Some(&"*") = args.first() {
|
||||
if let Some(&"*") = args.first() {
|
||||
args.remove(0);
|
||||
let release = args.contains(&"--release");
|
||||
let rust_flags = release_rust_flags(release);
|
||||
|
|
|
|||
|
|
@ -6,13 +6,6 @@ edition = "2021"
|
|||
license = "Apache-2.0"
|
||||
|
||||
[features]
|
||||
# Enable the zero_ui_core::profiler module.
|
||||
#
|
||||
# USAGE:
|
||||
#
|
||||
# `#[cfg(feature = "app_profiler")` or just use the `profile_scope!` macro.
|
||||
app_profiler = []
|
||||
|
||||
# like cfg(test) but also visible in docs and integration tests.
|
||||
#
|
||||
# USAGE:
|
||||
|
|
|
|||
|
|
@ -4,7 +4,6 @@ use crate::context::*;
|
|||
use crate::crate_util::PanicPayload;
|
||||
use crate::event::{cancelable_event_args, event, AnyEventUpdate, EventUpdate, EventUpdateArgs, Events};
|
||||
use crate::image::ImageManager;
|
||||
use crate::profiler::*;
|
||||
use crate::timer::Timers;
|
||||
use crate::var::{response_var, ResponderVar, ResponseVar, Vars};
|
||||
use crate::{
|
||||
|
|
@ -713,9 +712,6 @@ impl<E: AppExtension> AppExtended<E> {
|
|||
/// Panics if not called by the main thread. This means you cannot run an app in unit tests, use a headless
|
||||
/// app without renderer for that. The main thread is required by some operating systems and OpenGL.
|
||||
pub fn run(self, start: impl FnOnce(&mut AppContext)) {
|
||||
#[cfg(feature = "app_profiler")]
|
||||
register_thread_with_profiler();
|
||||
|
||||
let mut app = RunningApp::start(self.extensions, true, true, self.view_process_exe);
|
||||
|
||||
start(&mut app.ctx());
|
||||
|
|
@ -733,9 +729,6 @@ impl<E: AppExtension> AppExtended<E> {
|
|||
/// If called in a test (`cfg(test)`) this blocks until no other instance of [`HeadlessApp`] and
|
||||
/// [`TestWidgetContext`] are running in the current thread.
|
||||
pub fn run_headless(self, with_renderer: bool) -> HeadlessApp {
|
||||
#[cfg(feature = "app_profiler")]
|
||||
register_thread_with_profiler();
|
||||
|
||||
let app = RunningApp::start(self.extensions.boxed(), false, with_renderer, self.view_process_exe);
|
||||
|
||||
HeadlessApp { app }
|
||||
|
|
@ -767,7 +760,7 @@ impl<E: AppExtension> RunningApp<E> {
|
|||
}
|
||||
}
|
||||
|
||||
profile_scope!("App::start");
|
||||
let _s = tracing::debug_span!("App::start").entered();
|
||||
|
||||
let (sender, receiver) = AppEventSender::new();
|
||||
|
||||
|
|
@ -795,7 +788,7 @@ impl<E: AppExtension> RunningApp<E> {
|
|||
}
|
||||
|
||||
{
|
||||
profile_scope!("extensions.init");
|
||||
let _s = tracing::debug_span!("extensions.init").entered();
|
||||
extensions.init(&mut ctx);
|
||||
}
|
||||
|
||||
|
|
@ -852,7 +845,7 @@ impl<E: AppExtension> RunningApp<E> {
|
|||
args: Ev::Args,
|
||||
observer: &mut O,
|
||||
) {
|
||||
profile_scope!("notify_event<{}>", type_name::<Ev>());
|
||||
let _scope = tracing::trace_span!("notify_event", event = type_name::<Ev>()).entered();
|
||||
|
||||
let update = EventUpdate::<Ev>(args);
|
||||
extensions.event_preview(ctx, &update);
|
||||
|
|
@ -877,8 +870,7 @@ impl<E: AppExtension> RunningApp<E> {
|
|||
let mut flow = ControlFlow::Poll;
|
||||
|
||||
while let ControlFlow::Poll = flow {
|
||||
#[cfg(feature = "app_profiler")]
|
||||
let idle = crate::profiler::ProfileScope::new("<poll-idle>");
|
||||
let idle = tracing::trace_span!("<poll-idle>").entered();
|
||||
|
||||
let ev = if let Some(timer) = self.wake_time {
|
||||
match self.receiver.recv_deadline(timer) {
|
||||
|
|
@ -897,7 +889,6 @@ impl<E: AppExtension> RunningApp<E> {
|
|||
self.receiver.recv().expect("app events channel disconnected")
|
||||
};
|
||||
|
||||
#[cfg(feature = "app_profiler")]
|
||||
drop(idle);
|
||||
|
||||
flow = if !matches!(ev, AppEvent::ViewEvent(view_process::Event::EventsCleared)) || self.receiver.is_empty() {
|
||||
|
|
@ -937,7 +928,7 @@ impl<E: AppExtension> RunningApp<E> {
|
|||
|
||||
/// Process an [`AppEvent`].
|
||||
fn app_event<O: AppEventObserver>(&mut self, app_event: AppEvent, observer: &mut O) -> ControlFlow {
|
||||
profile_scope!("app_event");
|
||||
let _s = tracing::trace_span!("app_event").entered();
|
||||
|
||||
self.maybe_has_updates = true;
|
||||
|
||||
|
|
@ -962,15 +953,7 @@ impl<E: AppExtension> RunningApp<E> {
|
|||
///
|
||||
/// Does `update` on `EventsCleared`.
|
||||
fn view_event<O: AppEventObserver>(&mut self, ev: zero_ui_view_api::Event, observer: &mut O) -> ControlFlow {
|
||||
profile_scope!("view_event");
|
||||
profile_scope!("{}", {
|
||||
let ev = format!("Event::{:?}", ev);
|
||||
let l = ev.len();
|
||||
let p = ev.find('(').unwrap_or(l);
|
||||
let c = ev.find('{').unwrap_or(l);
|
||||
let i = p.min(c);
|
||||
ev[..i].to_owned()
|
||||
});
|
||||
let _s = tracing::debug_span!("view_event", ?ev).entered();
|
||||
|
||||
use raw_device_events::*;
|
||||
use raw_events::*;
|
||||
|
|
@ -1294,7 +1277,7 @@ impl<E: AppExtension> RunningApp<E> {
|
|||
/// [`wake_time`]: RunningApp::wake_time
|
||||
pub fn update<O: AppEventObserver>(&mut self, observer: &mut O) -> ControlFlow {
|
||||
if self.maybe_has_updates {
|
||||
profile_scope!("update-cycle");
|
||||
let _s = tracing::debug_span!("update-cycle").entered();
|
||||
|
||||
self.maybe_has_updates = false;
|
||||
|
||||
|
|
@ -1318,7 +1301,7 @@ impl<E: AppExtension> RunningApp<E> {
|
|||
if u.update {
|
||||
// check shutdown.
|
||||
if let Some(r) = ctx.services.app_process().take_requests() {
|
||||
profile_scope!("shutdown_requested");
|
||||
let _s = tracing::debug_span!("shutdown_requested").entered();
|
||||
|
||||
let args = ShutdownRequestedArgs::now();
|
||||
|
||||
|
|
@ -1338,10 +1321,10 @@ impl<E: AppExtension> RunningApp<E> {
|
|||
|
||||
// does `Event` notifications.
|
||||
{
|
||||
profile_scope!("events");
|
||||
let _s = tracing::trace_span!("events").entered();
|
||||
|
||||
for event in u.events {
|
||||
profile_scope!("{:?}", event);
|
||||
let _s = tracing::debug_span!("event", ?event).entered();
|
||||
|
||||
self.extensions.event_preview(&mut ctx, &event);
|
||||
observer.event_preview(&mut ctx, &event);
|
||||
|
|
@ -1358,7 +1341,7 @@ impl<E: AppExtension> RunningApp<E> {
|
|||
|
||||
// does general updates.
|
||||
{
|
||||
profile_scope!("update");
|
||||
let _s = tracing::trace_span!("update").entered();
|
||||
|
||||
self.extensions.update_preview(&mut ctx);
|
||||
observer.update_preview(&mut ctx);
|
||||
|
|
@ -1372,14 +1355,14 @@ impl<E: AppExtension> RunningApp<E> {
|
|||
Updates::on_updates(&mut ctx);
|
||||
}
|
||||
} else if layout {
|
||||
profile_scope!("layout");
|
||||
let _s = tracing::trace_span!("layout").entered();
|
||||
|
||||
self.extensions.layout(&mut ctx);
|
||||
observer.layout(&mut ctx);
|
||||
|
||||
layout = false;
|
||||
} else if render {
|
||||
profile_scope!("render");
|
||||
let _s = tracing::trace_span!("render").entered();
|
||||
|
||||
self.extensions.render(&mut ctx);
|
||||
observer.render(&mut ctx);
|
||||
|
|
@ -1400,7 +1383,7 @@ impl<E: AppExtension> RunningApp<E> {
|
|||
}
|
||||
impl<E: AppExtension> Drop for RunningApp<E> {
|
||||
fn drop(&mut self) {
|
||||
profile_scope!("extensions.deinit");
|
||||
let _s = tracing::debug_span!("extensions.deinit").entered();
|
||||
let mut ctx = self.owned_ctx.borrow();
|
||||
self.extensions.deinit(&mut ctx);
|
||||
}
|
||||
|
|
@ -1932,7 +1915,7 @@ pub mod view_process {
|
|||
use crate::task::SignalOnce;
|
||||
use crate::units::{DipPoint, DipSize, Px, PxPoint, PxRect, PxSize};
|
||||
use crate::window::{MonitorId, WindowId};
|
||||
use crate::{event, event_args, profile_scope};
|
||||
use crate::{event, event_args};
|
||||
use zero_ui_view_api::webrender_api::{
|
||||
DocumentId, FontInstanceKey, FontInstanceOptions, FontInstancePlatformOptions, FontKey, FontVariation, HitTestResult, IdNamespace,
|
||||
ImageKey, PipelineId,
|
||||
|
|
@ -1992,7 +1975,7 @@ pub mod view_process {
|
|||
where
|
||||
F: FnMut(Event) + Send + 'static,
|
||||
{
|
||||
profile_scope!("ViewProcess::start");
|
||||
let _s = tracing::debug_span!("ViewProcess::start").entered();
|
||||
|
||||
let process = zero_ui_view_api::Controller::start(view_process_exe, device_events, headless, on_event);
|
||||
Self(Rc::new(RefCell::new(ViewApp {
|
||||
|
|
@ -2020,7 +2003,7 @@ pub mod view_process {
|
|||
|
||||
/// Open a window and associate it with the `window_id`.
|
||||
pub fn open_window(&self, config: WindowRequest) -> Result<(ViewWindow, WindowOpenData)> {
|
||||
profile_scope!("ViewProcess.open_window");
|
||||
let _s = tracing::debug_span!("ViewProcess.open_window").entered();
|
||||
|
||||
let mut app = self.0.borrow_mut();
|
||||
let _ = app.check_generation();
|
||||
|
|
@ -2044,7 +2027,7 @@ pub mod view_process {
|
|||
/// Note that no actual window is created, only the renderer, the use of window-ids to identify
|
||||
/// this renderer is only for convenience.
|
||||
pub fn open_headless(&self, config: HeadlessRequest) -> Result<ViewHeadless> {
|
||||
profile_scope!("ViewProcess.open_headless");
|
||||
let _s = tracing::debug_span!("ViewProcess.open_headless").entered();
|
||||
|
||||
let mut app = self.0.borrow_mut();
|
||||
|
||||
|
|
@ -3063,13 +3046,13 @@ pub mod view_process {
|
|||
|
||||
/// Render a new frame.
|
||||
pub fn render(&self, frame: FrameRequest) -> Result<()> {
|
||||
profile_scope!("ViewRenderer.render");
|
||||
let _s = tracing::debug_span!("ViewRenderer.render").entered();
|
||||
self.call(|id, p| p.render(id, frame))
|
||||
}
|
||||
|
||||
/// Update the current frame and re-render it.
|
||||
pub fn render_update(&self, frame: FrameUpdateRequest) -> Result<()> {
|
||||
profile_scope!("ViewRenderer.render_update");
|
||||
let _s = tracing::debug_span!("ViewRenderer.render_update").entered();
|
||||
self.call(|id, p| p.render_update(id, frame))
|
||||
}
|
||||
}
|
||||
|
|
|
|||
|
|
@ -55,7 +55,7 @@ use crate::{
|
|||
context::RenderContext,
|
||||
crate_util::IdMap,
|
||||
event::EventUpdateArgs,
|
||||
formatx, profile_scope,
|
||||
formatx,
|
||||
text::{Text, ToText},
|
||||
BoxedUiNode,
|
||||
};
|
||||
|
|
@ -673,7 +673,7 @@ impl UiNode for PropertyInfoNode {
|
|||
}
|
||||
|
||||
fn render(&self, ctx: &mut RenderContext, frame: &mut FrameBuilder) {
|
||||
profile_scope!("{}.render", self.info.borrow().property_name);
|
||||
let _scope = tracing::trace_span!("property.render", property = self.info.borrow().property_name).entered();
|
||||
|
||||
let t = Instant::now();
|
||||
self.child.render(ctx, frame);
|
||||
|
|
|
|||
|
|
@ -54,7 +54,6 @@ pub mod gradient;
|
|||
pub mod image;
|
||||
pub mod keyboard;
|
||||
pub mod mouse;
|
||||
pub mod profiler;
|
||||
pub mod render;
|
||||
pub mod service;
|
||||
pub mod task;
|
||||
|
|
|
|||
|
|
@ -1,261 +0,0 @@
|
|||
//! Performance profiling.
|
||||
//!
|
||||
//! Crate must be compiled with the `app_profiler`. See [`profile_scope!`] and [`write_profile`] for more details.
|
||||
//!
|
||||
//! Profiler can be viewed using the `chrome://tracing` app.
|
||||
//!
|
||||
//! [`profile_scope!`]: crate::profiler::profile_scope
|
||||
//! [`write_profile`]: crate::profiler::write_profile
|
||||
|
||||
#[cfg(feature = "app_profiler")]
|
||||
#[cfg_attr(doc_nightly, doc(cfg(feature = "app_profiler")))]
|
||||
mod profiler_impl {
|
||||
use serde_json::*;
|
||||
|
||||
use crate::text::Text;
|
||||
use flume::{unbounded, Receiver, Sender};
|
||||
use parking_lot::{const_mutex, Mutex};
|
||||
use std::cell::RefCell;
|
||||
use std::fs::File;
|
||||
use std::io::BufWriter;
|
||||
use std::string::String;
|
||||
use std::thread;
|
||||
use std::time::{SystemTime, UNIX_EPOCH};
|
||||
|
||||
static GLOBAL_PROFILER: Mutex<Option<Profiler>> = const_mutex(None);
|
||||
|
||||
thread_local!(static THREAD_PROFILER: RefCell<Option<ThreadProfiler>> = RefCell::new(None));
|
||||
|
||||
#[derive(Copy, Clone)]
|
||||
struct ThreadId(usize);
|
||||
|
||||
struct ThreadInfo {
|
||||
name: String,
|
||||
}
|
||||
|
||||
struct Sample {
|
||||
tid: ThreadId,
|
||||
name: Text,
|
||||
t0: u64,
|
||||
t1: u64,
|
||||
}
|
||||
|
||||
struct ThreadProfiler {
|
||||
id: ThreadId,
|
||||
tx: Sender<Sample>,
|
||||
}
|
||||
|
||||
impl ThreadProfiler {
|
||||
fn push_sample(&self, name: Text, t0: u64, t1: u64) {
|
||||
let sample = Sample {
|
||||
tid: self.id,
|
||||
name,
|
||||
t0,
|
||||
t1,
|
||||
};
|
||||
self.tx.send(sample).ok();
|
||||
}
|
||||
}
|
||||
|
||||
struct Profiler {
|
||||
rx: Receiver<Sample>,
|
||||
tx: Sender<Sample>,
|
||||
threads: Vec<ThreadInfo>,
|
||||
}
|
||||
|
||||
impl Profiler {
|
||||
fn new() -> Profiler {
|
||||
let (tx, rx) = unbounded();
|
||||
|
||||
Profiler {
|
||||
rx,
|
||||
tx,
|
||||
threads: Vec::new(),
|
||||
}
|
||||
}
|
||||
|
||||
fn register_thread(&mut self) {
|
||||
let registered_name = THREAD_PROFILER.with(|profiler| {
|
||||
if profiler.borrow().is_none() {
|
||||
let id = ThreadId(self.threads.len());
|
||||
|
||||
let thread_profiler = ThreadProfiler { id, tx: self.tx.clone() };
|
||||
*profiler.borrow_mut() = Some(thread_profiler);
|
||||
|
||||
Some(match thread::current().name() {
|
||||
Some(s) => s.to_string(),
|
||||
None => format!("<unnamed-{}>", id.0),
|
||||
})
|
||||
} else {
|
||||
None
|
||||
}
|
||||
});
|
||||
if let Some(mut name) = registered_name {
|
||||
if cfg!(debug_assertions) {
|
||||
name.push_str("-DEBUG");
|
||||
}
|
||||
self.threads.push(ThreadInfo { name });
|
||||
}
|
||||
}
|
||||
|
||||
fn write_profile(&self, filename: &str, ignore_0ms: bool) {
|
||||
// Stop reading samples that are written after
|
||||
// write_profile() is called.
|
||||
let start_time = precise_time_ns();
|
||||
let mut data = Vec::new();
|
||||
|
||||
let p_id = std::process::id();
|
||||
|
||||
while let Ok(sample) = self.rx.try_recv() {
|
||||
if sample.t0 > start_time {
|
||||
break;
|
||||
}
|
||||
|
||||
let thread_id = self.threads[sample.tid.0].name.as_str();
|
||||
let t0 = sample.t0 / 1000;
|
||||
let t1 = sample.t1 / 1000;
|
||||
|
||||
if ignore_0ms && t0 == t1 {
|
||||
continue;
|
||||
}
|
||||
|
||||
data.push(json!({
|
||||
"pid": p_id,
|
||||
"tid": thread_id,
|
||||
"name": sample.name.as_ref(),
|
||||
"ph": "B",
|
||||
"ts": t0
|
||||
}));
|
||||
|
||||
data.push(json!({
|
||||
"pid": p_id,
|
||||
"tid": thread_id,
|
||||
"ph": "E",
|
||||
"ts": t1
|
||||
}));
|
||||
}
|
||||
|
||||
let f = BufWriter::new(File::create(filename).unwrap());
|
||||
serde_json::to_writer(f, &data).unwrap();
|
||||
}
|
||||
}
|
||||
|
||||
/// Named profile scope. The scope start time is when [`new`](ProfileScope::new) is called,
|
||||
/// the scope duration is the time it was alive.
|
||||
///
|
||||
/// # Example
|
||||
///
|
||||
/// ```
|
||||
/// # use zero_ui_core::profiler::ProfileScope;
|
||||
/// # fn do_thing() { }
|
||||
/// # fn do_another_thing() { }
|
||||
/// {
|
||||
/// #[cfg(feature = "app_profiler")]
|
||||
/// let _scope = ProfileScope::new("do-things");
|
||||
///
|
||||
/// do_thing();
|
||||
/// do_another_thing();
|
||||
/// }
|
||||
/// ```
|
||||
///
|
||||
/// # Macro
|
||||
///
|
||||
/// For basic usage like in the example there is also the [`profile_scope!`](macro.profile_scope.html) macro.
|
||||
#[cfg_attr(doc_nightly, doc(cfg(feature = "app_profiler")))]
|
||||
pub struct ProfileScope {
|
||||
name: Text,
|
||||
t0: u64,
|
||||
}
|
||||
impl ProfileScope {
|
||||
/// Starts a new profile scope, the start time is when this method is called.
|
||||
pub fn new(name: impl Into<Text>) -> ProfileScope {
|
||||
let t0 = precise_time_ns();
|
||||
ProfileScope { name: name.into(), t0 }
|
||||
}
|
||||
}
|
||||
impl Drop for ProfileScope {
|
||||
/// When the `ProfileScope` is dropped it records the
|
||||
/// length of time it was alive for and records it
|
||||
/// against the Profiler.
|
||||
fn drop(&mut self) {
|
||||
let t1 = precise_time_ns();
|
||||
|
||||
THREAD_PROFILER.with(|profiler| match *profiler.borrow() {
|
||||
Some(ref profiler) => {
|
||||
profiler.push_sample(std::mem::take(&mut self.name), self.t0, t1);
|
||||
}
|
||||
None => {
|
||||
println!("ERROR: ProfileScope {} on unregistered thread!", self.name);
|
||||
}
|
||||
});
|
||||
}
|
||||
}
|
||||
|
||||
/// Writes the global profile to a specific file.
|
||||
#[inline]
|
||||
#[cfg_attr(doc_nightly, doc(cfg(feature = "app_profiler")))]
|
||||
pub fn write_profile(filename: &str, ignore_0ms: bool) {
|
||||
GLOBAL_PROFILER
|
||||
.lock()
|
||||
.get_or_insert_with(Profiler::new)
|
||||
.write_profile(filename, ignore_0ms);
|
||||
}
|
||||
|
||||
/// Registers the current thread with the global profiler.
|
||||
///
|
||||
/// Does nothing if the thread is already registered.
|
||||
#[inline]
|
||||
#[cfg_attr(doc_nightly, doc(cfg(feature = "app_profiler")))]
|
||||
pub fn register_thread_with_profiler() {
|
||||
GLOBAL_PROFILER.lock().get_or_insert_with(Profiler::new).register_thread();
|
||||
}
|
||||
|
||||
fn precise_time_ns() -> u64 {
|
||||
SystemTime::now().duration_since(UNIX_EPOCH).unwrap().as_nanos() as u64
|
||||
}
|
||||
}
|
||||
|
||||
#[cfg(feature = "app_profiler")]
|
||||
pub use profiler_impl::*;
|
||||
|
||||
///<span data-inline></span> Declares a [`ProfileScope`](crate::profiler::ProfileScope) variable if
|
||||
/// the `app_profiler` feature is active.
|
||||
///
|
||||
/// # Example
|
||||
///
|
||||
/// If compiled with the `app_profiler` feature, this will register a "do-things" scope
|
||||
/// that starts when the macro was called and has the duration of the block.
|
||||
/// ```
|
||||
/// # use zero_ui_core::profiler::profile_scope;
|
||||
/// # fn main()
|
||||
/// {
|
||||
/// # fn do_thing() { }
|
||||
/// # fn do_another_thing() { }
|
||||
/// profile_scope!("do-things");
|
||||
///
|
||||
/// do_thing();
|
||||
/// do_another_thing();
|
||||
/// }
|
||||
/// ```
|
||||
///
|
||||
/// You can also format strings:
|
||||
/// ```
|
||||
/// # use zero_ui_core::profiler::profile_scope;
|
||||
/// # let thing = "";
|
||||
/// profile_scope!("do-{}", thing);
|
||||
/// ```
|
||||
#[macro_export]
|
||||
macro_rules! profile_scope {
|
||||
($name:expr) => {
|
||||
#[cfg(feature = "app_profiler")]
|
||||
let _profile_scope =
|
||||
$crate::profiler::ProfileScope::new($name);
|
||||
};
|
||||
($($args:tt)+) => {
|
||||
#[cfg(feature = "app_profiler")]
|
||||
let _profile_scope =
|
||||
$crate::profiler::ProfileScope::new(format!($($args)+));
|
||||
};
|
||||
}
|
||||
#[doc(inline)]
|
||||
pub use crate::profile_scope;
|
||||
|
|
@ -27,7 +27,7 @@ use crate::{
|
|||
event::{event, EventUpdateArgs},
|
||||
event_args,
|
||||
image::{Image, ImageDataFormat, ImageSource, ImageVar, ImagesExt},
|
||||
impl_from_and_into_var, profile_scope,
|
||||
impl_from_and_into_var,
|
||||
render::{
|
||||
webrender_api::{BuiltDisplayList, DynamicProperties, ExternalScrollId, PipelineId},
|
||||
FrameBuilder, FrameHitInfo, FrameId, FrameInfo, FrameUpdate, WidgetTransformKey,
|
||||
|
|
@ -1901,12 +1901,12 @@ impl AppWindow {
|
|||
|
||||
fn on_update(&mut self, ctx: &mut AppContext) {
|
||||
if self.first_update {
|
||||
profile_scope!("window({}).on_update-init", self.id.sequential());
|
||||
let _s = tracing::trace_span!("window.on_update#first", window = %self.id.sequential());
|
||||
|
||||
self.context.init(ctx);
|
||||
self.first_update = false;
|
||||
} else {
|
||||
profile_scope!("window({}).on_update", self.id.sequential());
|
||||
let _s = tracing::trace_span!("window.on_update", window = %self.id.sequential());
|
||||
|
||||
self.context.update(ctx);
|
||||
|
||||
|
|
@ -2141,7 +2141,7 @@ impl AppWindow {
|
|||
return;
|
||||
}
|
||||
|
||||
profile_scope!("window({}).on_layout", self.id.sequential());
|
||||
let _s = tracing::trace_span!("window.on_layout", window = %self.id.sequential());
|
||||
|
||||
// layout using the "system" size, it can still be overwritten by auto_size.
|
||||
let (size, _, _) = self.layout_size(ctx, true);
|
||||
|
|
@ -2167,7 +2167,7 @@ impl AppWindow {
|
|||
fn on_init_layout(&mut self, ctx: &mut AppContext) {
|
||||
debug_assert!(self.first_layout);
|
||||
|
||||
profile_scope!("window({}).on_init_layout", self.id.sequential());
|
||||
let _s = tracing::trace_span!("window.on_init_layout", window = %self.id.sequential());
|
||||
|
||||
self.first_layout = false;
|
||||
|
||||
|
|
@ -2501,7 +2501,7 @@ impl AppWindow {
|
|||
return;
|
||||
}
|
||||
|
||||
profile_scope!("window({}).on_render", self.id.sequential());
|
||||
let _s = tracing::trace_span!("window.on_render", window = %self.id.sequential());
|
||||
|
||||
let frame = self.render_frame(ctx);
|
||||
|
||||
|
|
@ -2519,7 +2519,7 @@ impl AppWindow {
|
|||
return;
|
||||
}
|
||||
|
||||
profile_scope!("window({}).on_render_update", self.id.sequential());
|
||||
let _s = tracing::trace_span!("window.on_render_update", window = %self.id.sequential());
|
||||
|
||||
let capture_image = self.take_capture_image(ctx.vars);
|
||||
|
||||
|
|
@ -2669,7 +2669,7 @@ impl OwnedWindowContext {
|
|||
scale_factor: f32,
|
||||
renderer: &Option<ViewRenderer>,
|
||||
) -> ((PipelineId, BuiltDisplayList), RenderColor, FrameInfo) {
|
||||
profile_scope!("WindowContext.render");
|
||||
let _s = tracing::trace_span!("WindowContext.render");
|
||||
|
||||
self.update = WindowUpdates::none();
|
||||
|
||||
|
|
|
|||
Loading…
Reference in New Issue