improve(log): adjust verbosity of some logging

fix: settings do not log due to logging being initialized to late
This commit is contained in:
Songtronix 2019-11-23 15:34:03 +01:00
parent 6e64924556
commit 0d919a9dc6
5 changed files with 85 additions and 79 deletions

View File

@ -30,7 +30,7 @@ use common::{
terrain::{block::Block, TerrainChunkSize, TerrainGrid},
vol::{ReadVol, RectVolSize, Vox},
};
use log::{debug, trace};
use log::debug;
use metrics::ServerMetrics;
use rand::Rng;
use specs::{join::Join, world::EntityBuilder as EcsEntityBuilder, Builder, Entity as EcsEntity};
@ -178,8 +178,7 @@ impl Server {
.expect("Failed to initialize server metrics submodule."),
server_settings: settings.clone(),
};
debug!("created veloren server");
trace!("server configuration: {:?}", &settings);
debug!("created veloren server with: {:?}", &settings);
Ok(this)
}
@ -973,7 +972,7 @@ impl Server {
.with(client)
.build();
// Return the state of the current world (all of the components that Sphynx tracks).
log::info!("Starting initial sync with client.");
log::debug!("Starting initial sync with client.");
self.state
.ecs()
.write_storage::<Client>()
@ -985,7 +984,7 @@ impl Server {
server_info: self.server_info.clone(),
// world_map: (WORLD_SIZE/*, self.world.sim().get_map()*/),
});
log::info!("Done initial sync with client.");
log::debug!("Done initial sync with client.");
frontend_events.push(Event::ClientConnected { entity });
}

55
voxygen/src/logging.rs Normal file
View File

@ -0,0 +1,55 @@
use fern::colors::{Color, ColoredLevelConfig};
pub fn init(term_log_level: log::LevelFilter, file_log_level: log::LevelFilter) {
let colors = ColoredLevelConfig::new()
.error(Color::Red)
.warn(Color::Yellow)
.info(Color::Cyan)
.debug(Color::Green)
.trace(Color::BrightBlack);
let base = fern::Dispatch::new()
.level_for("dot_vox::parser", log::LevelFilter::Warn)
.level_for("gfx_device_gl::factory", log::LevelFilter::Warn)
.level_for("veloren_voxygen::discord", log::LevelFilter::Warn)
.level_for("uvth", log::LevelFilter::Warn)
.level_for("tiny_http", log::LevelFilter::Warn);
let time = chrono::offset::Utc::now();
let file_cfg = fern::Dispatch::new()
.level(file_log_level)
.format(|out, message, record| {
out.finish(format_args!(
"{}[{}:{}][{}] {}",
chrono::Local::now().format("[%Y-%m-%d][%H:%M:%S]"),
record.target(),
record
.line()
.map(|x| x.to_string())
.unwrap_or("X".to_string()),
record.level(),
message
))
})
.chain(
fern::log_file(&format!("voxygen-{}.log", time.format("%Y-%m-%d-%H")))
.expect("Failed to create log file!"),
);
let stdout_cfg = fern::Dispatch::new()
.level(term_log_level)
.format(move |out, message, record| {
out.finish(format_args!(
"[{}] {}",
colors.color(record.level()),
message
))
})
.chain(std::io::stdout());
base.chain(file_cfg)
.chain(stdout_cfg)
.apply()
.expect("Failed to setup logging!");
}

View File

