Merge branch 'imbris/tracy' into 'master'

Add more tracing instrumentation and tracy support

See merge request veloren/veloren!1359
This commit is contained in:
Imbris 2020-09-10 05:07:51 +00:00
commit c3ae641fbb
48 changed files with 393 additions and 33 deletions

View File

@ -6,6 +6,8 @@ rustflags = [
[alias]
generate = "run --package tools --"
test-server = "-Zpackage-features run --bin veloren-server-cli --no-default-features"
tracy-server = "-Zunstable-options -Zpackage-features run --bin veloren-server-cli --no-default-features --features tracy --profile no_overflow"
test-voxygen = "-Zpackage-features run --bin veloren-voxygen --no-default-features --features gl"
tracy-voxygen = "-Zunstable-options -Zpackage-features run --bin veloren-voxygen --no-default-features --features tracy,gl --profile no_overflow"
server = "run --bin veloren-server-cli"

32
Cargo.lock generated
View File

@ -4357,6 +4357,35 @@ dependencies = [
"tracing-serde",
]
[[package]]
name = "tracing-tracy"
version = "0.2.0"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "d4f1c3ed7f680cf645838f62e8dd1f64cd3820ad1af0b8d9585fd69d97f0feab"
dependencies = [
"tracing-core",
"tracing-subscriber",
"tracy-client",
]
[[package]]
name = "tracy-client"
version = "0.8.0"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "650c280019cd1a841752d50f6a834216a2c8a810aeb18bdd48054be23cacd8a6"
dependencies = [
"tracy-client-sys",
]
[[package]]
name = "tracy-client-sys"
version = "0.9.0"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "c07e4636dad390858d247cf2633eaea90e67d7e21151cd476bbfd070d321279f"
dependencies = [
"cc",
]
[[package]]
name = "treeculler"
version = "0.1.0"
@ -4623,6 +4652,7 @@ dependencies = [
"specs-idvs",
"sum_type",
"tracing",
"tracy-client",
"vek 0.12.0",
]
@ -4670,6 +4700,7 @@ dependencies = [
"lazy_static",
"tracing",
"tracing-subscriber",
"tracing-tracy",
"tui",
"veloren-common",
"veloren-server",
@ -4721,6 +4752,7 @@ dependencies = [
"tracing-appender",
"tracing-log",
"tracing-subscriber",
"tracing-tracy",
"treeculler",
"uvth 3.1.1",
"vek 0.12.0",

View File

@ -6,6 +6,7 @@ edition = "2018"
[features]
no-assets = []
tracy = ["tracy-client"]
[dependencies]
arraygen = "0.1.13"
@ -34,6 +35,9 @@ authc = { git = "https://gitlab.com/veloren/auth.git", rev = "b943c85e4a38f5ec60
slab = "0.4.2"
enum-iterator = "0.6"
# Tracy
tracy-client = { version = "0.8.0", optional = true }
[dev-dependencies]
criterion = "0.3"

View File

@ -1,3 +1,4 @@
use crate::span;
use std::{
thread,
time::{Duration, Instant},
@ -31,6 +32,7 @@ impl Clock {
pub fn get_avg_delta(&self) -> Duration { Duration::from_secs_f64(self.running_tps_average) }
pub fn tick(&mut self, tgt: Duration) {
span!(_guard, "tick", "Clock::tick");
let delta = Instant::now().duration_since(self.last_sys_time);
// Attempt to sleep to fill the gap.

View File

@ -1,5 +1,6 @@
use crate::{
astar::{Astar, PathResult},
span,
terrain::Block,
vol::{BaseVol, ReadVol},
};
@ -327,6 +328,7 @@ impl Chaser {
where
V: BaseVol<Vox = Block> + ReadVol,
{
span!(_guard, "chase", "Chaser::chase");
let pos_to_tgt = pos.distance(tgt);
// If we're already close to the target then there's nothing to do

View File

@ -1,4 +1,7 @@
use crate::vol::{ReadVol, Vox};
use crate::{
span,
vol::{ReadVol, Vox},
};
use vek::*;
pub trait RayUntil<V: Vox> = FnMut(&V) -> bool;
@ -52,6 +55,7 @@ impl<'a, V: ReadVol, F: RayUntil<V::Vox>, G: RayForEach<V::Vox>> Ray<'a, V, F, G
}
pub fn cast(mut self) -> (f32, Result<Option<&'a V::Vox>, V::Error>) {
span!(_guard, "cast", "Ray::cast");
// TODO: Fully test this!
const PLANCK: f32 = 0.001;

View File

@ -1,4 +1,7 @@
use crate::comp::{Pos, Vel};
use crate::{
comp::{Pos, Vel},
span,
};
use hashbrown::{hash_map::DefaultHashBuilder, HashSet};
use indexmap::IndexMap;
use specs::{hibitset::BitSetLike, BitSet, Entities, Join, ReadStorage};
@ -104,6 +107,7 @@ impl RegionMap {
// TODO maintain within a system?
// TODO special case large entities
pub fn tick(&mut self, pos: ReadStorage<Pos>, vel: ReadStorage<Vel>, entities: Entities) {
span!(_guard, "tick", "Region::tick");
self.tick += 1;
// Clear events within each region
for i in 0..self.regions.len() {

View File

@ -11,6 +11,7 @@ use crate::{
},
event::{EventBus, ServerEvent},
path::{Chaser, TraversalConfig},
span,
state::{DeltaTime, Time},
sync::{Uid, UidAllocator},
terrain::TerrainGrid,
@ -83,6 +84,7 @@ impl<'a> System<'a> for Sys {
invites,
): Self::SystemData,
) {
span!(_guard, "run", "agent::Sys::run");
for (
entity,
pos,

View File

@ -4,6 +4,7 @@ use crate::{
Loadout, Mounting, Ori, PhysicsState, Pos, StateUpdate, Stats, Vel,
},
event::{EventBus, LocalEvent, ServerEvent},
span,
state::DeltaTime,
states,
sync::{Uid, UidAllocator},
@ -183,6 +184,7 @@ impl<'a> System<'a> for Sys {
mountings,
): Self::SystemData,
) {
span!(_guard, "run", "character_behavior::Sys::run");
let mut server_emitter = server_bus.emitter();
let mut local_emitter = local_bus.emitter();

View File

@ -4,6 +4,7 @@ use crate::{
Loadout, Ori, Pos, Scale, Stats,
},
event::{EventBus, LocalEvent, ServerEvent},
span,
sync::Uid,
util::Dir,
};
@ -52,6 +53,7 @@ impl<'a> System<'a> for Sys {
character_states,
): Self::SystemData,
) {
span!(_guard, "run", "combat::Sys::run");
let mut server_emitter = server_bus.emitter();
let mut local_emitter = local_bus.emitter();
// Attacks

View File

@ -4,6 +4,7 @@ use crate::{
CharacterState, ControlEvent, Controller, InventoryManip,
},
event::{EventBus, LocalEvent, ServerEvent},
span,
state::DeltaTime,
sync::{Uid, UidAllocator},
};
@ -43,6 +44,7 @@ impl<'a> System<'a> for Sys {
uids,
): Self::SystemData,
) {
span!(_guard, "run", "controller::Sys::run");
let mut server_emitter = server_bus.emitter();
for (entity, _uid, controller, character_state) in

View File

@ -1,5 +1,6 @@
use crate::{
comp::{Controller, MountState, Mounting, Ori, Pos, Vel},
span,
sync::UidAllocator,
};
use specs::{
@ -36,6 +37,7 @@ impl<'a> System<'a> for Sys {
mut orientations,
): Self::SystemData,
) {
span!(_guard, "run", "mount::Sys::run");
// Mounted entities.
for (entity, mut mount_states) in (&entities, &mut mount_state.restrict_mut()).join() {
match mount_states.get_unchecked() {

View File

@ -4,6 +4,7 @@ use crate::{
Sticky, Vel,
},
event::{EventBus, ServerEvent},
span,
state::DeltaTime,
sync::{Uid, UidAllocator},
terrain::{Block, BlockKind, TerrainGrid},
@ -94,9 +95,11 @@ impl<'a> System<'a> for Sys {
projectiles,
): Self::SystemData,
) {
span!(_guard, "run", "phys::Sys::run");
let mut event_emitter = event_bus.emitter();
// Add/reset physics state components
span!(guard, "Add/reset physics state components");
for (entity, _, _, _, _) in (
&entities,
&colliders,
@ -110,6 +113,7 @@ impl<'a> System<'a> for Sys {
.entry(entity)
.map(|e| e.or_insert_with(Default::default));
}
drop(guard);
// Apply pushback
//
@ -124,6 +128,7 @@ impl<'a> System<'a> for Sys {
// terrain collision code below, although that's not trivial to do since
// it means the step needs to take into account the speeds of both
// entities.
span!(guard, "Apply pushback");
for (entity, pos, scale, mass, collider, _, _, physics, projectile) in (
&entities,
&positions,
@ -244,8 +249,10 @@ impl<'a> System<'a> for Sys {
.get_mut(entity)
.map(|vel| vel.0 += vel_delta * dt.0);
}
drop(guard);
// Apply movement inputs
span!(guard, "Apply movement and terrain collision");
let land_on_grounds = (
&entities,
scales.maybe(),
@ -646,6 +653,7 @@ impl<'a> System<'a> for Sys {
land_on_grounds_a.append(&mut land_on_grounds_b);
land_on_grounds_a
});
drop(guard);
land_on_grounds.into_iter().for_each(|(entity, vel)| {
event_emitter.emit(ServerEvent::LandOnGround { entity, vel: vel.0 });

View File

@ -4,6 +4,7 @@ use crate::{
Loadout, Ori, PhysicsState, Pos, Projectile, Vel,
},
event::{EventBus, LocalEvent, ServerEvent},
span,
state::DeltaTime,
sync::UidAllocator,
util::Dir,
@ -48,6 +49,7 @@ impl<'a> System<'a> for Sys {
loadouts,
): Self::SystemData,
) {
span!(_guard, "run", "projectile::Sys::run");
let mut local_emitter = local_bus.emitter();
let mut server_emitter = server_bus.emitter();

View File

@ -1,6 +1,7 @@
use crate::{
comp::{CharacterState, Energy, EnergySource, HealthSource, Stats},
event::{EventBus, ServerEvent},
span,
state::DeltaTime,
};
use specs::{Entities, Join, Read, ReadStorage, System, WriteStorage};
@ -24,6 +25,7 @@ impl<'a> System<'a> for Sys {
&mut self,
(entities, dt, server_event_bus, character_states, mut stats, mut energies): Self::SystemData,
) {
span!(_guard, "run", "stats::Sys::run");
let mut server_event_emitter = server_event_bus.emitter();
// Increment last change timer

View File

@ -10,3 +10,77 @@ lazy_static::lazy_static! {
pub use color::*;
pub use dir::*;
#[cfg(feature = "tracy")] pub use tracy_client;
// https://discordapp.com/channels/676678179678715904/676685797524766720/723358438943621151
#[macro_export]
macro_rules! span {
($guard_name:tt, $level:ident, $name:expr, $($fields:tt)*) => {
let span = tracing::span!(tracing::Level::$level, $name, $($fields)*);
let $guard_name = span.enter();
};
($guard_name:tt, $level:ident, $name:expr) => {
let span = tracing::span!(tracing::Level::$level, $name);
let $guard_name = span.enter();
};
($guard_name:tt, $name:expr) => {
#[cfg(not(feature = "tracy"))]
let span = tracing::span!(tracing::Level::TRACE, $name);
#[cfg(not(feature = "tracy"))]
let $guard_name = span.enter();
// Directly use `tracy_client` to decrease overhead for better timing
#[cfg(feature = "tracy")]
let $guard_name = $crate::util::tracy_client::Span::new(
$name,
"",
module_path!(),
line!(),
// No callstack since this has significant overhead
0,
);
};
($guard_name:tt, $no_tracy_name:expr, $tracy_name:expr) => {
#[cfg(not(feature = "tracy"))]
$crate::span!($guard_name, $no_tracy_name);
#[cfg(feature = "tracy")]
$crate::span!($guard_name, $tracy_name);
};
}
/// There's no guard, but really this is actually the guard
pub struct GuardlessSpan {
span: tracing::Span,
subscriber: tracing::Dispatch,
}
impl GuardlessSpan {
pub fn new(span: tracing::Span) -> Self {
let subscriber = tracing::dispatcher::get_default(|d| d.clone());
span.id().map(|id| subscriber.enter(&id));
Self { span, subscriber }
}
}
impl Drop for GuardlessSpan {
fn drop(&mut self) { self.span.id().map(|id| self.subscriber.exit(&id)); }
}
#[macro_export]
macro_rules! no_guard_span {
($level:ident, $name:expr, $($fields:tt)*) => {
GuardlessSpan::new(
tracing::span!(tracing::Level::$level, $name, $($fields)*)
)
};
($level:ident, $name:expr) => {
GuardlessSpan::new(
tracing::span!(tracing::Level::$level, $name)
)
};
($name:expr) => {
GuardlessSpan::new(
tracing::span!(tracing::Level::TRACE, $name)
)
};
}

View File

@ -7,17 +7,21 @@ edition = "2018"
[features]
worldgen = ["server/worldgen"]
default = ["worldgen"]
tracy = ["common/tracy", "tracing-tracy"]
[dependencies]
server = { package = "veloren-server", path = "../server", default-features = false }
common = { package = "veloren-common", path = "../common" }
tracing = { version = "0.1", default-features = false }
tracing-subscriber = { version = "0.2.3", default-features = false, features = ["env-filter", "fmt", "chrono", "ansi", "smallvec"] }
crossterm = "0.17"
lazy_static = "1"
ansi-parser = "0.6"
clap = "2.33"
crossterm = "0.17"
lazy_static = "1"
tracing = { version = "0.1", default-features = false }
tracing-subscriber = { version = "0.2.3", default-features = false, features = ["env-filter", "fmt", "chrono", "ansi", "smallvec"] }
# Tracy
tracing-tracy = { version = "0.2.0", optional = true }
[dependencies.tui]
git = "https://github.com/fdehau/tui-rs.git"

View File

@ -13,6 +13,8 @@ use common::clock::Clock;
use server::{Event, Input, Server, ServerSettings};
use tracing::{info, Level};
use tracing_subscriber::{filter::LevelFilter, EnvFilter, FmtSubscriber};
#[cfg(feature = "tracy")]
use tracing_subscriber::{layer::SubscriberExt, prelude::*};
use clap::{App, Arg};
use std::{io, sync::mpsc, time::Duration};
@ -49,6 +51,7 @@ fn main() -> io::Result<()> {
let (mut tui, msg_r) = Tui::new();
// Init logging
#[cfg(not(feature = "tracy"))]
let filter = match std::env::var_os(RUST_LOG_ENV).map(|s| s.into_string()) {
Some(Ok(env)) => {
let mut filter = EnvFilter::new("veloren_world::sim=info")
@ -68,6 +71,15 @@ fn main() -> io::Result<()> {
.add_directive(LevelFilter::INFO.into()),
};
#[cfg(feature = "tracy")]
tracing_subscriber::registry()
.with(tracing_tracy::TracyLayer::new().with_stackdepth(0))
.init();
#[cfg(not(feature = "tracy"))]
// TODO: when tracing gets per Layer filters re-enable this when the tracy feature is being
// used (and do the same in voxygen)
{
let subscriber = FmtSubscriber::builder()
.with_max_level(Level::ERROR)
.with_env_filter(filter);
@ -77,6 +89,7 @@ fn main() -> io::Result<()> {
} else {
subscriber.with_writer(|| LOG.clone()).init();
}
}
tui.run(basic);
@ -111,6 +124,8 @@ fn main() -> io::Result<()> {
// Clean up the server after a tick.
server.cleanup();
#[cfg(feature = "tracy")]
common::util::tracy_client::finish_continuous_frame!();
match msg_r.try_recv() {
Ok(msg) => match msg {

View File

@ -1,5 +1,8 @@
use crate::{state_ext::StateExt, Server};
use common::event::{EventBus, ServerEvent};
use common::{
event::{EventBus, ServerEvent},
span,
};
use entity_creation::{
handle_create_npc, handle_create_waypoint, handle_initialize_character,
handle_loaded_character_data, handle_shoot,
@ -36,6 +39,7 @@ pub enum Event {
impl Server {
pub fn handle_events(&mut self) -> Vec<Event> {
span!(_guard, "handle_events", "Server::handle_events");
let mut frontend_events = Vec::new();
let mut requested_chunks = Vec::new();

View File

@ -6,6 +6,7 @@ use common::{
comp,
comp::{group, Player},
msg::{ClientState, PlayerListUpdate, ServerMsg},
span,
sync::{Uid, UidAllocator},
};
use futures_executor::block_on;
@ -13,6 +14,7 @@ use specs::{saveload::MarkerAllocator, Builder, Entity as EcsEntity, WorldExt};
use tracing::{debug, error, trace, warn};
pub fn handle_exit_ingame(server: &mut Server, entity: EcsEntity) {
span!(_guard, "handle_exit_ingame");
let state = server.state_mut();
// Create new entity with just `Client`, `Uid`, and `Player` components
@ -78,6 +80,7 @@ pub fn handle_exit_ingame(server: &mut Server, entity: EcsEntity) {
}
pub fn handle_client_disconnect(server: &mut Server, entity: EcsEntity) -> Event {
span!(_guard, "handle_client_disconnect");
if let Some(client) = server.state().read_storage::<Client>().get(entity) {
let participant = match client.participant.try_lock() {
Ok(mut p) => p.take().unwrap(),

View File

@ -11,6 +11,7 @@ use common::{
msg::ServerMsg,
outcome::Outcome,
region::{Event as RegionEvent, RegionMap},
span,
state::TimeOfDay,
sync::{CompSyncPackage, Uid},
terrain::TerrainChunkSize,
@ -77,6 +78,7 @@ impl<'a> System<'a> for Sys {
trackers,
): Self::SystemData,
) {
span!(_guard, "run", "entity_sync::Sys::run");
timer.start();
let tick = tick.0;

View File

@ -3,6 +3,7 @@ use crate::client::Client;
use common::{
comp::group::{Invite, PendingInvites},
msg::{InviteAnswer, ServerMsg},
span,
sync::Uid,
};
use specs::{Entities, Join, ReadStorage, System, Write, WriteStorage};
@ -24,6 +25,7 @@ impl<'a> System<'a> for Sys {
&mut self,
(entities, mut invites, mut pending_invites, mut clients, uids, mut timer): Self::SystemData,
) {
span!(_guard, "run", "invite_timeout::Sys::run");
timer.start();
let now = std::time::Instant::now();

View File

@ -13,6 +13,7 @@ use common::{
validate_chat_msg, CharacterInfo, ChatMsgValidationError, ClientMsg, ClientState,
PlayerInfo, PlayerListUpdate, RequestStateError, ServerMsg, MAX_BYTES_CHAT_MSG,
},
span,
state::{BlockChange, Time},
sync::Uid,
terrain::{Block, TerrainChunkSize, TerrainGrid},
@ -454,6 +455,7 @@ impl<'a> System<'a> for Sys {
alias_validator,
): Self::SystemData,
) {
span!(_guard, "run", "message::Sys::run");
timer.start();
let mut server_emitter = server_event_bus.emitter();

View File

@ -1,6 +1,7 @@
use common::{
comp::{HealthSource, Object, PhysicsState, Pos, Vel},
event::{EventBus, ServerEvent},
span,
state::DeltaTime,
};
use specs::{Entities, Join, Read, ReadStorage, System, WriteStorage};
@ -23,6 +24,7 @@ impl<'a> System<'a> for Sys {
&mut self,
(entities, _dt, server_bus, positions, velocities, physics_states, mut objects): Self::SystemData,
) {
span!(_guard, "run", "object::Sys::run");
let mut server_emitter = server_bus.emitter();
// Objects

View File

@ -2,7 +2,10 @@ use crate::{
persistence::character,
sys::{SysScheduler, SysTimer},
};
use common::comp::{Inventory, Loadout, Player, Stats};
use common::{
comp::{Inventory, Loadout, Player, Stats},
span,
};
use specs::{Join, ReadExpect, ReadStorage, System, Write};
pub struct Sys;
@ -31,6 +34,7 @@ impl<'a> System<'a> for Sys {
mut timer,
): Self::SystemData,
) {
span!(_guard, "run", "persistence::Sys::run");
if scheduler.should_run() {
timer.start();
updater.batch_update(

View File

@ -5,6 +5,7 @@ use common::{
Loadout, Mass, MountState, Mounting, Ori, Player, Pos, Scale, Stats, Sticky, Vel,
},
msg::EcsCompPacket,
span,
sync::{CompSyncPackage, EntityPackage, EntitySyncPackage, Uid, UpdateTracker, WorldSyncExt},
};
use hashbrown::HashMap;
@ -26,6 +27,7 @@ impl<'a> System<'a> for Sys {
);
fn run(&mut self, (mut timer, comps, mut trackers): Self::SystemData) {
span!(_guard, "run", "sentinel::Sys::run");
timer.start();
record_changes(&comps, &mut trackers);

View File

@ -7,6 +7,7 @@ use common::{
comp::{Ori, Player, Pos, Vel},
msg::ServerMsg,
region::{region_in_vd, regions_in_vd, Event as RegionEvent, RegionMap},
span,
sync::Uid,
terrain::TerrainChunkSize,
vol::RectVolSize,
@ -55,6 +56,7 @@ impl<'a> System<'a> for Sys {
tracked_comps,
): Self::SystemData,
) {
span!(_guard, "run", "subscription::Sys::run");
timer.start();
// To update subscriptions

View File

@ -11,6 +11,7 @@ use common::{
generation::get_npc_name,
msg::ServerMsg,
npc::NPC_NAMES,
span,
state::TerrainChanges,
terrain::TerrainGrid,
LoadoutBuilder,
@ -55,6 +56,7 @@ impl<'a> System<'a> for Sys {
mut clients,
): Self::SystemData,
) {
span!(_guard, "run", "terrain::Sys::run");
timer.start();
let mut server_emitter = server_event_bus.emitter();

View File

@ -3,6 +3,7 @@ use crate::client::Client;
use common::{
comp::{Player, Pos},
msg::ServerMsg,
span,
state::TerrainChanges,
terrain::TerrainGrid,
};
@ -26,6 +27,7 @@ impl<'a> System<'a> for Sys {
&mut self,
(terrain, terrain_changes, mut timer, positions, players, mut clients): Self::SystemData,
) {
span!(_guard, "run", "terrain_sync::Sys::run");
timer.start();
// Sync changed chunks

View File

@ -3,6 +3,7 @@ use crate::client::Client;
use common::{
comp::{Player, Pos, Waypoint, WaypointArea},
msg::{Notification, ServerMsg},
span,
state::Time,
};
use specs::{Entities, Join, Read, ReadStorage, System, Write, WriteStorage};
@ -30,6 +31,7 @@ impl<'a> System<'a> for Sys {
&mut self,
(entities, positions, players, waypoint_areas, mut waypoints, mut clients, time, mut timer): Self::SystemData,
) {
span!(_guard, "run", "waypoint::Sys::run");
timer.start();
for (entity, player_pos, _, client) in

View File

@ -12,6 +12,7 @@ version = "0.7.0"
gl = ["gfx_device_gl", "gfx_gl"]
hot-anim = ["anim/use-dyn-lib"]
singleplayer = ["server"]
tracy = ["tracing-tracy", "common/tracy"]
tweak = ["const-tweaker"]
default = ["gl", "singleplayer", "native-dialog"]
@ -81,6 +82,9 @@ tracing-appender = "0.1"
tracing-log = "0.1.1"
tracing-subscriber = {version = "0.2.3", default-features = false, features = ["env-filter", "fmt", "chrono", "ansi", "smallvec", "tracing-log"]}
# Tracy
tracing-tracy = { version = "0.2.0", optional = true }
[target.'cfg(target_os = "macos")'.dependencies]
dispatch = "0.1.4"

View File

@ -56,7 +56,7 @@ use crate::{
GlobalState,
};
use client::Client;
use common::{assets::Asset, comp, sync::Uid, terrain::TerrainChunk, vol::RectRasterableVol};
use common::{assets::Asset, comp, span, sync::Uid, terrain::TerrainChunk, vol::RectRasterableVol};
use conrod_core::{
text::cursor::Index,
widget::{self, Button, Image, Text},
@ -685,6 +685,7 @@ impl Hud {
info: HudInfo,
camera: &Camera,
) -> Vec<Event> {
span!(_guard, "update_layout", "Hud::update_layout");
let mut events = std::mem::replace(&mut self.events, Vec::new());
let (ref mut ui_widgets, ref mut tooltip_manager) = self.ui.set_widgets();
// pulse time for pulsating elements
@ -2521,6 +2522,7 @@ impl Hud {
dt: Duration,
info: HudInfo,
) -> Vec<Event> {
span!(_guard, "maintain", "Hud::maintain");
// conrod eats tabs. Un-eat a tabstop so tab completion can work
if self.ui.ui.global_input().events().any(|event| {
use conrod_core::{event, input};
@ -2565,6 +2567,7 @@ impl Hud {
}
pub fn render(&self, renderer: &mut Renderer, globals: &Consts<Globals>) {
span!(_guard, "render", "Hud::render");
// Don't show anything if the UI is toggled off.
if self.show.ui {
self.ui.render(renderer, Some(globals));

View File

@ -47,6 +47,7 @@ pub fn init(settings: &Settings) -> Vec<impl Drop> {
.add_directive(LevelFilter::INFO.into())
};
#[cfg(not(feature = "tracy"))]
let filter = match std::env::var_os(RUST_LOG_ENV).map(|s| s.into_string()) {
Some(Ok(env)) => {
let mut filter = base_exceptions(EnvFilter::new(""));
@ -61,6 +62,9 @@ pub fn init(settings: &Settings) -> Vec<impl Drop> {
_ => base_exceptions(EnvFilter::from_env(RUST_LOG_ENV)),
};
#[cfg(feature = "tracy")]
let filter = base_exceptions(EnvFilter::new("")).add_directive(LevelFilter::TRACE.into());
// Create the terminal writer layer.
let (non_blocking, _stdio_guard) = tracing_appender::non_blocking(std::io::stdout());
_guards.push(_stdio_guard);
@ -77,11 +81,19 @@ pub fn init(settings: &Settings) -> Vec<impl Drop> {
tracing_appender::rolling::daily(&settings.log.logs_path, LOG_FILENAME);
let (non_blocking_file, _file_guard) = tracing_appender::non_blocking(file_appender);
_guards.push(_file_guard);
#[cfg(not(feature = "tracy"))]
registry()
.with(tracing_subscriber::fmt::layer().with_writer(non_blocking))
.with(tracing_subscriber::fmt::layer().with_writer(non_blocking_file))
.with(filter)
.init();
#[cfg(feature = "tracy")]
registry()
// NOTE: collecting stacks has a significant overhead (x6 overhead of
// starting/stopping a span through the layer interface)
.with(tracing_tracy::TracyLayer::new().with_stackdepth(0))
.with(filter)
.init();
let logdir = &settings.log.logs_path;
info!(?logdir, "Setup terminal and file logging.");
},
@ -91,8 +103,13 @@ pub fn init(settings: &Settings) -> Vec<impl Drop> {
?e,
"Failed to create log file!. Falling back to terminal logging only.",
);
#[cfg(not(feature = "tracy"))]
registry()
.with(tracing_subscriber::fmt::layer().with_writer(non_blocking))
.with(filter);
#[cfg(feature = "tracy")]
registry()
.with(tracing_tracy::TracyLayer::new().with_stackdepth(0))
.with(filter)
.init();
info!("Setup terminal logging.");

View File

@ -10,7 +10,7 @@ use crate::{
Direction, GlobalState, PlayState, PlayStateResult,
};
use client::{self, Client};
use common::{assets::Asset, comp, msg::ClientState, state::DeltaTime};
use common::{assets::Asset, comp, msg::ClientState, span, state::DeltaTime};
use specs::WorldExt;
use std::{cell::RefCell, rc::Rc};
use tracing::error;
@ -60,6 +60,7 @@ impl PlayState for CharSelectionState {
}
fn tick(&mut self, global_state: &mut GlobalState, events: Vec<WinEvent>) -> PlayStateResult {
span!(_guard, "tick", "<CharSelectionState as PlayState>::tick");
let client_state = self.client.borrow().get_client_state();
if let ClientState::Pending | ClientState::Registered = client_state {
// Handle window events

View File

@ -9,7 +9,7 @@ use crate::{
PlayStateResult,
};
use client_init::{ClientInit, Error as InitError, Msg as InitMsg};
use common::{assets::Asset, comp};
use common::{assets::Asset, comp, span};
use tracing::{error, warn};
use ui::{Event as MainMenuEvent, MainMenuUi};
@ -46,6 +46,7 @@ impl PlayState for MainMenuState {
}
fn tick(&mut self, global_state: &mut GlobalState, events: Vec<Event>) -> PlayStateResult {
span!(_guard, "tick", "<MainMenuState as PlayState>::tick");
let localized_strings = crate::i18n::VoxygenLocalization::load_expect(
&crate::i18n::i18n_asset_key(&global_state.settings.language.selected_language),
);

View File

@ -1,4 +1,5 @@
use crate::render::{self, mesh::Quad, ColLightFmt, ColLightInfo, TerrainPipeline};
use common::span;
use vek::*;
type TerrainVertex = <TerrainPipeline as render::Pipeline>::Vertex;
@ -101,6 +102,7 @@ impl<'a> GreedyMesh<'a> {
/// most 30 bits total, meaning we are restricted to "only" at most 2^15
/// × 2^15 atlases even if the hardware supports larger ones.
pub fn new(max_size: guillotiere::Size) -> Self {
span!(_guard, "new", "GreedyMesh::new");
let min_max_dim = max_size.width.min(max_size.height);
assert!(
min_max_dim >= 4,
@ -148,6 +150,7 @@ impl<'a> GreedyMesh<'a> {
FS: for<'r> FnMut(&'r mut D, Vec3<i32>, Vec3<i32>, Vec2<Vec3<i32>>) -> Option<(bool, M)>,
FP: FnMut(Vec2<u16>, Vec2<Vec2<u16>>, Vec3<f32>, Vec2<Vec3<f32>>, Vec3<f32>, &M),
{
span!(_guard, "push", "GreedyMesh::push");
let cont = greedy_mesh(
&mut self.atlas,
&mut self.col_lights_size,
@ -167,6 +170,7 @@ impl<'a> GreedyMesh<'a> {
///
/// Returns the ColLightsInfo corresponding to the constructed atlas.
pub fn finalize(self) -> ColLightInfo {
span!(_guard, "finalize", "GreedyMesh::finalize");
let cur_size = self.col_lights_size;
let col_lights = vec![
TerrainVertex::make_col_light(254, Rgb::broadcast(254));
@ -205,6 +209,7 @@ where
FS: for<'r> FnMut(&'r mut D, Vec3<i32>, Vec3<i32>, Vec2<Vec3<i32>>) -> Option<(bool, M)>,
FP: FnMut(Vec2<u16>, Vec2<Vec2<u16>>, Vec3<f32>, Vec2<Vec3<f32>>, Vec3<f32>, &M),
{
span!(_guard, "greedy_mesh");
// TODO: Collect information to see if we can choose a good value here.
let mut todo_rects = Vec::with_capacity(1024);
@ -367,6 +372,7 @@ fn greedy_mesh_cross_section<M: PartialEq>(
// Vertex, width and height, and meta information about the block.
mut push_quads: impl FnMut(Vec3<usize>, Vec2<usize>, &M),
) {
span!(_guard, "greedy_mesh_cross_section");
// mask represents which faces are either set while the other is unset, or unset
// while the other is set.
let mut mask = (0..dims.y * dims.x).map(|_| None).collect::<Vec<_>>();

View File

@ -6,6 +6,7 @@ use crate::{
render::{self, ColLightInfo, FluidPipeline, Mesh, ShadowPipeline, TerrainPipeline},
};
use common::{
span,
terrain::{Block, BlockKind},
vol::{ReadVol, RectRasterableVol, Vox},
volumes::vol_grid_2d::{CachedVolGrid2d, VolGrid2d},
@ -47,6 +48,7 @@ fn calc_light<V: RectRasterableVol<Vox = Block> + ReadVol + Debug>(
vol: &VolGrid2d<V>,
lit_blocks: impl Iterator<Item = (Vec3<i32>, u8)>,
) -> impl FnMut(Vec3<i32>) -> f32 + '_ {
span!(_guard, "calc_light");
const UNKNOWN: u8 = 255;
const OPAQUE: u8 = 254;
@ -240,6 +242,11 @@ impl<'a, V: RectRasterableVol<Vox = Block> + ReadVol + Debug>
self,
(range, max_texture_size): Self::Supplement,
) -> MeshGen<TerrainPipeline, FluidPipeline, Self> {
span!(
_guard,
"generate_mesh",
"<&VolGrid2d as Meshable<_, _>>::generate_mesh"
);
// Find blocks that should glow
// FIXME: Replace with real lit blocks when we actually have blocks that glow.
let lit_blocks = core::iter::empty();
@ -256,6 +263,7 @@ impl<'a, V: RectRasterableVol<Vox = Block> + ReadVol + Debug>
let mut lowest_air = range.size().d;
let mut highest_air = 0;
let flat_get = {
span!(_guard, "copy to flat array");
let (w, h, d) = range.size().into_tuple();
// z can range from -1..range.size().d + 1
let d = d + 2;

View File

@ -12,7 +12,10 @@ use super::{
AaMode, CloudMode, FilterMethod, FluidMode, LightingMode, Pipeline, RenderError, RenderMode,
ShadowMapMode, ShadowMode, WrapMode,
};
use common::assets::{self, watch::ReloadIndicator, Asset};
use common::{
assets::{self, watch::ReloadIndicator, Asset},
span,
};
use core::convert::TryFrom;
use gfx::{
self,
@ -603,6 +606,7 @@ impl Renderer {
/// Queue the clearing of the shadow targets ready for a new frame to be
/// rendered.
pub fn clear_shadows(&mut self) {
span!(_guard, "clear_shadows", "Renderer::clear_shadows");
if !self.mode.shadow.is_map() {
return;
}
@ -675,6 +679,7 @@ impl Renderer {
/// Queue the clearing of the depth target ready for a new frame to be
/// rendered.
pub fn clear(&mut self) {
span!(_guard, "clear", "Renderer::clear");
self.encoder.clear_depth(&self.tgt_depth_stencil_view, 1.0);
// self.encoder.clear_stencil(&self.tgt_depth_stencil_view, 0);
self.encoder.clear_depth(&self.win_depth_view, 1.0);
@ -710,6 +715,7 @@ impl Renderer {
/// Perform all queued draw calls for this frame and clean up discarded
/// items.
pub fn flush(&mut self) {
span!(_guard, "flush", "Renderer::flush");
self.encoder.flush(&mut self.device);
self.device.cleanup();

View File

@ -4,6 +4,7 @@ use crate::{
window::{Event, EventLoop},
Direction, GlobalState, PlayState, PlayStateResult,
};
use common::{no_guard_span, span, util::GuardlessSpan};
use std::{mem, time::Duration};
use tracing::debug;
@ -22,6 +23,9 @@ pub fn run(mut global_state: GlobalState, event_loop: EventLoop) {
// See: https://github.com/rust-windowing/winit/issues/1418
let mut polled_twice = false;
let mut poll_span = None;
let mut event_span = None;
event_loop.run(move |event, _, control_flow| {
// Continuously run loop since we handle sleeping
*control_flow = winit::event_loop::ControlFlow::Poll;
@ -32,16 +36,26 @@ pub fn run(mut global_state: GlobalState, event_loop: EventLoop) {
}
match event {
winit::event::Event::NewEvents(_) => {
event_span = Some(no_guard_span!("Process Events"));
},
winit::event::Event::MainEventsCleared => {
event_span.take();
poll_span.take();
if polled_twice {
handle_main_events_cleared(&mut states, control_flow, &mut global_state);
}
poll_span = Some(no_guard_span!("Poll Winit"));
polled_twice = !polled_twice;
},
winit::event::Event::WindowEvent { event, .. } => global_state
winit::event::Event::WindowEvent { event, .. } => {
span!(_guard, "Handle WindowEvent");
global_state
.window
.handle_window_event(event, &mut global_state.settings),
.handle_window_event(event, &mut global_state.settings)
},
winit::event::Event::DeviceEvent { event, .. } => {
span!(_guard, "Handle DeviceEvent");
global_state.window.handle_device_event(event)
},
winit::event::Event::LoopDestroyed => {
@ -59,6 +73,7 @@ fn handle_main_events_cleared(
control_flow: &mut winit::event_loop::ControlFlow,
global_state: &mut GlobalState,
) {
span!(guard, "Handle MainEventsCleared");
// Screenshot / Fullscreen toggle
global_state
.window
@ -82,14 +97,6 @@ fn handle_main_events_cleared(
// Implement state transfer logic.
match state_result {
PlayStateResult::Continue => {
// Wait for the next tick.
global_state.clock.tick(Duration::from_millis(
1000 / global_state.settings.graphics.max_fps as u64,
));
// Maintain global state.
global_state.maintain(global_state.clock.get_last_delta().as_secs_f32());
exit = false;
break;
},
@ -136,7 +143,9 @@ fn handle_main_events_cleared(
*control_flow = winit::event_loop::ControlFlow::Exit;
}
drop(guard);
if let Some(last) = states.last_mut() {
span!(guard, "Render");
let renderer = global_state.window.renderer_mut();
// Clear the shadow maps.
renderer.clear_shadows();
@ -151,5 +160,20 @@ fn handle_main_events_cleared(
.window
.swap_buffers()
.expect("Failed to swap window buffers!");
drop(guard);
#[cfg(feature = "tracy")]
common::util::tracy_client::finish_continuous_frame!();
}
if !exit {
// Wait for the next tick.
span!(_guard, "Main thread sleep");
global_state.clock.tick(Duration::from_millis(
1000 / global_state.settings.graphics.max_fps as u64,
));
span!(_guard, "Maintain global state");
// Maintain global state.
global_state.maintain(global_state.clock.get_last_delta().as_secs_f32());
}
}

View File

@ -1,4 +1,7 @@
use common::vol::{ReadVol, Vox};
use common::{
span,
vol::{ReadVol, Vox},
};
use std::f32::consts::PI;
use treeculler::Frustum;
use vek::*;
@ -78,6 +81,7 @@ impl Camera {
/// Compute the transformation matrices (view matrix and projection matrix)
/// and position of the camera.
pub fn compute_dependents(&mut self, terrain: &impl ReadVol) {
span!(_guard, "compute_dependents", "Camera::compute_dependents");
let dist = {
let (start, end) = (self.focus - self.forward() * self.dist, self.focus);

View File

@ -28,6 +28,7 @@ use common::{
item::ItemKind, Body, CharacterState, Item, Last, LightAnimation, LightEmitter, Loadout,
Ori, PhysicsState, Pos, Scale, Stats, Vel,
},
span,
state::{DeltaTime, State},
states::triple_strike,
terrain::TerrainChunk,
@ -195,6 +196,7 @@ impl FigureMgrStates {
}
fn retain(&mut self, mut f: impl FnMut(&EcsEntity, &mut FigureStateMeta) -> bool) {
span!(_guard, "retain", "FigureManagerStates::retain");
self.character_states.retain(|k, v| f(k, &mut *v));
self.quadruped_small_states.retain(|k, v| f(k, &mut *v));
self.quadruped_medium_states.retain(|k, v| f(k, &mut *v));
@ -337,6 +339,7 @@ impl FigureMgr {
pub fn col_lights(&self) -> &FigureColLights { &self.col_lights }
pub fn clean(&mut self, tick: u64) {
span!(_guard, "clean", "FigureManager::clean");
self.model_cache.clean(&mut self.col_lights, tick);
self.critter_model_cache.clean(&mut self.col_lights, tick);
self.quadruped_small_model_cache
@ -363,6 +366,7 @@ impl FigureMgr {
#[allow(clippy::redundant_pattern_matching)]
// TODO: Pending review in #587
pub fn update_lighting(&mut self, scene_data: &SceneData) {
span!(_guard, "update_lighting", "FigureManager::update_lighting");
let ecs = scene_data.state.ecs();
for (entity, body, light_emitter) in (
&ecs.entities(),
@ -451,6 +455,7 @@ impl FigureMgr {
visible_psr_bounds: math::Aabr<f32>,
camera: &Camera,
) -> anim::vek::Aabb<f32> {
span!(_guard, "maintain", "FigureManager::maintain");
let state = scene_data.state;
let time = state.get_time();
let tick = scene_data.tick;
@ -2130,6 +2135,7 @@ impl FigureMgr {
(is_daylight, _light_data): super::LightData,
(camera, figure_lod_render_distance): CameraData,
) {
span!(_guard, "render_shadows", "FigureManager::render_shadows");
let ecs = state.ecs();
if is_daylight && renderer.render_mode().shadow.is_map() {
@ -2181,6 +2187,7 @@ impl FigureMgr {
lod: &LodData,
(camera, figure_lod_render_distance): CameraData,
) {
span!(_guard, "render", "FigureManager::render");
let ecs = state.ecs();
let character_state_storage = state.read_storage::<common::comp::CharacterState>();
@ -2231,6 +2238,7 @@ impl FigureMgr {
lod: &LodData,
(camera, figure_lod_render_distance): CameraData,
) {
span!(_guard, "render_player", "FigureManager::render_player");
let ecs = state.ecs();
let character_state_storage = state.read_storage::<common::comp::CharacterState>();
@ -2614,6 +2622,7 @@ impl FigureColLights {
(opaque, bounds): (Mesh<TerrainPipeline>, math::Aabb<f32>),
vertex_range: [Range<u32>; N],
) -> Result<FigureModelEntry<N>, RenderError> {
span!(_guard, "create_figure", "FigureColLights::create_figure");
let atlas = &mut self.atlas;
let allocation = atlas
.allocate(guillotiere::Size::new(

View File

@ -28,6 +28,7 @@ use client::Client;
use common::{
comp,
outcome::Outcome,
span,
state::{DeltaTime, State},
terrain::{BlockKind, TerrainChunk},
vol::ReadVol,
@ -379,6 +380,7 @@ impl Scene {
scene_data: &SceneData,
audio: &mut AudioFrontend,
) {
span!(_guard, "handle_outcome", "Scene::handle_outcome");
self.particle_mgr.handle_outcome(&outcome, &scene_data);
self.sfx_mgr.handle_outcome(&outcome, audio);
@ -422,6 +424,7 @@ impl Scene {
audio: &mut AudioFrontend,
scene_data: &SceneData,
) {
span!(_guard, "maintain", "Scene::maintain");
// Get player position.
let ecs = scene_data.state.ecs();
@ -973,6 +976,7 @@ impl Scene {
tick: u64,
scene_data: &SceneData,
) {
span!(_guard, "render", "Scene::render");
let sun_dir = scene_data.get_sun_dir();
let is_daylight = sun_dir.z < 0.0;
let focus_pos = self.camera.get_focus_pos();

View File

@ -11,6 +11,7 @@ use common::{
comp::{item::Reagent, object, Body, CharacterState, Pos},
figure::Segment,
outcome::Outcome,
span,
spiral::Spiral2d,
state::DeltaTime,
terrain::TerrainChunk,
@ -48,6 +49,7 @@ impl ParticleMgr {
}
pub fn handle_outcome(&mut self, outcome: &Outcome, scene_data: &SceneData) {
span!(_guard, "handle_outcome", "ParticleMgr::handle_outcome");
let time = scene_data.state.get_time();
let mut rng = rand::thread_rng();
@ -98,6 +100,7 @@ impl ParticleMgr {
scene_data: &SceneData,
terrain: &Terrain<TerrainChunk>,
) {
span!(_guard, "maintain", "ParticleMgr::maintain");
if scene_data.particles_enabled {
// update timings
self.scheduler.maintain(scene_data.state.get_time());
@ -122,6 +125,11 @@ impl ParticleMgr {
}
fn maintain_body_particles(&mut self, scene_data: &SceneData) {
span!(
_guard,
"body_particles",
"ParticleMgr::maintain_body_particles"
);
let ecs = scene_data.state.ecs();
for (body, pos) in (&ecs.read_storage::<Body>(), &ecs.read_storage::<Pos>()).join() {
match body {
@ -148,6 +156,11 @@ impl ParticleMgr {
}
fn maintain_campfirelit_particles(&mut self, scene_data: &SceneData, pos: &Pos) {
span!(
_guard,
"campfirelit_particles",
"ParticleMgr::maintain_campfirelit_particles"
);
let time = scene_data.state.get_time();
for _ in 0..self.scheduler.heartbeats(Duration::from_millis(10)) {
@ -168,6 +181,11 @@ impl ParticleMgr {
}
fn maintain_boltfire_particles(&mut self, scene_data: &SceneData, pos: &Pos) {
span!(
_guard,
"boltfire_particles",
"ParticleMgr::maintain_boltfire_particles"
);
let time = scene_data.state.get_time();
for _ in 0..self.scheduler.heartbeats(Duration::from_millis(10)) {
@ -187,6 +205,11 @@ impl ParticleMgr {
}
fn maintain_boltfirebig_particles(&mut self, scene_data: &SceneData, pos: &Pos) {
span!(
_guard,
"boltfirebig_particles",
"ParticleMgr::maintain_boltfirebig_particles"
);
let time = scene_data.state.get_time();
// fire
@ -217,6 +240,11 @@ impl ParticleMgr {
}
fn maintain_bomb_particles(&mut self, scene_data: &SceneData, pos: &Pos) {
span!(
_guard,
"bomb_particles",
"ParticleMgr::maintain_bomb_particles"
);
let time = scene_data.state.get_time();
for _ in 0..self.scheduler.heartbeats(Duration::from_millis(10)) {
@ -239,6 +267,11 @@ impl ParticleMgr {
}
fn maintain_boost_particles(&mut self, scene_data: &SceneData) {
span!(
_guard,
"boost_particles",
"ParticleMgr::maintain_boost_particles"
);
let state = scene_data.state;
let ecs = state.ecs();
let time = state.get_time();
@ -272,6 +305,11 @@ impl ParticleMgr {
scene_data: &SceneData,
terrain: &Terrain<TerrainChunk>,
) {
span!(
_guard,
"block_particles",
"ParticleMgr::maintain_block_particles"
);
let dt = scene_data.state.ecs().fetch::<DeltaTime>().0;
let time = scene_data.state.get_time();
let player_pos = scene_data
@ -383,6 +421,7 @@ impl ParticleMgr {
}
fn upload_particles(&mut self, renderer: &mut Renderer) {
span!(_guard, "upload_particles", "ParticleMgr::upload_particles");
let all_cpu_instances = self
.particles
.iter()
@ -404,6 +443,7 @@ impl ParticleMgr {
global: &GlobalModel,
lod: &LodData,
) {
span!(_guard, "render", "ParticleMgr::render");
if scene_data.particles_enabled {
let model = &self
.model_cache
@ -489,6 +529,7 @@ impl HeartbeatScheduler {
/// updates the last elapsed times and elapsed counts
/// this should be called once, and only once per tick.
pub fn maintain(&mut self, now: f64) {
span!(_guard, "maintain", "HeartbeatScheduler::maintain");
self.last_known_time = now;
for (frequency, (last_update, heartbeats)) in self.timers.iter_mut() {
@ -520,6 +561,7 @@ impl HeartbeatScheduler {
/// - if it's equal to the tick rate, it could be between 2 and 0, due to
/// delta time variance.
pub fn heartbeats(&mut self, frequency: Duration) -> u8 {
span!(_guard, "HeartbeatScheduler::heartbeats");
let last_known_time = self.last_known_time;
self.timers

View File

@ -15,6 +15,7 @@ use super::{math, LodData, SceneData};
use common::{
assets::{Asset, Ron},
figure::Segment,
span,
spiral::Spiral2d,
terrain::{block, Block, BlockKind, TerrainChunk},
vol::{BaseVol, ReadVol, RectRasterableVol, SampleVol, Vox},
@ -124,6 +125,7 @@ fn mesh_worker<V: BaseVol<Vox = Block> + RectRasterableVol + ReadVol + Debug>(
sprite_data: &HashMap<(BlockKind, usize), Vec<SpriteData>>,
sprite_config: &SpriteSpec,
) -> MeshWorkerResponse {
span!(_guard, "mesh_worker");
let (opaque_mesh, fluid_mesh, _shadow_mesh, (bounds, col_lights_info)) =
volume.generate_mesh((range, Vec2::new(max_texture_size, max_texture_size)));
MeshWorkerResponse {
@ -134,6 +136,7 @@ fn mesh_worker<V: BaseVol<Vox = Block> + RectRasterableVol + ReadVol + Debug>(
col_lights_info,
// Extract sprite locations from volume
sprite_instances: {
span!(_guard, "extract sprite_instances");
let mut instances = HashMap::new();
for x in 0..V::RECT_SIZE.x as i32 {
@ -382,6 +385,7 @@ impl<V: RectRasterableVol> Terrain<V> {
fn make_atlas(
renderer: &mut Renderer,
) -> Result<(AtlasAllocator, Texture<ColLightFmt>), RenderError> {
span!(_guard, "male_atlas", "Terrain::make_atlas");
let max_texture_size = renderer.max_texture_size();
let atlas_size =
guillotiere::Size::new(i32::from(max_texture_size), i32::from(max_texture_size));
@ -449,12 +453,14 @@ impl<V: RectRasterableVol> Terrain<V> {
view_mat: Mat4<f32>,
proj_mat: Mat4<f32>,
) -> (Aabb<f32>, Vec<math::Vec3<f32>>, math::Aabr<f32>) {
span!(_guard, "maintain", "Terrain::maintain");
let current_tick = scene_data.tick;
let current_time = scene_data.state.get_time();
let mut visible_bounding_box: Option<Aabb<f32>> = None;
// Add any recently created or changed chunks to the list of chunks to be
// meshed.
span!(guard, "Add new/modified chunks to mesh todo list");
for (modified, pos) in scene_data
.state
.terrain_changes()
@ -501,9 +507,12 @@ impl<V: RectRasterableVol> Terrain<V> {
}
}
}
drop(guard);
// Add the chunks belonging to recently changed blocks to the list of chunks to
// be meshed
span!(guard, "Add chunks with modified blocks to mesh todo list");
// TODO: would be useful if modified blocks were grouped by chunk
for pos in scene_data
.state
.terrain_changes()
@ -542,6 +551,7 @@ impl<V: RectRasterableVol> Terrain<V> {
}
}
}
drop(guard);
// Remove any models for chunks that have been recently removed.
for &pos in &scene_data.state.terrain_changes().removed_chunks {
@ -551,6 +561,7 @@ impl<V: RectRasterableVol> Terrain<V> {
// Limit ourselves to u16::MAX even if larger textures are supported.
let max_texture_size = renderer.max_texture_size();
span!(guard, "Queue meshing from todo list");
for (todo, chunk) in self
.mesh_todo
.values_mut()
@ -637,11 +648,13 @@ impl<V: RectRasterableVol> Terrain<V> {
});
todo.active_worker = Some(todo.started_tick);
}
drop(guard);
// Receive a chunk mesh from a worker thread and upload it to the GPU, then
// store it. Only pull out one chunk per frame to avoid an unacceptable
// amount of blocking lag due to the GPU upload. That still gives us a
// 60 chunks / second budget to play with.
span!(guard, "Get/upload meshed chunk");
if let Ok(response) = self.mesh_recv.recv_timeout(Duration::new(0, 0)) {
match self.mesh_todo.get(&response.pos) {
// It's the mesh we want, insert the newly finished model into the terrain model
@ -739,14 +752,18 @@ impl<V: RectRasterableVol> Terrain<V> {
None => {},
}
}
drop(guard);
// Construct view frustum
span!(guard, "Construct view frustum");
let focus_off = focus_pos.map(|e| e.trunc());
let frustum = Frustum::from_modelview_projection(
(proj_mat * view_mat * Mat4::translation_3d(-focus_off)).into_col_arrays(),
);
drop(guard);
// Update chunk visibility
span!(guard, "Update chunk visibility");
let chunk_sz = V::RECT_SIZE.x as f32;
for (pos, chunk) in &mut self.chunks {
let chunk_pos = pos.as_::<f32>() * chunk_sz;
@ -796,7 +813,9 @@ impl<V: RectRasterableVol> Terrain<V> {
// (and hardcodes the shadow distance). Should ideally exist per-light, too.
chunk.can_shadow_point = distance_2 < (128.0 * 128.0);
}
drop(guard);
span!(guard, "Shadow magic");
// PSRs: potential shadow receivers
let visible_bounding_box = visible_bounding_box.unwrap_or(Aabb {
min: focus_pos - 2.0,
@ -901,6 +920,7 @@ impl<V: RectRasterableVol> Terrain<V> {
max: math::Vec2::zero(),
})
};
drop(guard);
(
visible_bounding_box,
@ -931,6 +951,7 @@ impl<V: RectRasterableVol> Terrain<V> {
(is_daylight, light_data): super::LightData,
focus_pos: Vec3<f32>,
) {
span!(_guard, "render_shadows", "Terrain::render_shadows");
if !renderer.render_mode().shadow.is_map() {
return;
};
@ -992,6 +1013,7 @@ impl<V: RectRasterableVol> Terrain<V> {
lod: &LodData,
focus_pos: Vec3<f32>,
) {
span!(_guard, "render", "Terrain::render");
let focus_chunk = Vec2::from(focus_pos).map2(TerrainChunk::RECT_SIZE, |e: f32, sz| {
(e as i32).div_euclid(sz as i32)
});
@ -1025,6 +1047,7 @@ impl<V: RectRasterableVol> Terrain<V> {
cam_pos: Vec3<f32>,
sprite_render_distance: f32,
) {
span!(_guard, "render_translucent", "Terrain::render_translucent");
let focus_chunk = Vec2::from(focus_pos).map2(TerrainChunk::RECT_SIZE, |e: f32, sz| {
(e as i32).div_euclid(sz as i32)
});
@ -1038,6 +1061,8 @@ impl<V: RectRasterableVol> Terrain<V> {
.take(self.chunks.len());
// Terrain sprites
// TODO: move to separate functions
span!(guard, "Terrain sprites");
let chunk_size = V::RECT_SIZE.map(|e| e as f32);
let chunk_mag = (chunk_size * (f32::consts::SQRT_2 * 0.5)).magnitude_squared();
for (pos, chunk) in chunk_iter.clone() {
@ -1096,6 +1121,7 @@ impl<V: RectRasterableVol> Terrain<V> {
}
}
}
drop(guard);
// Translucent
chunk_iter

View File

@ -1,4 +1,5 @@
use common::{
span,
terrain::{BlockKind, TerrainChunk},
vol::{IntoVolIterator, RectRasterableVol},
};
@ -16,6 +17,7 @@ pub struct BlocksOfInterest {
impl BlocksOfInterest {
pub fn from_chunk(chunk: &TerrainChunk) -> Self {
span!(_guard, "from_chunk", "BlocksOfInterest::from_chunk");
let mut leaves = Vec::new();
let mut grass = Vec::new();
let mut embers = Vec::new();

View File

@ -22,6 +22,7 @@ use common::{
event::EventBus,
msg::ClientState,
outcome::Outcome,
span,
terrain::{Block, BlockKind},
util::Dir,
vol::ReadVol,
@ -111,6 +112,7 @@ impl SessionState {
global_state: &mut GlobalState,
outcomes: &mut Vec<Outcome>,
) -> Result<TickAction, Error> {
span!(_guard, "tick", "Session::tick");
self.inputs.tick(dt);
let mut client = self.client.borrow_mut();
@ -195,6 +197,7 @@ impl PlayState for SessionState {
}
fn tick(&mut self, global_state: &mut GlobalState, events: Vec<Event>) -> PlayStateResult {
span!(_guard, "tick", "<Session as PlayState>::tick");
// NOTE: Not strictly necessary, but useful for hotloading translation changes.
self.voxygen_i18n = VoxygenLocalization::load_expect(&i18n_asset_key(
&global_state.settings.language.selected_language,
@ -1084,6 +1087,7 @@ impl PlayState for SessionState {
///
/// This method should be called once per frame.
fn render(&mut self, renderer: &mut Renderer, settings: &Settings) {
span!(_guard, "render", "<Session as PlayState>::render");
// Render the screen using the global renderer
{
let client = self.client.borrow();

View File

@ -32,7 +32,7 @@ use crate::{
#[rustfmt::skip]
use ::image::GenericImageView;
use cache::Cache;
use common::{assets, util::srgba_to_linear};
use common::{assets, span, util::srgba_to_linear};
use conrod_core::{
event::Input,
graph::{self, Graph},
@ -293,6 +293,7 @@ impl Ui {
#[allow(clippy::float_cmp)] // TODO: Pending review in #587
pub fn maintain(&mut self, renderer: &mut Renderer, view_projection_mat: Option<Mat4<f32>>) {
span!(_guard, "maintain", "Ui::maintain");
// Maintain tooltip manager
self.tooltip_manager
.maintain(self.ui.global_input(), self.scale.scale_factor_logical());
@ -334,6 +335,7 @@ impl Ui {
view_projection_mat: Option<Mat4<f32>>,
retry: &mut bool,
) {
span!(_guard, "internal", "Ui::maintain_internal");
let (graphic_cache, text_cache, glyph_cache, cache_tex) = self.cache.cache_mut_and_tex();
let mut primitives = if *retry {
@ -978,6 +980,7 @@ impl Ui {
}
pub fn render(&self, renderer: &mut Renderer, maybe_globals: Option<&Consts<Globals>>) {
span!(_guard, "render", "Ui::render");
let mut scissor = default_scissor(renderer);
let globals = maybe_globals.unwrap_or(&self.default_globals);
let mut locals = &self.interface_locals;

View File

@ -4,6 +4,7 @@ use crate::{
settings::{ControlSettings, Settings},
ui, Error,
};
use common::span;
use crossbeam::channel;
use gilrs::{EventType, Gilrs};
use hashbrown::HashMap;
@ -1043,6 +1044,7 @@ impl Window {
}
pub fn swap_buffers(&self) -> Result<(), Error> {
span!(_guard, "swap_buffers", "Window::swap_buffers");
self.window
.swap_buffers()
.map_err(|err| Error::BackendError(Box::new(err)))