diff --git a/.circleci/config.yml b/.circleci/config.yml index 5aae143e48..643c853854 100644 --- a/.circleci/config.yml +++ b/.circleci/config.yml @@ -113,7 +113,7 @@ jobs: CARGO_FLAGS= elif [[ $BUILD_TYPE == "release" ]]; then cov_prefix=() - CARGO_FLAGS=--release + CARGO_FLAGS="--release --features profiling" fi export CARGO_INCREMENTAL=0 @@ -369,7 +369,7 @@ jobs: when: always command: | du -sh /tmp/test_output/* - find /tmp/test_output -type f ! -name "pg.log" ! -name "pageserver.log" ! -name "safekeeper.log" ! -name "regression.diffs" ! -name "junit.xml" ! -name "*.filediff" ! -name "*.stdout" ! -name "*.stderr" -delete + find /tmp/test_output -type f ! -name "pg.log" ! -name "pageserver.log" ! -name "safekeeper.log" ! -name "regression.diffs" ! -name "junit.xml" ! -name "*.filediff" ! -name "*.stdout" ! -name "*.stderr" ! -name "flamegraph.svg" -delete du -sh /tmp/test_output/* - store_artifacts: path: /tmp/test_output diff --git a/Cargo.lock b/Cargo.lock index 508b56125d..3ca3671207 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -55,6 +55,15 @@ dependencies = [ "backtrace", ] +[[package]] +name = "arrayvec" +version = "0.4.12" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "cd9fd44efafa8690358b7408d253adf110036b88f55672a933f01d616ad9b1b9" +dependencies = [ + "nodrop", +] + [[package]] name = "async-stream" version = "0.3.3" @@ -196,6 +205,12 @@ version = "3.9.1" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "a4a45a46ab1f2412e53d3a0ade76ffad2025804294569aae387231a0cd6e0899" +[[package]] +name = "bytemuck" +version = "1.9.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "cdead85bdec19c194affaeeb670c0e41fe23de31459efd1c174d049269cf02cc" + [[package]] name = "byteorder" version = "1.4.3" @@ -385,6 +400,15 @@ version = "0.8.3" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "5827cebf4670468b8772dd191856768aedcb1b0278a04f989f7766351917b9dc" +[[package]] +name = "cpp_demangle" +version = "0.3.5" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "eeaa953eaad386a53111e47172c2fedba671e5684c8dd601a5f474f4f118710f" +dependencies = [ + "cfg-if", +] + [[package]] name = "cpufeatures" version = "0.2.1" @@ -580,6 +604,15 @@ dependencies = [ "syn", ] +[[package]] +name = "debugid" +version = "0.7.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "d6ee87af31d84ef885378aebca32be3d682b0e0dc119d5b4860a2c5bb5046730" +dependencies = [ + "uuid", +] + [[package]] name = "digest" version = "0.9.0" @@ -691,6 +724,18 @@ dependencies = [ "winapi", ] +[[package]] +name = "findshlibs" +version = "0.10.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "40b9e59cd0f7e0806cca4be089683ecb6434e602038df21fe6bf6711b2f07f64" +dependencies = [ + "cc", + "lazy_static", + "libc", + "winapi", +] + [[package]] name = "fixedbitset" version = "0.4.1" @@ -1098,6 +1143,24 @@ dependencies = [ "hashbrown", ] +[[package]] +name = "inferno" +version = "0.10.12" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "de3886428c6400486522cf44b8626e7b94ad794c14390290f2a274dcf728a58f" +dependencies = [ + "ahash", + "atty", + "indexmap", + "itoa 1.0.1", + "lazy_static", + "log", + "num-format", + "quick-xml", + "rgb", + "str_stack", +] + [[package]] name = "instant" version = "0.1.12" @@ -1251,6 +1314,15 @@ version = "2.4.1" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "308cc39be01b73d0d18f82a0e7b2a3df85245f84af96fdddc5d202d27e47b86a" +[[package]] +name = "memmap2" +version = "0.5.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "057a3db23999c867821a7a59feb06a578fcb03685e983dff90daf9e7d24ac08f" +dependencies = [ + "libc", +] + [[package]] name = "memoffset" version = "0.6.5" @@ -1353,6 +1425,12 @@ dependencies = [ "memoffset", ] +[[package]] +name = "nodrop" +version = "0.1.14" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "72ef4a56884ca558e5ddb05a1d1e7e1bfd9a68d9ed024c21704cc98872dae1bb" + [[package]] name = "nom" version = "7.1.0" @@ -1384,6 +1462,16 @@ dependencies = [ "num-traits", ] +[[package]] +name = "num-format" +version = "0.4.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "bafe4179722c2894288ee77a9f044f02811c86af699344c498b0840c698a2465" +dependencies = [ + "arrayvec", + "itoa 0.4.8", +] + [[package]] name = "num-integer" version = "0.1.44" @@ -1520,6 +1608,7 @@ dependencies = [ "postgres-protocol", "postgres-types", "postgres_ffi", + "pprof", "rand", "regex", "rusoto_core", @@ -1747,6 +1836,25 @@ dependencies = [ "workspace_hack", ] +[[package]] +name = "pprof" +version = "0.6.1" +source = "git+https://github.com/neondatabase/pprof-rs.git?branch=wallclock-profiling#4e011a87d22fb4d21d15cc38bce81ff1c75e4bc9" +dependencies = [ + "backtrace", + "cfg-if", + "findshlibs", + "inferno", + "lazy_static", + "libc", + "log", + "nix", + "parking_lot", + "symbolic-demangle", + "tempfile", + "thiserror", +] + [[package]] name = "ppv-lite86" version = "0.2.16" @@ -1876,6 +1984,15 @@ dependencies = [ "workspace_hack", ] +[[package]] +name = "quick-xml" +version = "0.22.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "8533f14c8382aaad0d592c812ac3b826162128b65662331e1127b45c3d18536b" +dependencies = [ + "memchr", +] + [[package]] name = "quickcheck" version = "1.0.3" @@ -2063,6 +2180,15 @@ dependencies = [ "winreg", ] +[[package]] +name = "rgb" +version = "0.8.32" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "e74fdc210d8f24a7dbfedc13b04ba5764f5232754ccebfdf5fff1bad791ccbc6" +dependencies = [ + "bytemuck", +] + [[package]] name = "ring" version = "0.16.20" @@ -2521,6 +2647,18 @@ version = "0.5.2" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "6e63cff320ae2c57904679ba7cb63280a3dc4613885beafb148ee7bf9aa9042d" +[[package]] +name = "stable_deref_trait" +version = "1.2.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "a8f112729512f8e442d81f95a8a7ddf2b7c6b8a1a6f509a95864142b30cab2d3" + +[[package]] +name = "str_stack" +version = "0.1.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "9091b6114800a5f2141aee1d1b9d6ca3592ac062dc5decb3764ec5895a47b4eb" + [[package]] name = "stringprep" version = "0.1.2" @@ -2549,6 +2687,29 @@ version = "2.4.1" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "6bdef32e8150c2a081110b42772ffe7d7c9032b606bc226c8260fd97e0976601" +[[package]] +name = "symbolic-common" +version = "8.7.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "ac6aac7b803adc9ee75344af7681969f76d4b38e4723c6eaacf3b28f5f1d87ff" +dependencies = [ + "debugid", + "memmap2", + "stable_deref_trait", + "uuid", +] + +[[package]] +name = "symbolic-demangle" +version = "8.7.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "8143ea5aa546f86c64f9b9aafdd14223ffad4ecd2d58575c63c21335909c99a7" +dependencies = [ + "cpp_demangle", + "rustc-demangle", + "symbolic-common", +] + [[package]] name = "syn" version = "1.0.86" @@ -3099,6 +3260,12 @@ dependencies = [ "workspace_hack", ] +[[package]] +name = "uuid" +version = "0.8.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "bc5cf98d8186244414c848017f0e2676b3fcb46807f6668a97dfe67359a3c4b7" + [[package]] name = "valuable" version = "0.1.0" diff --git a/pageserver/Cargo.toml b/pageserver/Cargo.toml index 7b44dafb09..eb58b90ad9 100644 --- a/pageserver/Cargo.toml +++ b/pageserver/Cargo.toml @@ -3,6 +3,10 @@ name = "pageserver" version = "0.1.0" edition = "2021" +[features] +default = [] +profiling = ["pprof"] + [dependencies] chrono = "0.4.19" rand = "0.8.3" @@ -32,6 +36,8 @@ serde = { version = "1.0", features = ["derive"] } serde_json = "1" serde_with = "1.12.0" +pprof = { git = "https://github.com/neondatabase/pprof-rs.git", branch = "wallclock-profiling", features = ["flamegraph"], optional = true } + toml_edit = { version = "0.13", features = ["easy"] } scopeguard = "1.1.0" const_format = "0.2.21" diff --git a/pageserver/src/bin/pageserver.rs b/pageserver/src/bin/pageserver.rs index 867bea1b06..9b944cc2ec 100644 --- a/pageserver/src/bin/pageserver.rs +++ b/pageserver/src/bin/pageserver.rs @@ -10,7 +10,7 @@ use daemonize::Daemonize; use pageserver::{ config::{defaults::*, PageServerConf}, - http, page_cache, page_service, + http, page_cache, page_service, profiling, remote_storage::{self, SyncStartupData}, repository::{Repository, TimelineSyncStatusUpdate}, tenant_mgr, thread_mgr, @@ -29,11 +29,15 @@ use utils::{ GIT_VERSION, }; +fn version() -> String { + format!("{} profiling:{}", GIT_VERSION, cfg!(feature = "profiling")) +} + fn main() -> anyhow::Result<()> { metrics::set_common_metrics_prefix("pageserver"); let arg_matches = App::new("Zenith page server") .about("Materializes WAL stream to pages and serves them to the postgres") - .version(GIT_VERSION) + .version(&*version()) .arg( Arg::new("daemonize") .short('d') @@ -283,6 +287,9 @@ fn start_pageserver(conf: &'static PageServerConf, daemonize: bool) -> Result<() }; info!("Using auth: {:#?}", conf.auth_type); + // start profiler (if enabled) + let profiler_guard = profiling::init_profiler(conf); + // Spawn a new thread for the http endpoint // bind before launching separate thread so the error reported before startup exits let auth_cloned = auth.clone(); @@ -315,6 +322,7 @@ fn start_pageserver(conf: &'static PageServerConf, daemonize: bool) -> Result<() "Got {}. Terminating in immediate shutdown mode", signal.name() ); + profiling::exit_profiler(conf, &profiler_guard); std::process::exit(111); } @@ -323,6 +331,7 @@ fn start_pageserver(conf: &'static PageServerConf, daemonize: bool) -> Result<() "Got {}. Terminating gracefully in fast shutdown mode", signal.name() ); + profiling::exit_profiler(conf, &profiler_guard); pageserver::shutdown_pageserver(); unreachable!() } diff --git a/pageserver/src/config.rs b/pageserver/src/config.rs index 0cba3f48f8..24ab45386d 100644 --- a/pageserver/src/config.rs +++ b/pageserver/src/config.rs @@ -140,6 +140,27 @@ pub struct PageServerConf { pub auth_validation_public_key_path: Option, pub remote_storage_config: Option, + + pub profiling: ProfilingConfig, +} + +#[derive(Debug, Clone, PartialEq, Eq)] +pub enum ProfilingConfig { + Disabled, + PageRequests, +} + +impl FromStr for ProfilingConfig { + type Err = anyhow::Error; + + fn from_str(s: &str) -> Result { + let result = match s { + "disabled" => ProfilingConfig::Disabled, + "page_requests" => ProfilingConfig::PageRequests, + _ => bail!("invalid value \"{}\" for profiling option, valid values are \"disabled\" and \"page_requests\"", s), + }; + Ok(result) + } } // use dedicated enum for builder to better indicate the intention @@ -192,6 +213,8 @@ struct PageServerConfigBuilder { remote_storage_config: BuilderValue>, id: BuilderValue, + + profiling: BuilderValue, } impl Default for PageServerConfigBuilder { @@ -224,6 +247,7 @@ impl Default for PageServerConfigBuilder { auth_validation_public_key_path: Set(None), remote_storage_config: Set(None), id: NotSet, + profiling: Set(ProfilingConfig::Disabled), } } } @@ -308,6 +332,10 @@ impl PageServerConfigBuilder { self.id = BuilderValue::Set(node_id) } + pub fn profiling(&mut self, profiling: ProfilingConfig) { + self.profiling = BuilderValue::Set(profiling) + } + pub fn build(self) -> Result { Ok(PageServerConf { listen_pg_addr: self @@ -357,6 +385,7 @@ impl PageServerConfigBuilder { .remote_storage_config .ok_or(anyhow::anyhow!("missing remote_storage_config"))?, id: self.id.ok_or(anyhow::anyhow!("missing id"))?, + profiling: self.profiling.ok_or(anyhow::anyhow!("missing profiling"))?, }) } } @@ -486,11 +515,12 @@ impl PageServerConf { "auth_validation_public_key_path" => builder.auth_validation_public_key_path(Some( PathBuf::from(parse_toml_string(key, item)?), )), - "auth_type" => builder.auth_type(parse_toml_auth_type(key, item)?), + "auth_type" => builder.auth_type(parse_toml_from_str(key, item)?), "remote_storage" => { builder.remote_storage_config(Some(Self::parse_remote_storage_config(item)?)) } "id" => builder.id(ZNodeId(parse_toml_u64(key, item)?)), + "profiling" => builder.profiling(parse_toml_from_str(key, item)?), _ => bail!("unrecognized pageserver option '{}'", key), } } @@ -623,6 +653,7 @@ impl PageServerConf { auth_type: AuthType::Trust, auth_validation_public_key_path: None, remote_storage_config: None, + profiling: ProfilingConfig::Disabled, } } } @@ -656,11 +687,14 @@ fn parse_toml_duration(name: &str, item: &Item) -> Result { Ok(humantime::parse_duration(s)?) } -fn parse_toml_auth_type(name: &str, item: &Item) -> Result { +fn parse_toml_from_str(name: &str, item: &Item) -> Result +where + T: FromStr, +{ let v = item .as_str() .with_context(|| format!("configure option {} is not a string", name))?; - AuthType::from_str(v) + T::from_str(v) } #[cfg(test)] @@ -733,6 +767,7 @@ id = 10 auth_type: AuthType::Trust, auth_validation_public_key_path: None, remote_storage_config: None, + profiling: ProfilingConfig::Disabled, }, "Correct defaults should be used when no config values are provided" ); @@ -779,6 +814,7 @@ id = 10 auth_type: AuthType::Trust, auth_validation_public_key_path: None, remote_storage_config: None, + profiling: ProfilingConfig::Disabled, }, "Should be able to parse all basic config values correctly" ); diff --git a/pageserver/src/lib.rs b/pageserver/src/lib.rs index e6ac159ef2..a761f0dfe2 100644 --- a/pageserver/src/lib.rs +++ b/pageserver/src/lib.rs @@ -7,6 +7,7 @@ pub mod layered_repository; pub mod page_cache; pub mod page_service; pub mod pgdatadir_mapping; +pub mod profiling; pub mod reltag; pub mod remote_storage; pub mod repository; diff --git a/pageserver/src/page_service.rs b/pageserver/src/page_service.rs index 8f5ea2e845..8c90195131 100644 --- a/pageserver/src/page_service.rs +++ b/pageserver/src/page_service.rs @@ -29,8 +29,9 @@ use utils::{ }; use crate::basebackup; -use crate::config::PageServerConf; +use crate::config::{PageServerConf, ProfilingConfig}; use crate::pgdatadir_mapping::DatadirTimeline; +use crate::profiling::profpoint_start; use crate::reltag::RelTag; use crate::repository::Repository; use crate::repository::Timeline; @@ -331,7 +332,10 @@ impl PageServerHandler { pgb.write_message(&BeMessage::CopyBothResponse)?; while !thread_mgr::is_shutdown_requested() { - match pgb.read_message() { + let msg = pgb.read_message(); + + let profiling_guard = profpoint_start(self.conf, ProfilingConfig::PageRequests); + match msg { Ok(message) => { if let Some(message) = message { trace!("query: {:?}", message); @@ -383,6 +387,7 @@ impl PageServerHandler { } } } + drop(profiling_guard); } Ok(()) } diff --git a/pageserver/src/profiling.rs b/pageserver/src/profiling.rs new file mode 100644 index 0000000000..e2c12c9e12 --- /dev/null +++ b/pageserver/src/profiling.rs @@ -0,0 +1,95 @@ +//! +//! Support for profiling +//! +//! This relies on a modified version of the 'pprof-rs' crate. That's not very +//! nice, so to avoid a hard dependency on that, this is an optional feature. +//! +use crate::config::{PageServerConf, ProfilingConfig}; + +/// The actual implementation is in the `profiling_impl` submodule. If the profiling +/// feature is not enabled, it's just a dummy implementation that panics if you +/// try to enabled profiling in the configuration. +pub use profiling_impl::*; + +#[cfg(feature = "profiling")] +mod profiling_impl { + use super::*; + use pprof; + use std::marker::PhantomData; + + /// Start profiling the current thread. Returns a guard object; + /// the profiling continues until the guard is dropped. + /// + /// Note: profiling is not re-entrant. If you call 'profpoint_start' while + /// profiling is already started, nothing happens, and the profiling will be + /// stopped when either guard object is dropped. + #[inline] + pub fn profpoint_start( + conf: &crate::config::PageServerConf, + point: ProfilingConfig, + ) -> Option { + if conf.profiling == point { + pprof::start_profiling(); + Some(ProfilingGuard(PhantomData)) + } else { + None + } + } + + /// A hack to remove Send and Sync from the ProfilingGuard. Because the + /// profiling is attached to current thread. + //// + /// See comments in https://github.com/rust-lang/rust/issues/68318 + type PhantomUnsend = std::marker::PhantomData<*mut u8>; + + pub struct ProfilingGuard(PhantomUnsend); + + impl Drop for ProfilingGuard { + fn drop(&mut self) { + pprof::stop_profiling(); + } + } + + /// Initialize the profiler. This must be called before any 'profpoint_start' calls. + pub fn init_profiler(conf: &PageServerConf) -> Option { + if conf.profiling != ProfilingConfig::Disabled { + Some(pprof::ProfilerGuardBuilder::default().build().unwrap()) + } else { + None + } + } + + /// Exit the profiler. Writes the flamegraph to current workdir. + pub fn exit_profiler(_conf: &PageServerConf, profiler_guard: &Option) { + // Write out the flamegraph + if let Some(profiler_guard) = profiler_guard { + if let Ok(report) = profiler_guard.report().build() { + // this gets written under the workdir + let file = std::fs::File::create("flamegraph.svg").unwrap(); + let mut options = pprof::flamegraph::Options::default(); + options.image_width = Some(2500); + report.flamegraph_with_options(file, &mut options).unwrap(); + } + } + } +} + +/// Dummy implementation when compiling without profiling feature +#[cfg(not(feature = "profiling"))] +mod profiling_impl { + use super::*; + + pub fn profpoint_start(_conf: &PageServerConf, _point: ProfilingConfig) -> () { + () + } + + pub fn init_profiler(conf: &PageServerConf) -> () { + if conf.profiling != ProfilingConfig::Disabled { + // shouldn't happen, we don't allow profiling in the config if the support + // for it is disabled. + panic!("profiling enabled but the binary was compiled without profiling support"); + } + } + + pub fn exit_profiler(_conf: &PageServerConf, _guard: &()) {} +} diff --git a/test_runner/fixtures/zenith_fixtures.py b/test_runner/fixtures/zenith_fixtures.py index a9c4c0f395..9a2d6cdc88 100644 --- a/test_runner/fixtures/zenith_fixtures.py +++ b/test_runner/fixtures/zenith_fixtures.py @@ -155,6 +155,18 @@ def pytest_configure(config): raise Exception('zenith binaries not found at "{}"'.format(zenith_binpath)) +def profiling_supported(): + """Return True if the pageserver was compiled with the 'profiling' feature + """ + bin_pageserver = os.path.join(str(zenith_binpath), 'pageserver') + res = subprocess.run([bin_pageserver, '--version'], + check=True, + universal_newlines=True, + stdout=subprocess.PIPE, + stderr=subprocess.PIPE) + return "profiling:true" in res.stdout + + def shareable_scope(fixture_name, config) -> Literal["session", "function"]: """Return either session of function scope, depending on TEST_SHARED_FIXTURES envvar. diff --git a/test_runner/performance/test_perf_pgbench.py b/test_runner/performance/test_perf_pgbench.py index d2de76913a..fc10ca4d6c 100644 --- a/test_runner/performance/test_perf_pgbench.py +++ b/test_runner/performance/test_perf_pgbench.py @@ -1,5 +1,5 @@ from contextlib import closing -from fixtures.zenith_fixtures import PgBin, VanillaPostgres, ZenithEnv +from fixtures.zenith_fixtures import PgBin, VanillaPostgres, ZenithEnv, profiling_supported from fixtures.compare_fixtures import PgCompare, VanillaCompare, ZenithCompare from fixtures.benchmark_fixture import PgBenchRunResult, MetricReport, ZenithBenchmarker @@ -106,6 +106,28 @@ def test_pgbench(zenith_with_baseline: PgCompare, scale: int, duration: int): run_test_pgbench(zenith_with_baseline, scale, duration) +# Run the pgbench tests, and generate a flamegraph from it +# This requires that the pageserver was built with the 'profiling' feature. +# +# TODO: If the profiling is cheap enough, there's no need to run the same test +# twice, with and without profiling. But for now, run it separately, so that we +# can see how much overhead the profiling adds. +@pytest.mark.parametrize("scale", get_scales_matrix()) +@pytest.mark.parametrize("duration", get_durations_matrix()) +def test_pgbench_flamegraph(zenbenchmark, pg_bin, zenith_env_builder, scale: int, duration: int): + zenith_env_builder.num_safekeepers = 1 + zenith_env_builder.pageserver_config_override = ''' +profiling="page_requests" +''' + if not profiling_supported(): + pytest.skip("pageserver was built without 'profiling' feature") + + env = zenith_env_builder.init_start() + env.zenith_cli.create_branch("empty", "main") + + run_test_pgbench(ZenithCompare(zenbenchmark, env, pg_bin, "pgbench"), scale, duration) + + # Run the pgbench tests against an existing Postgres cluster @pytest.mark.parametrize("scale", get_scales_matrix()) @pytest.mark.parametrize("duration", get_durations_matrix())