Auto merge of #4659 - str4d:tracing-init, r=str4d

Improvements to tracing initialization

The refactor makes it easier to implement further tracing customisations.

We also now have spans for `zcashd` initialization and shutdown.
This commit is contained in:
Homu 2020-08-17 07:32:04 +00:00
commit c2f991db5b
3 changed files with 102 additions and 68 deletions

View File

@ -170,6 +170,11 @@ bool AppInit(int argc, char* argv[])
// Set this early so that parameter interactions go to console
InitLogging();
// Now that we have logging set up, start the initialization span.
auto span = TracingSpan("info", "main", "Init");
auto spanGuard = span.Enter();
InitParameterInteraction();
fRet = AppInit2(threadGroup, scheduler);
}

View File

@ -177,7 +177,9 @@ void Interrupt(boost::thread_group& threadGroup)
void Shutdown()
{
LogPrintf("%s: In progress...\n", __func__);
auto span = TracingSpan("info", "main", "Shutdown");
auto spanGuard = span.Enter();
static CCriticalSection cs_Shutdown;
TRY_LOCK(cs_Shutdown, lockShutdown);
if (!lockShutdown)
@ -260,7 +262,7 @@ void Shutdown()
#endif
globalVerifyHandle.reset();
ECC_Stop();
LogPrintf("%s: done\n", __func__);
TracingInfo("main", "done");
if (pTracingHandle) {
tracing_free(pTracingHandle);
}
@ -809,20 +811,22 @@ void InitLogging()
// Set up the initial filtering directive from the -debug flags.
std::string initialFilter = LogConfigFilter();
if (fPrintToConsole) {
pTracingHandle = tracing_init(nullptr, 0, initialFilter.c_str(), fLogTimestamps);
} else {
boost::filesystem::path pathDebug = GetDebugLogPath();
const boost::filesystem::path::string_type& pathDebugStr = pathDebug.native();
static_assert(sizeof(boost::filesystem::path::value_type) == sizeof(codeunit),
"native path has unexpected code unit size");
pTracingHandle = tracing_init(
reinterpret_cast<const codeunit*>(pathDebugStr.c_str()),
pathDebugStr.length(),
initialFilter.c_str(),
fLogTimestamps);
boost::filesystem::path pathDebug = GetDebugLogPath();
const boost::filesystem::path::string_type& pathDebugStr = pathDebug.native();
static_assert(sizeof(boost::filesystem::path::value_type) == sizeof(codeunit),
"native path has unexpected code unit size");
const codeunit* pathDebugCStr = nullptr;
size_t pathDebugLen = 0;
if (!fPrintToConsole) {
pathDebugCStr = reinterpret_cast<const codeunit*>(pathDebugStr.c_str());
pathDebugLen = pathDebugStr.length();
}
pTracingHandle = tracing_init(
pathDebugCStr, pathDebugLen,
initialFilter.c_str(),
fLogTimestamps);
LogPrintf("\n\n\n\n\n\n\n\n\n\n\n\n\n\n\n\n\n\n\n\n");
LogPrintf("Zcash version %s (%s)\n", FormatFullVersion(), CLIENT_DATE);
}

View File

@ -17,8 +17,9 @@ use tracing_appender::non_blocking::WorkerGuard;
use tracing_core::Once;
use tracing_subscriber::{
filter::EnvFilter,
layer::Layer,
layer::{Layer, SubscriberExt},
reload::{self, Handle},
util::SubscriberInitExt,
};
#[cfg(not(target_os = "windows"))]
@ -62,72 +63,96 @@ pub extern "C" fn tracing_init(
.to_str()
.expect("initial filter should be a valid string");
if log_path.is_null() {
tracing_init_stdout(initial_filter, log_timestamps)
let log_path = if log_path.is_null() {
None
} else {
let log_path = unsafe { slice::from_raw_parts(log_path, log_path_len) };
#[cfg(not(target_os = "windows"))]
let log_path = OsStr::from_bytes(log_path);
#[cfg(target_os = "windows")]
let log_path = OsString::from_wide(log_path);
tracing_init_file(Path::new(&log_path), initial_filter, log_timestamps)
}
}
fn tracing_init_stdout(initial_filter: &str, log_timestamps: bool) -> *mut TracingHandle {
let builder = tracing_subscriber::fmt()
.with_ansi(true)
.with_env_filter(initial_filter);
let reload_handle = if log_timestamps {
let builder = builder.with_filter_reloading();
let reload_handle = builder.reload_handle();
builder.init();
Box::new(reload_handle) as Box<dyn ReloadHandle>
} else {
let builder = builder.without_time().with_filter_reloading();
let reload_handle = builder.reload_handle();
builder.init();
Box::new(reload_handle) as Box<dyn ReloadHandle>
Some(unsafe { slice::from_raw_parts(log_path, log_path_len) })
};
Box::into_raw(Box::new(TracingHandle {
_file_guard: None,
reload_handle,
}))
#[cfg(not(target_os = "windows"))]
let log_path = log_path.map(OsStr::from_bytes);
#[cfg(target_os = "windows")]
let log_path = log_path.map(OsString::from_wide);
tracing_init_inner(
log_path.as_ref().map(Path::new),
initial_filter,
log_timestamps,
)
}
fn tracing_init_file(
log_path: &Path,
fn tracing_init_inner(
log_path: Option<&Path>,
initial_filter: &str,
log_timestamps: bool,
) -> *mut TracingHandle {
let file_appender =
tracing_appender::rolling::never(log_path.parent().unwrap(), log_path.file_name().unwrap());
let (non_blocking, file_guard) = tracing_appender::non_blocking(file_appender);
let (file_logger, file_guard) = if let Some(log_path) = log_path {
let file_appender = tracing_appender::rolling::never(
log_path.parent().unwrap(),
log_path.file_name().unwrap(),
);
let (non_blocking, file_guard) = tracing_appender::non_blocking(file_appender);
let builder = tracing_subscriber::fmt()
.with_ansi(false)
.with_env_filter(initial_filter)
.with_writer(non_blocking);
let reload_handle = if log_timestamps {
let builder = builder.with_filter_reloading();
let reload_handle = builder.reload_handle();
builder.init();
Box::new(reload_handle) as Box<dyn ReloadHandle>
(
Some(
tracing_subscriber::fmt::layer()
.with_ansi(false)
.with_writer(non_blocking),
),
Some(file_guard),
)
} else {
let builder = builder.without_time().with_filter_reloading();
let reload_handle = builder.reload_handle();
builder.init();
Box::new(reload_handle) as Box<dyn ReloadHandle>
(None, None)
};
let stdout_logger = tracing_subscriber::fmt::layer().with_ansi(true);
let filter = EnvFilter::from(initial_filter);
let reload_handle = match (file_logger, log_timestamps) {
(None, true) => {
let (filter, reload_handle) = reload::Layer::new(filter);
tracing_subscriber::registry()
.with(stdout_logger)
.with(filter)
.init();
Box::new(reload_handle) as Box<dyn ReloadHandle>
}
(None, false) => {
let (filter, reload_handle) = reload::Layer::new(filter);
tracing_subscriber::registry()
.with(stdout_logger.without_time())
.with(filter)
.init();
Box::new(reload_handle) as Box<dyn ReloadHandle>
}
(Some(file_logger), true) => {
let (filter, reload_handle) = reload::Layer::new(filter);
tracing_subscriber::registry()
.with(file_logger)
.with(filter)
.init();
Box::new(reload_handle) as Box<dyn ReloadHandle>
}
(Some(file_logger), false) => {
let (filter, reload_handle) = reload::Layer::new(filter);
tracing_subscriber::registry()
.with(file_logger.without_time())
.with(filter)
.init();
Box::new(reload_handle) as Box<dyn ReloadHandle>
}
};
Box::into_raw(Box::new(TracingHandle {
_file_guard: Some(file_guard),
_file_guard: file_guard,
reload_handle,
}))
}