@ -19,6 +19,7 @@ pub mod audio;
pub mod error;
pub mod hud;
pub mod key_state;
mod logging;
pub mod menu;
pub mod mesh;
pub mod render;
@ -33,9 +34,7 @@ pub mod window;
pub use crate::error::Error;
use crate::{audio::AudioFrontend, menu::main::MainMenuState, settings::Settings, window::Window};
use log::{self, debug, error, info};
use fern::colors::{Color, ColoredLevelConfig};
use log::{self, debug, error};
use std::{mem, panic, str::FromStr};
/// A type used to store state that is shared between all play states.
@ -97,6 +96,16 @@ lazy_static! {
}
fn main() {
// Initialize logging.
let term_log_level = std::env::var_os("VOXYGEN_LOG")
.and_then(|env| env.to_str().map(|s| s.to_owned()))
.and_then(|s| log::LevelFilter::from_str(&s).ok())
.unwrap_or(log::LevelFilter::Warn);
// TODO: Use another environment variable for this?
let file_log_level = log::LevelFilter::Debug;
logging::init(term_log_level, file_log_level);
// Load the settings
let settings = Settings::load();
// Save settings to add new fields or create the file if it is not already there
@ -126,63 +135,6 @@ fn main() {
let settings = &global_state.settings;
// Initialize logging.
let term_log_level = std::env::var_os("VOXYGEN_LOG")
.and_then(|env| env.to_str().map(|s| s.to_owned()))
.and_then(|s| log::LevelFilter::from_str(&s).ok())
.unwrap_or(log::LevelFilter::Warn);
let colors = ColoredLevelConfig::new()
.error(Color::Red)
.warn(Color::Yellow)
.info(Color::Cyan)
.debug(Color::Green)
.trace(Color::BrightBlack);
let base = fern::Dispatch::new()
.level_for("dot_vox::parser", log::LevelFilter::Warn)
.level_for("gfx_device_gl::factory", log::LevelFilter::Warn)
.level_for("veloren_voxygen::discord", log::LevelFilter::Warn);
// TODO: Filter tracing better such that our own tracing gets seen more easily
let time = chrono::offset::Utc::now();
let file_cfg = fern::Dispatch::new()
.level(log::LevelFilter::Trace)
.format(|out, message, record| {
out.finish(format_args!(
"{}[{}:{}][{}] {}",
chrono::Local::now().format("[%Y-%m-%d][%H:%M:%S]"),
record.target(),
record
.line()
.map(|x| x.to_string())
.unwrap_or("X".to_string()),
record.level(),
message
))
})
.chain(
fern::log_file(&format!("voxygen-{}.log", time.format("%Y-%m-%d-%H")))
.expect("Failed to create log file!"),
);
let stdout_cfg = fern::Dispatch::new()
.level(term_log_level)
.format(move |out, message, record| {
out.finish(format_args!(
"[{}] {}",
colors.color(record.level()),
message
))
})
.chain(std::io::stdout());
base.chain(file_cfg)
.chain(stdout_cfg)
.apply()
.expect("Failed to setup logging!");
// Set up panic handler to relay swish panic messages to the user
let settings_clone = settings.clone();
let default_hook = panic::take_hook();
@ -261,7 +213,7 @@ fn main() {
let mut states: Vec<Box<dyn PlayState>> = vec![Box::new(MainMenuState::new(&mut global_state))];
states
.last()
.map(|current_state| info!("Started game with state '{}'", current_state.name()));
.map(|current_state| debug!("Started game with state '{}'", current_state.name()));
// What's going on here?
// ---------------------
@ -279,7 +231,7 @@ fn main() {
match state_result {
PlayStateResult::Shutdown => {
direction = Direction::Backwards;
info!("Shutting down all states...");
debug!("Shutting down all states...");
while states.last().is_some() {
states.pop().map(|old_state| {
debug!("Popped state '{}'.", old_state.name());

View File

@ -579,22 +579,22 @@ fn erode(
uplift: impl Fn(usize) -> f32,
is_ocean: impl Fn(usize) -> bool + Sync,
) {
log::info!("Done draining...");
log::debug!("Done draining...");
let mmaxh = 1.0;
let k = erosion_base as f64 + 2.244 / mmaxh as f64 * max_uplift as f64;
let ((dh, indirection, newh, area), max_slope) = rayon::join(
|| {
let mut dh = downhill(h, |posi| is_ocean(posi));
log::info!("Computed downhill...");
log::debug!("Computed downhill...");
let (boundary_len, indirection, newh) = get_lakes(&h, &mut dh);
log::info!("Got lakes...");
log::debug!("Got lakes...");
let area = get_drainage(&newh, &dh, boundary_len);
log::info!("Got flux...");
log::debug!("Got flux...");
(dh, indirection, newh, area)
},
|| {
let max_slope = get_max_slope(h, rock_strength_nz);
log::info!("Got max slopes...");
log::debug!("Got max slopes...");
max_slope
},
);
@ -669,7 +669,7 @@ fn erode(
}
maxh = h[posi].max(maxh);
}
log::info!(
log::debug!(
"Done eroding (max height: {:?}) (avg height: {:?}) (avg slope: {:?})",
maxh,
if nland == 0 {
@ -841,7 +841,7 @@ pub fn get_lakes(h: &[f32], downhill: &mut [isize]) -> (usize, Box<[i32]>, Box<[
}
assert_eq!(newh.len(), downhill.len());
log::info!("Old lake roots: {:?}", lake_roots.len());
log::debug!("Old lake roots: {:?}", lake_roots.len());
let newh = newh.into_boxed_slice();
// Now, we know that the sum of all the indirection nodes will be the same as the number of
@ -1067,7 +1067,7 @@ pub fn get_lakes(h: &[f32], downhill: &mut [isize]) -> (usize, Box<[i32]>, Box<[
}
// println!("I am a pass: {:?}", (uniform_idx_as_vec2(chunk_idx as usize), uniform_idx_as_vec2(neighbor_idx as usize)));
}
log::info!("Total lakes: {:?}", pass_flows_sorted.len());
log::debug!("Total lakes: {:?}", pass_flows_sorted.len());
// Perform the bfs once again.
let mut newh = Vec::with_capacity(downhill.len());
@ -1130,17 +1130,17 @@ pub fn do_erosion(
.cloned()
.map(|e| e as f64)
.sum::<f64>();
log::info!("Sum uplifts: {:?}", sum_uplift);
log::debug!("Sum uplifts: {:?}", sum_uplift);
let max_uplift = uplift
.into_par_iter()
.cloned()
.max_by(|a, b| a.partial_cmp(&b).unwrap())
.unwrap();
log::info!("Max uplift: {:?}", max_uplift);
log::debug!("Max uplift: {:?}", max_uplift);
let mut h = oldh_;
for i in 0..n {
log::info!("Erosion iteration #{:?}", i);
log::debug!("Erosion iteration #{:?}", i);
erode(
&mut h,
erosion_base,

View File

@ -1083,7 +1083,7 @@ impl SimChunk {
); */
}
if river_slope.abs() >= 1.0 && cross_section.x >= 1.0 {
log::info!(
log::debug!(
"Big waterfall! Pos area: {:?}, River data: {:?}, slope: {:?}",
wposf,
river,