diff --git a/Cargo.lock b/Cargo.lock index 3dbd5df0c..36717ba3f 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -74,22 +74,22 @@ dependencies = [ [[package]] name = "anstyle-query" -version = "1.1.4" +version = "1.1.5" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "9e231f6134f61b71076a3eab506c379d4f36122f2af15a9ff04415ea4c3339e2" +checksum = "40c48f72fd53cd289104fc64099abca73db4166ad86ea0b4341abe65af83dadc" dependencies = [ - "windows-sys 0.60.2", + "windows-sys 0.61.2", ] [[package]] name = "anstyle-wincon" -version = "3.0.10" +version = "3.0.11" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "3e0633414522a32ffaac8ac6cc8f748e090c5717661fddeea04219e2344f5f2a" +checksum = "291e6a250ff86cd4a820112fb8898808a366d8f9f58ce16d1f538353ad55747d" dependencies = [ "anstyle", "once_cell_polyfill", - "windows-sys 0.60.2", + "windows-sys 0.61.2", ] [[package]] @@ -241,9 +241,9 @@ checksum = "1fd0f2584146f6f2ef48085050886acf353beff7305ebd1ae69500e27c67f64b" [[package]] name = "bytes" -version = "1.10.1" +version = "1.11.0" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "d71b6127be86fdcfddb610f7182ac57211d4b18a3e9c82eb2d17662f2227ad6a" +checksum = "b35204fbdc0b3f4446b89fc1ac2cf84a8a68971995d0bf2e925ec7cd960f9cb3" [[package]] name = "bytesize" @@ -274,9 +274,9 @@ dependencies = [ [[package]] name = "cc" -version = "1.2.45" +version = "1.2.46" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "35900b6c8d709fb1d854671ae27aeaa9eec2f8b01b364e1619a40da3e6fe2afe" +checksum = "b97463e1064cb1b1c1384ad0a0b9c8abd0988e2a91f52606c80ef14aadb63e36" dependencies = [ "find-msvc-tools", "shlex", @@ -358,6 +358,16 @@ version = "0.4.30" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "3a9b614a5787ef0c8802a55766480563cb3a93b435898c422ed2a359cf811582" +[[package]] +name = "core-foundation" +version = "0.9.4" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "91e195e091a93c46f7102ec7818a2aa394e1e1771c3ab4825963fa03e45afb8f" +dependencies = [ + "core-foundation-sys", + "libc", +] + [[package]] name = "core-foundation" version = "0.10.1" @@ -416,6 +426,25 @@ dependencies = [ "crossbeam-utils", ] +[[package]] +name = "crossbeam-deque" +version = "0.8.6" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "9dd111b7b7f7d55b72c0a6ae361660ee5853c9af73f70c3c2ef6858b950e2e51" +dependencies = [ + "crossbeam-epoch", + "crossbeam-utils", +] + +[[package]] +name = "crossbeam-epoch" +version = "0.9.18" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "5b82ac4a3c2ca9c3460964f020e1402edd5753411d7737aa39c3714ad1b5420e" +dependencies = [ + "crossbeam-utils", +] + [[package]] name = "crossbeam-utils" version = "0.8.21" @@ -542,6 +571,15 @@ dependencies = [ "stable_deref_trait", ] +[[package]] +name = "encoding_rs" +version = "0.8.35" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "75030f3c4f45dafd7586dd6780965a8c7e8e285a5ecb86713e63a79c5b2766f3" +dependencies = [ + "cfg-if", +] + [[package]] name = "enum-as-inner" version = "0.6.1" @@ -631,9 +669,9 @@ dependencies = [ [[package]] name = "find-msvc-tools" -version = "0.1.4" +version = "0.1.5" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "52051878f80a721bb68ebfbc930e07b65ba72f2da88968ea5c06fd6ca3d3a127" +checksum = "3a3076410a55c90011c298b04d0cfa770b00fa04e1e3c97d3f6c9de105a03844" [[package]] name = "flate2" @@ -658,6 +696,21 @@ version = "0.1.5" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "d9c4f5dac5e15c24eb999c26181a6ca40b39fe946cbe4c263c7209467bc83af2" +[[package]] +name = "foreign-types" +version = "0.3.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "f6f339eb8adc052cd2ca78910fda869aefa38d22d5cb648e6485e4d3fc06f3b1" +dependencies = [ + "foreign-types-shared", +] + +[[package]] +name = "foreign-types-shared" +version = "0.1.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "00b0228411908ca8685dba7fc2cdd70ec9990a6e753e89b6ac91a84c40fbaf4b" + [[package]] name = "form_urlencoded" version = "1.2.2" @@ -966,9 +1019,9 @@ checksum = "135b12329e5e3ce057a9f972339ea52bc954fe1e9358ef27f95e89716fbc5424" [[package]] name = "hyper" -version = "1.8.0" +version = "1.8.1" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "1744436df46f0bde35af3eda22aeaba453aada65d8f1c171cd8a5f59030bd69f" +checksum = "2ab2d4f250c3d7b1c9fcdff1cece94ea4e2dfbec68614f7b87cb205f24ca9d11" dependencies = [ "atomic-waker", "bytes", @@ -1004,11 +1057,27 @@ dependencies = [ "webpki-roots", ] +[[package]] +name = "hyper-tls" +version = "0.6.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "70206fc6890eaca9fde8a0bf71caa2ddfc9fe045ac9e5c70df101a7dbde866e0" +dependencies = [ + "bytes", + "http-body-util", + "hyper", + "hyper-util", + "native-tls", + "tokio", + "tokio-native-tls", + "tower-service", +] + [[package]] name = "hyper-util" -version = "0.1.17" +version = "0.1.18" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "3c6995591a8f1380fcb4ba966a252a4b29188d51d2b89e3a252f5305be65aea8" +checksum = "52e9a2a24dc5c6821e71a7030e1e14b7b632acac55c40e9d2e082c621261bb56" dependencies = [ "base64", "bytes", @@ -1023,9 +1092,11 @@ dependencies = [ "percent-encoding", "pin-project-lite", "socket2", + "system-configuration", "tokio", "tower-service", "tracing", + "windows-registry", ] [[package]] @@ -1359,6 +1430,15 @@ version = "0.2.6" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "7b29dffab797218e12e4df08ef5d15ab9efca2504038b1b32b9b32fc844b39c9" +[[package]] +name = "mach2" +version = "0.4.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "d640282b302c0bb0a2a8e0233ead9035e3bed871f0b7e81fe4a1ec829765db44" +dependencies = [ + "libc", +] + [[package]] name = "mach2" version = "0.5.0" @@ -1409,6 +1489,12 @@ dependencies = [ "autocfg", ] +[[package]] +name = "mime" +version = "0.3.17" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "6877bb514081ee2a7ff5ef9de3281f14a4dd4bceac4c09388074a6b5df8a139a" + [[package]] name = "minimal-lexical" version = "0.2.1" @@ -1447,6 +1533,23 @@ dependencies = [ "itoa", ] +[[package]] +name = "native-tls" +version = "0.2.14" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "87de3442987e9dbec73158d5c715e7ad9072fda936bb03d19d7fa10e00520f0e" +dependencies = [ + "libc", + "log", + "openssl", + "openssl-probe", + "openssl-sys", + "schannel", + "security-framework", + "security-framework-sys", + "tempfile", +] + [[package]] name = "nix" version = "0.30.1" @@ -1572,6 +1675,50 @@ dependencies = [ "windows-sys 0.60.2", ] +[[package]] +name = "openssl" +version = "0.10.75" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "08838db121398ad17ab8531ce9de97b244589089e290a384c900cb9ff7434328" +dependencies = [ + "bitflags", + "cfg-if", + "foreign-types", + "libc", + "once_cell", + "openssl-macros", + "openssl-sys", +] + +[[package]] +name = "openssl-macros" +version = "0.1.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "a948666b637a0f465e8564c73e89d4dde00d72d4d473cc972f390fc3dcee7d9c" +dependencies = [ + "proc-macro2", + "quote", + "syn", +] + +[[package]] +name = "openssl-probe" +version = "0.1.6" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "d05e27ee213611ffe7d6348b942e8f942b37114c00cc03cec254295a4a17852e" + +[[package]] +name = "openssl-sys" +version = "0.9.111" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "82cab2d520aa75e3c58898289429321eb788c3106963d0dc886ec7a5f4adc321" +dependencies = [ + "cc", + "libc", + "pkg-config", + "vcpkg", +] + [[package]] name = "option-ext" version = "0.2.0" @@ -1910,9 +2057,29 @@ dependencies = [ [[package]] name = "rangemap" -version = "1.6.0" +version = "1.7.0" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "f93e7e49bb0bf967717f7bd674458b3d6b0c5f48ec7e3038166026a69fc22223" +checksum = "acbbbbea733ec66275512d0b9694f34102e7d5406fdbe2ad8d21b28dce92887c" + +[[package]] +name = "rayon" +version = "1.11.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "368f01d005bf8fd9b1206fb6fa653e6c4a81ceb1466406b81792d87c5677a58f" +dependencies = [ + "either", + "rayon-core", +] + +[[package]] +name = "rayon-core" +version = "1.13.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "22e18b0f0062d30d4230b2e85ff77fdfe4326feb054b9783a3460d8435c8ab91" +dependencies = [ + "crossbeam-deque", + "crossbeam-utils", +] [[package]] name = "redox_syscall" @@ -2003,17 +2170,22 @@ dependencies = [ "async-compression", "base64", "bytes", + "encoding_rs", "futures-channel", "futures-core", "futures-util", + "h2", "http", "http-body", "http-body-util", "hyper", "hyper-rustls", + "hyper-tls", "hyper-util", "js-sys", "log", + "mime", + "native-tls", "percent-encoding", "pin-project-lite", "quinn", @@ -2024,6 +2196,7 @@ dependencies = [ "serde_urlencoded", "sync_wrapper", "tokio", + "tokio-native-tls", "tokio-rustls", "tokio-util", "tower", @@ -2216,7 +2389,7 @@ dependencies = [ "libc", "linux-perf-data", "log", - "mach2", + "mach2 0.5.0", "memchr", "memmap2", "memoffset", @@ -2284,6 +2457,23 @@ dependencies = [ "uuid", ] +[[package]] +name = "samply-markers" +version = "0.1.0" +dependencies = [ + "futures", + "itoa", + "libc", + "mach2 0.4.3", + "nix", + "rayon", + "regex", + "reqwest", + "serial_test", + "tempfile", + "tokio", +] + [[package]] name = "samply-object" version = "0.1.0" @@ -2353,6 +2543,24 @@ version = "0.0.6" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "0a4416eddc0eaf31e04aa4039bd3db4288ea1ba613955d86cf9c310049c5d1e2" +[[package]] +name = "scc" +version = "2.4.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "46e6f046b7fef48e2660c57ed794263155d713de679057f2d0c169bfc6e756cc" +dependencies = [ + "sdd", +] + +[[package]] +name = "schannel" +version = "0.1.28" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "891d81b926048e76efe18581bf793546b4c0eaf8448d72be8de2bbee5fd166e1" +dependencies = [ + "windows-sys 0.61.2", +] + [[package]] name = "scopeguard" version = "1.2.0" @@ -2365,6 +2573,25 @@ version = "0.12.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "6ab8598aa408498679922eff7fa985c25d58a90771bd6be794434c5277eab1a6" +[[package]] +name = "sdd" +version = "3.0.10" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "490dcfcbfef26be6800d11870ff2df8774fa6e86d047e3e8c8a76b25655e41ca" + +[[package]] +name = "security-framework" +version = "2.11.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "897b2245f0b511c87893af39b033e5ca9cce68824c4d7e7630b5a1d339658d02" +dependencies = [ + "bitflags", + "core-foundation 0.9.4", + "core-foundation-sys", + "libc", + "security-framework-sys", +] + [[package]] name = "security-framework-sys" version = "2.15.0" @@ -2430,6 +2657,31 @@ dependencies = [ "serde", ] +[[package]] +name = "serial_test" +version = "3.2.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "1b258109f244e1d6891bf1053a55d63a5cd4f8f4c30cf9a1280989f80e7a1fa9" +dependencies = [ + "futures", + "log", + "once_cell", + "parking_lot", + "scc", + "serial_test_derive", +] + +[[package]] +name = "serial_test_derive" +version = "3.2.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "5d69265a08751de7844521fd15003ae0a888e035773ba05695c5c759a6f89eef" +dependencies = [ + "proc-macro2", + "quote", + "syn", +] + [[package]] name = "shlex" version = "1.3.0" @@ -2555,6 +2807,27 @@ dependencies = [ "walkdir", ] +[[package]] +name = "system-configuration" +version = "0.6.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "3c879d448e9d986b661742763247d3693ed13609438cf3d006f51f5368a5ba6b" +dependencies = [ + "bitflags", + "core-foundation 0.9.4", + "system-configuration-sys", +] + +[[package]] +name = "system-configuration-sys" +version = "0.6.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "8e1d1b10ced5ca923a1fcb8d03e96b8d3268065d724548c0211415ff6ac6bac4" +dependencies = [ + "core-foundation-sys", + "libc", +] + [[package]] name = "tap" version = "1.0.1" @@ -2707,6 +2980,16 @@ dependencies = [ "syn", ] +[[package]] +name = "tokio-native-tls" +version = "0.3.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "bbae76ab933c85776efabc971569dd6119c580d8f5d448769dec1764bf796ef2" +dependencies = [ + "native-tls", + "tokio", +] + [[package]] name = "tokio-rustls" version = "0.26.4" @@ -3031,7 +3314,7 @@ version = "0.8.1" dependencies = [ "async-compression", "bytes", - "core-foundation", + "core-foundation 0.10.1", "core-foundation-sys", "debugid", "flate2", @@ -3135,8 +3418,8 @@ dependencies = [ "windows-implement", "windows-interface", "windows-link 0.1.3", - "windows-result", - "windows-strings", + "windows-result 0.3.4", + "windows-strings 0.4.2", ] [[package]] @@ -3194,6 +3477,17 @@ dependencies = [ "windows-link 0.1.3", ] +[[package]] +name = "windows-registry" +version = "0.6.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "02752bf7fbdcce7f2a27a742f798510f3e5ad88dbe84871e5168e2120c3d5720" +dependencies = [ + "windows-link 0.2.1", + "windows-result 0.4.1", + "windows-strings 0.5.1", +] + [[package]] name = "windows-result" version = "0.3.4" @@ -3203,6 +3497,15 @@ dependencies = [ "windows-link 0.1.3", ] +[[package]] +name = "windows-result" +version = "0.4.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "7781fa89eaf60850ac3d2da7af8e5242a5ea78d1a11c49bf2910bb5a73853eb5" +dependencies = [ + "windows-link 0.2.1", +] + [[package]] name = "windows-strings" version = "0.4.2" @@ -3212,6 +3515,15 @@ dependencies = [ "windows-link 0.1.3", ] +[[package]] +name = "windows-strings" +version = "0.5.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "7837d08f69c77cf6b07689544538e017c1bfcf57e34b4c0ff58e6c2cd3b37091" +dependencies = [ + "windows-link 0.2.1", +] + [[package]] name = "windows-sys" version = "0.48.0" diff --git a/Cargo.toml b/Cargo.toml index 5ecdb789a..0129eac1e 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -6,6 +6,7 @@ members = [ "gecko_profile", "samply-api", "samply-debugid", + "samply-markers", "samply-object", "samply-quota-manager", "samply-symbols", @@ -22,3 +23,8 @@ exclude = ["etw-reader"] # Should not be compiled on non-Windows [profile.dist] inherits = "release" lto = "thin" + +# Profile for profiling with samply +[profile.profiling] +inherits = "release" +debug = true diff --git a/samply-markers/Cargo.toml b/samply-markers/Cargo.toml new file mode 100644 index 000000000..f9aa73ecf --- /dev/null +++ b/samply-markers/Cargo.toml @@ -0,0 +1,42 @@ +[package] +name = "samply-markers" +version = "0.1.0" +edition = "2024" +authors = ["Erik Nordin "] +rust-version = "1.85.1" +license = "MIT OR Apache-2.0" +description = "Emit markers for samply profiles." +repository = "https://github.com/mstange/samply/" +readme = "README.md" +keywords = ["profiling", "markers", "instrumentation", "tracing", "performance"] + + +[features] +default = [] +enabled = [ + "dep:itoa", + "dep:nix", + "dep:tempfile", +] + +[target.'cfg(unix)'.dependencies] +itoa = { version = "1.0.15", optional = true } +nix = { version = "0.30.1", features = ["mman", "process", "time"], optional = true } +tempfile = { version = "3.23.0", optional = true } + +[target.'cfg(target_os = "macos")'.dependencies] +libc = "0.2" +mach2 = "0.4" + +[target.'cfg(unix)'.dev-dependencies] +nix = { version = "0.30.1", features = ["process"] } +regex = "1.12.2" +serial_test = "3.2.0" +tokio = { version = "1", features = ["rt", "rt-multi-thread", "macros", "time"] } +futures = "0.3" + +[dev-dependencies] +tokio = { version = "1", features = ["rt", "rt-multi-thread", "macros"] } +reqwest = "0.12" +futures = "0.3" +rayon = "1.10" diff --git a/samply-markers/LICENSE-APACHE b/samply-markers/LICENSE-APACHE new file mode 100644 index 000000000..16fe87b06 --- /dev/null +++ b/samply-markers/LICENSE-APACHE @@ -0,0 +1,201 @@ + Apache License + Version 2.0, January 2004 + http://www.apache.org/licenses/ + +TERMS AND CONDITIONS FOR USE, REPRODUCTION, AND DISTRIBUTION + +1. Definitions. + + "License" shall mean the terms and conditions for use, reproduction, + and distribution as defined by Sections 1 through 9 of this document. + + "Licensor" shall mean the copyright owner or entity authorized by + the copyright owner that is granting the License. + + "Legal Entity" shall mean the union of the acting entity and all + other entities that control, are controlled by, or are under common + control with that entity. For the purposes of this definition, + "control" means (i) the power, direct or indirect, to cause the + direction or management of such entity, whether by contract or + otherwise, or (ii) ownership of fifty percent (50%) or more of the + outstanding shares, or (iii) beneficial ownership of such entity. + + "You" (or "Your") shall mean an individual or Legal Entity + exercising permissions granted by this License. + + "Source" form shall mean the preferred form for making modifications, + including but not limited to software source code, documentation + source, and configuration files. + + "Object" form shall mean any form resulting from mechanical + transformation or translation of a Source form, including but + not limited to compiled object code, generated documentation, + and conversions to other media types. + + "Work" shall mean the work of authorship, whether in Source or + Object form, made available under the License, as indicated by a + copyright notice that is included in or attached to the work + (an example is provided in the Appendix below). + + "Derivative Works" shall mean any work, whether in Source or Object + form, that is based on (or derived from) the Work and for which the + editorial revisions, annotations, elaborations, or other modifications + represent, as a whole, an original work of authorship. For the purposes + of this License, Derivative Works shall not include works that remain + separable from, or merely link (or bind by name) to the interfaces of, + the Work and Derivative Works thereof. + + "Contribution" shall mean any work of authorship, including + the original version of the Work and any modifications or additions + to that Work or Derivative Works thereof, that is intentionally + submitted to Licensor for inclusion in the Work by the copyright owner + or by an individual or Legal Entity authorized to submit on behalf of + the copyright owner. For the purposes of this definition, "submitted" + means any form of electronic, verbal, or written communication sent + to the Licensor or its representatives, including but not limited to + communication on electronic mailing lists, source code control systems, + and issue tracking systems that are managed by, or on behalf of, the + Licensor for the purpose of discussing and improving the Work, but + excluding communication that is conspicuously marked or otherwise + designated in writing by the copyright owner as "Not a Contribution." + + "Contributor" shall mean Licensor and any individual or Legal Entity + on behalf of whom a Contribution has been received by Licensor and + subsequently incorporated within the Work. + +2. Grant of Copyright License. Subject to the terms and conditions of + this License, each Contributor hereby grants to You a perpetual, + worldwide, non-exclusive, no-charge, royalty-free, irrevocable + copyright license to reproduce, prepare Derivative Works of, + publicly display, publicly perform, sublicense, and distribute the + Work and such Derivative Works in Source or Object form. + +3. Grant of Patent License. Subject to the terms and conditions of + this License, each Contributor hereby grants to You a perpetual, + worldwide, non-exclusive, no-charge, royalty-free, irrevocable + (except as stated in this section) patent license to make, have made, + use, offer to sell, sell, import, and otherwise transfer the Work, + where such license applies only to those patent claims licensable + by such Contributor that are necessarily infringed by their + Contribution(s) alone or by combination of their Contribution(s) + with the Work to which such Contribution(s) was submitted. If You + institute patent litigation against any entity (including a + cross-claim or counterclaim in a lawsuit) alleging that the Work + or a Contribution incorporated within the Work constitutes direct + or contributory patent infringement, then any patent licenses + granted to You under this License for that Work shall terminate + as of the date such litigation is filed. + +4. Redistribution. You may reproduce and distribute copies of the + Work or Derivative Works thereof in any medium, with or without + modifications, and in Source or Object form, provided that You + meet the following conditions: + + (a) You must give any other recipients of the Work or + Derivative Works a copy of this License; and + + (b) You must cause any modified files to carry prominent notices + stating that You changed the files; and + + (c) You must retain, in the Source form of any Derivative Works + that You distribute, all copyright, patent, trademark, and + attribution notices from the Source form of the Work, + excluding those notices that do not pertain to any part of + the Derivative Works; and + + (d) If the Work includes a "NOTICE" text file as part of its + distribution, then any Derivative Works that You distribute must + include a readable copy of the attribution notices contained + within such NOTICE file, excluding those notices that do not + pertain to any part of the Derivative Works, in at least one + of the following places: within a NOTICE text file distributed + as part of the Derivative Works; within the Source form or + documentation, if provided along with the Derivative Works; or, + within a display generated by the Derivative Works, if and + wherever such third-party notices normally appear. The contents + of the NOTICE file are for informational purposes only and + do not modify the License. You may add Your own attribution + notices within Derivative Works that You distribute, alongside + or as an addendum to the NOTICE text from the Work, provided + that such additional attribution notices cannot be construed + as modifying the License. + + You may add Your own copyright statement to Your modifications and + may provide additional or different license terms and conditions + for use, reproduction, or distribution of Your modifications, or + for any such Derivative Works as a whole, provided Your use, + reproduction, and distribution of the Work otherwise complies with + the conditions stated in this License. + +5. Submission of Contributions. Unless You explicitly state otherwise, + any Contribution intentionally submitted for inclusion in the Work + by You to the Licensor shall be under the terms and conditions of + this License, without any additional terms or conditions. + Notwithstanding the above, nothing herein shall supersede or modify + the terms of any separate license agreement you may have executed + with Licensor regarding such Contributions. + +6. Trademarks. This License does not grant permission to use the trade + names, trademarks, service marks, or product names of the Licensor, + except as required for reasonable and customary use in describing the + origin of the Work and reproducing the content of the NOTICE file. + +7. Disclaimer of Warranty. Unless required by applicable law or + agreed to in writing, Licensor provides the Work (and each + Contributor provides its Contributions) on an "AS IS" BASIS, + WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or + implied, including, without limitation, any warranties or conditions + of TITLE, NON-INFRINGEMENT, MERCHANTABILITY, or FITNESS FOR A + PARTICULAR PURPOSE. You are solely responsible for determining the + appropriateness of using or redistributing the Work and assume any + risks associated with Your exercise of permissions under this License. + +8. Limitation of Liability. In no event and under no legal theory, + whether in tort (including negligence), contract, or otherwise, + unless required by applicable law (such as deliberate and grossly + negligent acts) or agreed to in writing, shall any Contributor be + liable to You for damages, including any direct, indirect, special, + incidental, or consequential damages of any character arising as a + result of this License or out of the use or inability to use the + Work (including but not limited to damages for loss of goodwill, + work stoppage, computer failure or malfunction, or any and all + other commercial damages or losses), even if such Contributor + has been advised of the possibility of such damages. + +9. Accepting Warranty or Additional Liability. While redistributing + the Work or Derivative Works thereof, You may choose to offer, + and charge a fee for, acceptance of support, warranty, indemnity, + or other liability obligations and/or rights consistent with this + License. However, in accepting such obligations, You may act only + on Your own behalf and on Your sole responsibility, not on behalf + of any other Contributor, and only if You agree to indemnify, + defend, and hold each Contributor harmless for any liability + incurred by, or claims asserted against, such Contributor by reason + of your accepting any such warranty or additional liability. + +END OF TERMS AND CONDITIONS + +APPENDIX: How to apply the Apache License to your work. + + To apply the Apache License to your work, attach the following + boilerplate notice, with the fields enclosed by brackets "[]" + replaced with your own identifying information. (Don't include + the brackets!) The text should be enclosed in the appropriate + comment syntax for the file format. We also recommend that a + file or class name and description of purpose be included on the + same "printed page" as the copyright notice for easier + identification within third-party archives. + +Copyright [yyyy] [name of copyright owner] + +Licensed under the Apache License, Version 2.0 (the "License"); +you may not use this file except in compliance with the License. +You may obtain a copy of the License at + + http://www.apache.org/licenses/LICENSE-2.0 + +Unless required by applicable law or agreed to in writing, software +distributed under the License is distributed on an "AS IS" BASIS, +WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +See the License for the specific language governing permissions and +limitations under the License. diff --git a/samply-markers/LICENSE-MIT b/samply-markers/LICENSE-MIT new file mode 100644 index 000000000..6a96dd571 --- /dev/null +++ b/samply-markers/LICENSE-MIT @@ -0,0 +1,25 @@ +Copyright (c) 2025 the samply authors + +Permission is hereby granted, free of charge, to any +person obtaining a copy of this software and associated +documentation files (the "Software"), to deal in the +Software without restriction, including without +limitation the rights to use, copy, modify, merge, +publish, distribute, sublicense, and/or sell copies of +the Software, and to permit persons to whom the Software +is furnished to do so, subject to the following +conditions: + +The above copyright notice and this permission notice +shall be included in all copies or substantial portions +of the Software. + +THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF +ANY KIND, EXPRESS OR IMPLIED, INCLUDING BUT NOT LIMITED +TO THE WARRANTIES OF MERCHANTABILITY, FITNESS FOR A +PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT +SHALL THE AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY +CLAIM, DAMAGES OR OTHER LIABILITY, WHETHER IN AN ACTION +OF CONTRACT, TORT OR OTHERWISE, ARISING FROM, OUT OF OR +IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER +DEALINGS IN THE SOFTWARE. diff --git a/samply-markers/README.md b/samply-markers/README.md new file mode 100644 index 000000000..f427c5c79 --- /dev/null +++ b/samply-markers/README.md @@ -0,0 +1,377 @@ +# Samply Markers + +Emit profiler markers that [samply] records and displays in the [Firefox Profiler] UI. + +## Quick Demo + +The following Fibonacci Sequence example demonstrates recursive function call tracking. + +The [`samply_measure!`] macro emits an interval marker +for each recursive call, allowing the profiler to display the complete call tree with timing information for every `fib(n)` invocation. + +**[macOS][fib-profile-macos] | [Ubuntu][fib-profile-ubuntu] | Windows (not yet supported)** + +```rust +use samply_markers::prelude::*; + +use std::thread::sleep; +use std::time::Duration; + +fn fib(n: u64) -> u64 { + samply_measure!({ + match n { + 0 | 1 => { + sleep(Duration::from_millis(10)); + n + }, + _ => fib(n - 1) + fib(n - 2), + } + }, marker: { + name: format!("fib({n})"), + }) +} + +fn main() { + let n = 12; + let value = fib(n); + println!("fib({n}) = {}", value); +} +``` + +## Project Configuration + +
**1)** Add [samply-markers] as a dependency to your project's `Cargo.toml`. + +```toml +[dependencies] +samply-markers = "{version}" +``` + +
**2)** Add a `samply-markers` feature flag to your project's `Cargo.toml`. + +> [!NOTE] +> Samply markers are designed to no-op by default, so they must be explicitly enabled in order +> to see them in profiles. +> +> * Using [samply-markers] has effectively zero cost when not enabled. +> * Using [samply-markers] does not pull in any additional dependencies when not enabled. + +```toml +[features] +samply-markers = ["samply-markers/enabled"] +``` + +
**3)** Add a `profiling` profile to your project's `Cargo.toml`. + +> [!NOTE] +> This step is optional, but highly recommended for profiling with [samply]. + +```toml +[profile.profiling] +inherits = "release" +debug = true +``` + +
**4)** Build your project for profiling, then record the resulting binary with [samply] to process the emitted markers. + +```text +cargo build --profile profiling --features samply-markers +samply record target/profiling/{binary} +``` + +## Public API + +### The [`samply_marker!`] macro + +The [`samply_marker!`] macro is the foundational way to emit profiler markers. +It creates and emits a [`SamplyMarker`] at the current location in your code, +supporting both instant markers (a single point in time) and interval markers (a span of time). + +#### Instant Marker + +An instant marker marks a specific point in time: + +```rust +use samply_markers::prelude::*; + +fn process_request(request_id: u32) { + // Emit an instant marker at this exact moment + samply_marker!({ name: format!("processing request {request_id}") }); + + // ... process the request. +} +``` + +#### Interval Marker + +An interval marker spans from a start time to the current time using [`SamplyTimestamp`]: + +```rust +use samply_markers::prelude::*; + +fn query_database(query: &str) -> Vec { + let start = SamplyTimestamp::now(); + + // ... execute the database query. + let results = vec![]; // Placeholder for actual results. + + // Emit an interval marker from start to now. + samply_marker!({ + name: format!("database query: {query}"), + start_time: start, + }); + + results +} +``` + +--- + +### The [`samply_timer!`] macro + +While [`samply_marker!`] requires manually providing a +[`SamplyTimestamp`] for interval markers, +the [`samply_timer!`] macro simplifies this pattern +by wrapping the timestamp in a scoped RAII object. It creates a [`SamplyTimer`] +that registers the time it was created and automatically emits the interval marker when dropped at the end of its scope. + +#### Automatic Interval + +The interval marker emits when the timer is dropped: + +```rust +use samply_markers::prelude::*; + +fn expensive_computation() { + let _timer = samply_timer!({ name: "expensive computation" }); + + // ... perform expensive work. + + // The interval marker is automatically emitted here when _timer is dropped. +} +``` + +#### Early Emit + +You can explicitly emit the interval marker before the end of the scope: + +```rust +use samply_markers::prelude::*; + +fn process_with_cleanup() { + let timer = samply_timer!({ name: "core processing" }); + + // ... perform core processing work. + + // Emit the interval marker now, excluding cleanup from the measurement. + timer.emit(); + + // ... perform cleanup tasks (not included in the interval marker). + + // The interval marker will not emit a second time when dropped. +} +``` + +--- + +### The [`samply_measure!`] macro + +Building on the scoped approach of [`samply_timer!`], +the [`samply_measure!`] macro further simplifies profiling +by eliminating the need to create a scoped timer yourself. Instead, you wrap a code block, then its execution time is automatically measured with an interval marker. + +#### Measure Synchronous Code + +The value of the measured block expression is preserved: + +```rust +use samply_markers::prelude::*; + +fn compute_sum(values: &[i32]) -> i32 { + samply_measure!({ + values.iter().sum() + }, marker: { + name: "compute sum", + }) +} + +let values = vec![1, 2, 3, 4, 5]; +let result = compute_sum(&values); +assert_eq!(result, 15); +``` + +#### With `?` Operator + +The block's control flow is preserved, including early returns: + +```rust +use samply_markers::prelude::*; + +fn parse_and_validate(data: &str) -> Result { + samply_measure!({ + let parsed = data.parse::() + .map_err(|e| format!("parse error: {e}"))?; + + if parsed > 100 { + return Err(String::from("value too large")); + } + + Ok(parsed) + }, marker: { + name: "parse and validate", + }) +} +``` + +#### Measure Asynchronous Code + +The macro works the same within asynchronous code. However, the clock does not stop between polls. +The resulting interval will span the total time to completion, including time spent waiting: + +```rust +use samply_markers::prelude::*; + +async fn fetch_data() -> String { + String::from("data") +} + +async fn process_data(data_id: u64) -> String { + samply_measure!({ + let data = fetch_data().await; + format!("Processed: {data} (id: {data_id})") + }, marker: { + name: format!("process data {data_id}"), + }) +} +``` + +#### Create a New Async Block + +Use the `async` keyword to create a new async block, which allows the `?` +operator to return from this measured block instead of the enclosing function: + +```rust +use samply_markers::prelude::*; + +async fn read_file(path: &str) -> Option { + Some(String::from("100,200")) +} + +async fn load_config(path: &str) -> (u32, u32) { + let config = samply_measure!(async { + let contents = read_file(path).await?; + let mut parts = contents.split(','); + + let x = parts.next()?.parse::().ok()?; + let y = parts.next()?.parse::().ok()?; + + Some((x, y)) + }, marker: { + name: "load config", + }) + .await; + + config.unwrap_or((0, 0)) +} +``` + +## Example + +Here's a complete example demonstrating everything in context: + +> [!NOTE] +> See the [examples directory] to build, run, and profile the examples in this README yourself. + + +**[macOS] | [Ubuntu] | Windows (not yet supported)** + +```rust +use samply_markers::prelude::*; + +async fn fetch_url(url: &str) -> (String, Option) { + // Emit an interval marker for the time it takes to fetch. + let result = samply_measure!(async { + let response = reqwest::get(url).await?; + response.text().await + }, marker: { + name: format!("fetch {url}"), + }) + .await; + + match result { + Ok(content) => { + println!(" ✓ Fetched {url} ({} bytes)", content.len()); + (String::from(url), Some(content)) + } + Err(error) => { + // Emit an instant marker any time a fetch fails. + samply_marker!({ name: format!("fetch failed: {url}") }); + println!(" ✗ Failed to fetch {url}: {error}"); + (String::from(url), None) + } + } +} + +#[tokio::main] +async fn main() { + // Create a timer that will span the entirety of main(). + // The timer will emit an interval marker when it is dropped at the end of the scope. + let _main_timer = samply_timer!({ name: "main()" }); + + println!("\nStarting samply-markers demo...\n"); + + std::thread::sleep(std::time::Duration::from_millis(200)); + + let urls = &[ + "https://example.com", + "https://fail.invalid", + "https://fail.invalid", + "https://en.wikipedia.org/wiki/Firefox", + "https://fail.invalid", + "https://github.com/nordzilla", + ]; + + println!("\n=== Sequential Fetching ===\n"); + + // Emit an interval marker for the total time to fetch all URLs sequentially. + samply_measure!({ + for url in urls { + fetch_url(url).await; + } + }, marker: { + name: "fetch all URLs sequentially", + }); + + std::thread::sleep(std::time::Duration::from_millis(200)); + + println!("\n=== Concurrent Fetching ===\n"); + + // Emit an interval marker for the total time to fetch all URLs concurrently. + samply_measure!({ + futures::future::join_all( + urls.iter().map(|url| fetch_url(url)) + ).await; + }, marker: { + name: "fetch all URLs concurrently", + }); + + std::thread::sleep(std::time::Duration::from_millis(200)); + + println!("\nDemo completed!\n"); +} +``` + +[`samply_marker!`]: https://docs.rs/samply-markers/latest/samply_markers/macro.samply_marker.html +[`samply_measure!`]: https://docs.rs/samply-markers/latest/samply_markers/macro.samply_measure.html +[`samply_timer!`]: https://docs.rs/samply-markers/latest/samply_markers/macro.samply_timer.html +[`SamplyMarker`]: https://docs.rs/samply-markers/latest/samply_markers/marker/struct.SamplyMarker.html +[`SamplyTimer`]: https://docs.rs/samply-markers/latest/samply_markers/marker/struct.SamplyTimer.html +[`SamplyTimestamp`]: https://docs.rs/samply-markers/latest/samply_markers/marker/struct.SamplyTimestamp.html +[examples directory]: https://github.com/mstange/samply/tree/main/samply-markers/examples +[fib-profile-macos]: https://share.firefox.dev/4oMKHtT +[fib-profile-ubuntu]: https://share.firefox.dev/4o3wur4 +[Firefox Profiler]: https://profiler.firefox.com/ +[macOS]: https://share.firefox.dev/48eHTj8 +[samply]: https://github.com/mstange/samply?tab=readme-ov-file#samply +[samply-markers]: https://crates.io/crates/samply-markers +[Ubuntu]: https://share.firefox.dev/3LzT6lJ diff --git a/samply-markers/examples/01_fibonacci.rs b/samply-markers/examples/01_fibonacci.rs new file mode 100644 index 000000000..77f6bbf09 --- /dev/null +++ b/samply-markers/examples/01_fibonacci.rs @@ -0,0 +1,24 @@ +use samply_markers::prelude::*; + +use std::thread::sleep; +use std::time::Duration; + +fn fib(n: u64) -> u64 { + samply_measure!({ + match n { + 0 | 1 => { + sleep(Duration::from_millis(10)); + n + }, + _ => fib(n - 1) + fib(n - 2), + } + }, marker: { + name: format!("fib({n})"), + }) +} + +fn main() { + let n = 12; + let value = fib(n); + println!("fib({n}) = {}", value); +} diff --git a/samply-markers/examples/02_network_requests.rs b/samply-markers/examples/02_network_requests.rs new file mode 100644 index 000000000..cb3466cfd --- /dev/null +++ b/samply-markers/examples/02_network_requests.rs @@ -0,0 +1,73 @@ +use samply_markers::prelude::*; + +async fn fetch_url(url: &str) -> (String, Option) { + // Emit an interval marker for the time it takes to fetch. + let result = samply_measure!(async { + let response = reqwest::get(url).await?; + response.text().await + }, marker: { + name: format!("fetch {url}"), + }) + .await; + + match result { + Ok(content) => { + println!(" ✓ Fetched {url} ({} bytes)", content.len()); + (String::from(url), Some(content)) + } + Err(error) => { + // Emit an instant marker any time a fetch fails. + samply_marker!({ name: format!("fetch failed: {url}") }); + println!(" ✗ Failed to fetch {url}: {error}"); + (String::from(url), None) + } + } +} + +#[tokio::main] +async fn main() { + // Create a timer that will span the entirety of main(). + // The timer will emit an interval marker when it is dropped at the end of the scope. + let _main_timer = samply_timer!({ name: "main()" }); + + println!("\nStarting samply-markers demo...\n"); + + std::thread::sleep(std::time::Duration::from_millis(200)); + + let urls = &[ + "https://example.com", + "https://fail.invalid", + "https://fail.invalid", + "https://en.wikipedia.org/wiki/Firefox", + "https://fail.invalid", + "https://github.com/nordzilla", + ]; + + println!("\n=== Sequential Fetching ===\n"); + + // Emit an interval marker for the total time to fetch all URLs sequentially. + samply_measure!({ + for url in urls { + fetch_url(url).await; + } + }, marker: { + name: "fetch all URLs sequentially", + }); + + std::thread::sleep(std::time::Duration::from_millis(200)); + + println!("\n=== Concurrent Fetching ===\n"); + + // Emit an interval marker for the total time to fetch all URLs concurrently. + samply_measure!({ + futures::future::join_all( + urls.iter().map(|url| fetch_url(url)) + ).await; + }, marker: { + name: "fetch all URLs concurrently", + }); + + std::thread::sleep(std::time::Duration::from_millis(200)); + + println!("\nDemo completed!\n"); +} diff --git a/samply-markers/examples/03_tokio_task_migration.rs b/samply-markers/examples/03_tokio_task_migration.rs new file mode 100644 index 000000000..ef2268294 --- /dev/null +++ b/samply-markers/examples/03_tokio_task_migration.rs @@ -0,0 +1,55 @@ +use samply_markers::prelude::*; +use tokio::time::{Duration, sleep}; + +async fn migrating_task(task_id: usize, iterations: usize) { + for i in 0..iterations { + samply_measure!(async { + samply_marker!({ name: format!("task({task_id}): iteration {i} start") }); + + sleep(Duration::from_micros(100)).await; + + let mut sum = 0u64; + for j in 0..10_000 { + sum = sum.wrapping_add(j); + } + + sleep(Duration::from_micros(100)).await; + }, marker: { + name: format!("task {task_id} iter {i}"), + }) + .await; + + // Yield to encourage task migration. + tokio::task::yield_now().await; + } +} + +#[tokio::main(flavor = "multi_thread", worker_threads = 10)] +async fn main() { + let _main_timer = samply_timer!({ name: "main()" }); + + println!("\n=== Tokio Task Migration Demo ===\n"); + println!("This example spawns async tasks on a multi-threaded runtime."); + println!("Tasks will migrate between worker threads during execution."); + + let num_tasks = 8; + let iterations_per_task = 20; + + samply_marker!({ name: "spawning tasks" }); + + let handles = (0..num_tasks) + .map(|task_id| { + tokio::spawn(async move { migrating_task(task_id, iterations_per_task).await }) + }) + .collect::>(); + + samply_marker!({ name: "all tasks spawned" }); + + samply_measure!({ + futures::future::join_all(handles).await + }, marker: { + name: "waiting for all tasks", + }); + + println!("\nAll tasks completed!"); +} diff --git a/samply-markers/examples/04_parallel_computation.rs b/samply-markers/examples/04_parallel_computation.rs new file mode 100644 index 000000000..ba2df24c1 --- /dev/null +++ b/samply-markers/examples/04_parallel_computation.rs @@ -0,0 +1,151 @@ +use rayon::{ThreadPoolBuilder, prelude::*}; +use samply_markers::prelude::*; +use std::{collections::HashSet, time::Duration}; + +fn contains_digit(mut value: u32, digit: u32) -> bool { + if value == 0 { + return digit == 0; + } + + while value > 0 { + if value % 10 == digit { + return true; + } + value /= 10; + } + + false +} + +fn filter_numbers_with_digit( + chunk_id: usize, + numbers: &[u32], + digit: u32, + parallel_filters: bool, +) -> Vec { + let mode = if parallel_filters { + "parallel" + } else { + "sequential" + }; + + samply_measure!({ + if parallel_filters { + numbers + .par_iter() + .filter(|&&n| contains_digit(n, digit)) + .cloned() + .collect() + } else { + numbers + .iter() + .filter(|&&n| contains_digit(n, digit)) + .cloned() + .collect() + } + }, marker: { + name: format!("chunk {chunk_id} filter digit {digit} ({mode})"), + }) +} + +fn symmetric_difference_sum(chunk_id: usize, twos: &[u32], fives: &[u32]) -> u64 { + samply_measure!({ + let two_set: HashSet = twos.iter().copied().collect(); + let five_set: HashSet = fives.iter().copied().collect(); + + let only_twos: u64 = two_set + .difference(&five_set) + .map(|&value| value as u64) + .sum(); + let only_fives: u64 = five_set + .difference(&two_set) + .map(|&value| value as u64) + .sum(); + + only_twos + only_fives + }, marker: { + name: format!("chunk {chunk_id} symmetric diff"), + }) +} + +fn process_chunk_pipeline(chunk_id: usize, numbers: &[u32], parallel_filters: bool) -> u64 { + let _chunk_timer = samply_timer!({ name: format!("chunk {chunk_id} pipeline") }); + + let twos = filter_numbers_with_digit(chunk_id, numbers, 2, parallel_filters); + let fives = filter_numbers_with_digit(chunk_id, numbers, 5, parallel_filters); + + symmetric_difference_sum(chunk_id, &twos, &fives) +} + +fn generate_chunks(chunk_count: usize, chunk_len: usize) -> Vec> { + let mut seed = 0u64; + + (0..chunk_count) + .map(|_| { + let mut values = Vec::with_capacity(chunk_len); + for _ in 0..chunk_len { + seed = seed.wrapping_mul(1_664_525).wrapping_add(1_013_904_223); + values.push((seed % 1_000_000) as u32); + } + values + }) + .collect() +} + +fn main() { + let _main_timer = samply_timer!({ name: "main()" }); + + ThreadPoolBuilder::new() + .num_threads(8) + .build_global() + .expect("Failed to configure Rayon thread pool"); + + println!("\n=== Digit Symmetric Difference Demo ===\n"); + + let chunk_count = 32; + let chunk_len = 131072; + let chunks = generate_chunks(chunk_count, chunk_len); + + println!( + "Generated {} chunks with {} numbers each ({} total)\n", + chunk_count, + chunk_len, + chunk_count * chunk_len + ); + + println!("=== Sequential Processing ==="); + let sequential_results: Vec<_> = samply_measure!({ + chunks + .iter() + .enumerate() + .map(|(i, chunk)| process_chunk_pipeline(i, chunk, false)) + .collect() + }, marker: { + name: "sequential pass", + }); + let sequential_total: u64 = sequential_results.iter().sum(); + println!( + "Sequential: {} chunks processed | total symmetric diff sum {}\n", + sequential_results.len(), + sequential_total + ); + + std::thread::sleep(Duration::from_millis(20)); + + println!("=== Parallel Processing (Rayon) ==="); + let parallel_results: Vec<_> = samply_measure!({ + chunks + .par_iter() + .enumerate() + .map(|(i, chunk)| process_chunk_pipeline(i + chunk_count, chunk, true)) + .collect() + }, marker: { + name: "parallel pass", + }); + let parallel_total: u64 = parallel_results.iter().sum(); + println!( + "Parallel: {} chunks processed | total symmetric diff sum {}\n", + parallel_results.len(), + parallel_total + ); +} diff --git a/samply-markers/examples/README.md b/samply-markers/examples/README.md new file mode 100644 index 000000000..be1fb0edb --- /dev/null +++ b/samply-markers/examples/README.md @@ -0,0 +1,111 @@ +# Samply Markers Examples + +This directory contains runnable examples demonstrating the `samply-markers` crate. + +> [!NOTE] +> These commands work from any directory in the workspace. The `target` directory is always at the workspace root. + +## Examples + +### 01) Fibonacci + +Demonstrates recursive function-call tracing of the [Fibonacci Sequence]. + +**[macOS][01-fib-example-macos] | [Ubuntu][01-fib-example-ubuntu] | Windows (not yet supported)** + +```bash +# Build samply +cargo build --release -p samply + +# Build the example +cargo build -p samply-markers --example 01_fibonacci --profile profiling --features enabled + +# Profile +TARGET=$(cargo metadata --format-version 1 | jq -r '.target_directory') +$TARGET/release/samply record $TARGET/profiling/examples/01_fibonacci +``` + +--- + +### 02) Network Requests + +Demonstrates sequential vs. parallel async network requests with [reqwest]. + +**[macOS][02-network-example-macos] | [Ubuntu][02-network-example-ubuntu] | Windows (not yet supported)** + +```bash +# Build samply +cargo build --release -p samply + +# Build the example +cargo build -p samply-markers --example 02_network_requests --profile profiling --features enabled + +# Profile +TARGET=$(cargo metadata --format-version 1 | jq -r '.target_directory') +$TARGET/release/samply record $TARGET/profiling/examples/02_network_requests +``` + +--- + +### 03) Tokio Task Migration + +Demonstrates async task migration across worker threads in a multi-threaded [tokio] runtime. + +**[macOS][03-tokio-example-macos] | [Ubuntu][03-tokio-example-ubuntu] | Windows (not yet supported)** + +```bash +# Build samply +cargo build --release -p samply + +# Build the example +cargo build -p samply-markers --example 03_tokio_task_migration --profile profiling --features enabled + +# Profile +TARGET=$(cargo metadata --format-version 1 | jq -r '.target_directory') +$TARGET/release/samply record $TARGET/profiling/examples/03_tokio_task_migration +``` + +--- + +### 04) Parallel Computation + +Demonstrates sequential vs. parallel computation using [rayon]. + +**[macOS][04-parallel-example-macos] | [Ubuntu][04-parallel-example-ubuntu] | Windows (not yet supported)** + +> [!IMPORTANT] +> This example isn't working correctly with the current FlushOnDrop implemenation. +> Rayon's threads live forever, so the per-thread buffers never flush to their files. +> +> This example works fine if you force a flush on write, but that is quite slow. +> +> I'm going to have to revisit the per-thread writing strategy to cover this case. + + +```bash +# Build samply +cargo build --release -p samply + +# Build the example +cargo build -p samply-markers --example 04_parallel_computation --profile profiling --features enabled + +# Profile +TARGET=$(cargo metadata --format-version 1 | jq -r '.target_directory') +$TARGET/release/samply record $TARGET/profiling/examples/04_parallel_computation +``` + +[01-fib-example-macos]: https://share.firefox.dev/4oMKHtT +[01-fib-example-ubuntu]: https://share.firefox.dev/4o3wur4 +[02-network-example-macos]: https://share.firefox.dev/48eHTj8 +[02-network-example-ubuntu]: https://share.firefox.dev/3LzT6lJ +[03-tokio-example-macos]: https://share.firefox.dev/3X3Wl7k +[03-tokio-example-ubuntu]: https://share.firefox.dev/43vXgB9 +[04-parallel-example-macos]: https://share.firefox.dev/4iabqhw +[04-parallel-example-ubuntu]: https://share.firefox.dev/4oSvBDe +[jq]: https://jqlang.github.io/jq/ +[cargo metadata]: https://doc.rust-lang.org/cargo/commands/cargo-metadata.html +[Fibonacci Sequence]: https://en.wikipedia.org/wiki/Fibonacci_sequence +[rayon]: https://crates.io/crates/rayon +[reqwest]: https://crates.io/crates/reqwest +[samply]: https://github.com/mstange/samply?tab=readme-ov-file#samply +[tokio]: https://crates.io/crates/tokio diff --git a/samply-markers/src/lib.rs b/samply-markers/src/lib.rs new file mode 100644 index 000000000..fd2857c2c --- /dev/null +++ b/samply-markers/src/lib.rs @@ -0,0 +1,403 @@ +#![warn(missing_docs)] + +//! # Samply Markers +//! +//! Emit profiler markers that [samply] records and displays in the [Firefox Profiler](https://profiler.firefox.com/) UI. +//! +//!
+//! +//! ## Quick Demo +//! +//!
+//! +//! The following Fibonacci Sequence example demonstrates recursive function call tracking. +//! +//! The [`samply_measure!`](crate::samply_measure) macro emits an interval marker for each recursive call, +//! allowing the profiler to display the complete call tree with timing information for every `fib(n)` invocation. +//! +//! **[macOS](https://share.firefox.dev/4oMKHtT) | +//! [Ubuntu](https://share.firefox.dev/4o3wur4) | +//! Windows (not yet supported)** +//! +//! ```rust,no_run +//! use samply_markers::prelude::*; +//! +//! use std::time::Duration; +//! use std::thread::sleep; +//! +//! fn fib(n: u64) -> u64 { +//! samply_measure!({ +//! match n { +//! 0 | 1 => { +//! sleep(Duration::from_millis(10)); +//! n +//! }, +//! _ => fib(n - 1) + fib(n - 2), +//! } +//! }, marker: { +//! name: format!("fib({n})"), +//! }) +//! } +//! +//! fn main() { +//! let n = 12; +//! let value = fib(n); +//! println!("fib({n}) = {}", value); +//! } +//! ``` +//! +//!
+//! +//! ## Project Configuration +//! +//!
**1)** Add [samply-markers](crate) as a dependency to your project's `Cargo.toml`. +//! +//! ```toml +//! [dependencies] +//! samply-markers = "{version}" +//! ``` +//! +//!
**2)** Add a `samply-markers` feature flag to your project's `Cargo.toml`. +//! +//! > Samply markers are designed to no-op by default, so they must be explicitly enabled in order +//! > to see them in profiles. +//! > +//! > * Using [samply-markers](crate) has effectively zero cost when not enabled. +//! > * Using [samply-markers](crate) does not pull in any additional dependencies when not enabled. +//! +//! ```toml +//! [features] +//! samply-markers = ["samply-markers/enabled"] +//! ``` +//! +//!
**3)** Add a `profiling` profile to your project's `Cargo.toml`. +//! +//! * This step is optional, but highly recommended for profiling with [samply]. +//! +//! ```toml +//! [profile.profiling] +//! inherits = "release" +//! debug = true +//! ``` +//! +//!
**4)** Build your project for profiling, then record the resulting binary with [samply] to process the emitted markers. +//! +//! ```text +//! cargo build --release -p samply +//! cargo build --profile profiling --features samply-markers +//! samply record target/profiling/{binary} +//! ``` +//! +//!
+//! +//! ## Public API +//! +//! +//! #### The [`samply_marker!`](crate::samply_marker) macro +//! +//!
+//! +//! The [`samply_marker!`](crate::samply_marker) macro is the foundational way to emit profiler markers. +//! It creates and emits a [`SamplyMarker`](marker::SamplyMarker) at the current location in your code, +//! supporting both instant markers (a single point in time) and interval markers (a span of time). +//! +//! ##### Instant Marker +//! +//! An instant marker marks a specific point in time: +//! +//! ```rust +//! # use samply_markers::prelude::*; +//! fn process_request(request_id: u32) { +//! // Emit an instant marker at this exact moment +//! samply_marker!({ name: format!("processing request {request_id}") }); +//! +//! // ... process the request. +//! } +//! ``` +//! +//! ##### Interval Marker +//! +//! An interval marker spans from a start time to the current time using [`SamplyTimestamp`](marker::SamplyTimestamp): +//! +//! ```rust +//! # use samply_markers::prelude::*; +//! fn query_database(query: &str) -> Vec { +//! let start = SamplyTimestamp::now(); +//! +//! // ... execute the database query. +//! let results = vec![]; // Placeholder for actual results. +//! +//! // Emit an interval marker from start to now. +//! samply_marker!({ +//! name: format!("database query: {query}"), +//! start_time: start, +//! }); +//! +//! results +//! } +//! ``` +//! +//!
+//! +//! --- +//! +//!
+//! +//! #### The [`samply_timer!`](crate::samply_timer) macro +//! +//!
+//! +//! While [`samply_marker!`](crate::samply_marker) requires manually providing a [`SamplyTimestamp`](marker::SamplyTimestamp) +//! for interval markers, the [`samply_timer!`](crate::samply_timer) macro simplifies this pattern by wrapping the timestamp in a scoped RAII object. +//! It creates a [`SamplyTimer`](marker::SamplyTimer) that registers the time it was created and automatically emits the interval marker when dropped at the end of its scope. +//! +//! ##### Automatic Interval +//! +//! The interval marker emits when the timer is dropped: +//! +//! ```rust +//! # use samply_markers::prelude::*; +//! fn expensive_computation() { +//! let _timer = samply_timer!({ name: "expensive computation" }); +//! +//! // ... perform expensive work. +//! +//! // The interval marker is automatically emitted here when _timer is dropped. +//! } +//! ``` +//! +//! ##### Early Emit +//! +//! You can explicitly emit the interval marker before the end of the scope: +//! +//! ```rust +//! # use samply_markers::prelude::*; +//! fn process_with_cleanup() { +//! let timer = samply_timer!({ name: "core processing" }); +//! +//! // ... perform core processing work. +//! +//! // Emit the interval marker now, excluding cleanup from the measurement. +//! timer.emit(); +//! +//! // ... perform cleanup tasks (not included in the interval marker). +//! +//! // The interval marker will not emit a second time when dropped. +//! } +//! ``` +//! +//!
+//! +//! --- +//! +//!
+//! +//! #### The [`samply_measure!`](crate::samply_measure) macro +//! +//!
+//! +//! Building on the scoped approach of [`samply_timer!`](crate::samply_timer), the [`samply_measure!`](crate::samply_measure) macro further simplifies profiling +//! by eliminating the need to create a scoped timer yourself. Instead, you wrap a code block, then its execution time is automatically measured with an interval marker. +//! +//! ##### Measure Synchronous Code +//! +//! The value of the measured block expression is preserved: +//! +//! ```rust +//! # use samply_markers::prelude::*; +//! fn compute_sum(values: &[i32]) -> i32 { +//! samply_measure!({ +//! values.iter().sum() +//! }, marker: { +//! name: "compute sum", +//! }) +//! } +//! +//! let values = vec![1, 2, 3, 4, 5]; +//! let result = compute_sum(&values); +//! assert_eq!(result, 15); +//! ``` +//! +//! ##### With `?` Operator +//! +//! The block's control flow is preserved, including early returns: +//! +//! ```rust +//! # use samply_markers::prelude::*; +//! fn parse_and_validate(data: &str) -> Result { +//! samply_measure!({ +//! let parsed = data.parse::() +//! .map_err(|e| format!("parse error: {e}"))?; +//! +//! if parsed > 100 { +//! return Err(String::from("value too large")); +//! } +//! +//! Ok(parsed) +//! }, marker: { +//! name: "parse and validate", +//! }) +//! } +//! ``` +//! +//! ##### Measure Asynchronous Code +//! +//! The macro works the same within asynchronous code. However, the clock does not stop between polls. +//! The resulting interval will span the total time to completion, including time spent waiting: +//! +//! ```rust +//! # use samply_markers::prelude::*; +//! # async fn fetch_data() -> String { +//! # String::from("data") +//! # } +//! async fn process_data(data_id: u64) -> String { +//! samply_measure!({ +//! let data = fetch_data().await; +//! format!("Processed: {data} (id: {data_id})") +//! }, marker: { +//! name: format!("process data {data_id}"), +//! }) +//! } +//! ``` +//! +//! ##### Create a New Async Block +//! +//! Use the `async` keyword to create a new async block, which allows the `?` +//! operator to return from the `async` block instead of from the enclosing function: +//! +//! ```rust +//! # use samply_markers::prelude::*; +//! # async fn read_file(path: &str) -> Option { Some(String::from("100,200")) } +//! async fn load_config(path: &str) -> (u32, u32) { +//! let config = samply_measure!(async { +//! let contents = read_file(path).await?; +//! let mut parts = contents.split(','); +//! +//! let x = parts.next()?.parse::().ok()?; +//! let y = parts.next()?.parse::().ok()?; +//! +//! Some((x, y)) +//! }, marker: { +//! name: "load config", +//! }) +//! .await; +//! +//! config.unwrap_or((0, 0)) +//! } +//! ``` +//! +//!
+//! +//! ## Example +//! +//!
+//! +//! Here's a complete example demonstrating everything in context: +//! +//! *See the [examples directory] to build, run, and profile the examples in this README yourself.* +//! +//! **[macOS](https://share.firefox.dev/48eHTj8) | +//! [Ubuntu](https://share.firefox.dev/3LzT6lJ) | +//! Windows (not yet supported)** +//! +//! ```rust,no_run +//! use samply_markers::prelude::*; +//! +//! async fn fetch_url(url: &str) -> (String, Option) { +//! // Emit an interval marker for the time it takes to fetch. +//! let result = samply_measure!(async { +//! let response = reqwest::get(url).await?; +//! response.text().await +//! }, marker: { +//! name: format!("fetch {url}"), +//! }) +//! .await; +//! +//! match result { +//! Ok(content) => { +//! println!(" ✓ Fetched {url} ({} bytes)", content.len()); +//! (String::from(url), Some(content)) +//! } +//! Err(error) => { +//! // Emit an instant marker any time a fetch fails. +//! samply_marker!({ name: format!("fetch failed: {url}") }); +//! println!(" ✗ Failed to fetch {url}: {error}"); +//! (String::from(url), None) +//! } +//! } +//! } +//! +//! #[tokio::main] +//! async fn main() { +//! // Create a timer that will span the entirety of main(). +//! // The timer will emit an interval marker when it is dropped at the end of the scope. +//! let _main_timer = samply_timer!({ name: "main()" }); +//! +//! println!("\nStarting samply-markers demo...\n"); +//! +//! std::thread::sleep(std::time::Duration::from_millis(200)); +//! +//! let urls = &[ +//! "https://example.com", +//! "https://fail.invalid", +//! "https://fail.invalid", +//! "https://en.wikipedia.org/wiki/Firefox", +//! "https://fail.invalid", +//! "https://github.com/nordzilla", +//! ]; +//! +//! println!("\n=== Sequential Fetching ===\n"); +//! +//! // Emit an interval marker for the total time to fetch all URLs sequentially. +//! samply_measure!({ +//! for url in urls { +//! fetch_url(url).await; +//! } +//! }, marker: { +//! name: "fetch all URLs sequentially", +//! }); +//! +//! std::thread::sleep(std::time::Duration::from_millis(200)); +//! +//! println!("\n=== Concurrent Fetching ===\n"); +//! +//! // Emit an interval marker for the total time to fetch all URLs concurrently. +//! samply_measure!({ +//! futures::future::join_all( +//! urls.iter().map(|url| fetch_url(url)) +//! ).await; +//! }, marker: { +//! name: "fetch all URLs concurrently", +//! }); +//! +//! std::thread::sleep(std::time::Duration::from_millis(200)); +//! +//! println!("\nDemo completed!\n"); +//! } +//! ``` +//! +//! [samply]: https://github.com/mstange/samply?tab=readme-ov-file#samply +//! [examples directory]: https://github.com/mstange/samply/tree/main/samply-markers/examples + +mod macros; +mod provider; + +pub mod marker; + +/// This module contains everything needed to add markers within a convenient glob import. +/// +/// ```rust +/// use samply_markers::prelude::*; +/// ``` +pub mod prelude { + pub use crate::marker::SamplyMarker; + pub use crate::marker::SamplyTimer; + pub use crate::marker::SamplyTimestamp; + + #[doc(inline)] + pub use crate::samply_marker; + #[doc(inline)] + pub use crate::samply_measure; + #[doc(inline)] + pub use crate::samply_timer; +} diff --git a/samply-markers/src/macros/mod.rs b/samply-markers/src/macros/mod.rs new file mode 100644 index 000000000..413829112 --- /dev/null +++ b/samply-markers/src/macros/mod.rs @@ -0,0 +1,13 @@ +//! This module defines the macros that ship with [samply-markers](crate). +//! +//! While it's possible to use the marker types directly, the macros provide a nicer experience. +//! +//! [samply-markers](crate) provides three primary macros for instrumenting code: +//! +//! * [`samply_marker!`](crate::samply_marker) - Emits an instant or interval marker at the current location. +//! * [`samply_measure!`](crate::samply_measure) - Measures the timing of a code block, emitting an interval automatically. +//! * [`samply_timer!`](crate::samply_timer) - Creates a scoped marker that emits an interval at the end of the frame. + +mod samply_marker; +mod samply_measure; +mod samply_timer; diff --git a/samply-markers/src/macros/samply_marker.rs b/samply-markers/src/macros/samply_marker.rs new file mode 100644 index 000000000..a61d39ee2 --- /dev/null +++ b/samply-markers/src/macros/samply_marker.rs @@ -0,0 +1,47 @@ +//! This module defines the [`samply_marker!`](crate::samply_marker) macro for emitting markers directly. + +/// Emits a marker at the current location in the code's execution. +/// +/// * Providing only a `name` will emit an instant marker at the current time. +/// * Providing an optional `start_time` will emit an interval marker from `start_time` to now. +/// +/// # Examples +/// +/// ```rust +/// # use samply_markers::prelude::*; +/// # struct Request {} +/// # impl Request { fn id(&self) -> u32 { 0 } } +/// # fn receive_request() -> Request { Request {} } +/// # fn query_database(id: u32) -> Vec { vec![] } +/// # fn serialize_json(data: &[String]) -> String { String::new() } +/// let request = receive_request(); +/// +/// // Emit an instant marker. +/// samply_marker!({ +/// name: format!("received request {}", request.id()), +/// }); +/// +/// // Mark the start time for serializing the response. +/// let start = SamplyTimestamp::now(); +/// +/// let data = query_database(request.id()); +/// let json = serialize_json(&data); +/// +/// // Emit an interval marker. +/// samply_marker!({ +/// name: "serialize response", +/// start_time: start, +/// }); +/// ``` +#[macro_export] +macro_rules! samply_marker { + // Instant marker with only a name. + {{ name: $name:expr $(,)? }} => {{ + $crate::marker::SamplyMarker::new($name).emit_instant(); + }}; + + // Interval marker with a provided start time. + {{ name: $name:expr, start_time: $start_time:expr $(,)? }} => {{ + $crate::marker::SamplyMarker::new($name).emit_interval($start_time); + }}; +} diff --git a/samply-markers/src/macros/samply_measure.rs b/samply-markers/src/macros/samply_measure.rs new file mode 100644 index 000000000..59817cb08 --- /dev/null +++ b/samply-markers/src/macros/samply_measure.rs @@ -0,0 +1,138 @@ +//! This module defines the [`samply_measure!`](crate::samply_measure) macro for measuring code blocks. + +/// Measures the runtime of a block of code by emitting an interval marker. +/// +/// * The interval marker's start time is the beginning of the block. +/// * The interval marker's end time is the end of the block. +/// +/// The block's returned value is preserved by the macro. +/// +/// Supports both synchronous and asynchronous blocks. +/// +/// # Examples +/// +/// #### Synchronous +/// ```rust +/// # use samply_markers::prelude::*; +/// # struct World { entities: Vec } +/// # impl World { +/// # fn new(len: usize) -> Self { Self { entities: vec![1; len] } } +/// # fn simulate_physics(&mut self) {} +/// # fn apply_effects(&mut self) {} +/// # } +/// // Measure the duration of update_world every time it is called. +/// fn update_world(world: &mut World) -> usize { +/// samply_measure!({ +/// world.simulate_physics(); +/// world.apply_effects(); +/// world.entities.len() +/// }, marker: { +/// name: "update world", +/// }) +/// } +/// +/// let mut world = World::new(13); +/// let count = update_world(&mut world); +/// +/// assert_eq!(count, 13); +/// ``` +/// +/// #### Asynchronous +/// +/// ```rust +/// # use samply_markers::prelude::*; +/// # async fn http_get(url: &str) -> Result { Ok(String::from("data")) } +/// # fn parse_response(data: &str) -> Result, ()> { Ok(vec![]) } +/// // Measure the duration of fetch_user_data every time it is called. +/// async fn fetch_user_data(user_id: u64) -> Result, ()> { +/// samply_measure!({ +/// let response = http_get(&format!("/api/users/{user_id}")).await?; +/// parse_response(&response) +/// }, marker: { +/// name: "fetch user data", +/// }) +/// } +/// ``` +/// +/// #### Create a New Async Block +/// +/// Use the `async` keyword to create a new async block, +/// which allows the `?` operator to return from this block instead of the enclosing function. +/// +/// ```rust +/// # use samply_markers::prelude::*; +/// # async fn read_file(path: &str) -> Option { Some(String::from("100,200")) } +/// async fn load_config(path: &str) -> (u32, u32) { +/// let config = samply_measure!(async { +/// let contents = read_file(path).await?; +/// let mut parts = contents.split(','); +/// +/// let x = parts.next()?.parse::().ok()?; +/// let y = parts.next()?.parse::().ok()?; +/// +/// Some((x, y)) +/// }, marker: { +/// name: "load config", +/// }).await; +/// +/// config.unwrap_or((0, 0)) +/// } +/// ``` +/// +/// #### Create a New Async Move Block +/// +/// Use `async move` to transfer ownership of captured variables into the async block. +/// +/// ```rust +/// # use samply_markers::prelude::*; +/// # async fn process_data(data: String) -> usize { data.len() } +/// async fn measure_owned_data() -> usize { +/// let data = String::from("owned data"); +/// samply_measure!(async move { +/// process_data(data).await +/// }, marker: { +/// name: "process owned data", +/// }).await +/// } +/// ``` +#[macro_export] +macro_rules! samply_measure { + // New block scope within the same context + ( + $body:block + $(,)? + marker: { + name: $name:expr $(,)? + } + $(,)? + ) => {{ + let _timer = $crate::marker::SamplyTimer::new($name); + $body + }}; + + // Create a new async block + ( + async $body:block + $(,)? + marker: { + name: $name:expr $(,)? + } + $(,)? + ) => {async { + let _timer = $crate::marker::SamplyTimer::new($name); + (async $body).await + }}; + + // Create a new async move block + ( + async move $body:block + $(,)? + marker: { + name: $name:expr $(,)? + } + $(,)? + ) => {async move { + let _timer = $crate::marker::SamplyTimer::new($name); + (async move $body).await + }}; +} diff --git a/samply-markers/src/macros/samply_timer.rs b/samply-markers/src/macros/samply_timer.rs new file mode 100644 index 000000000..13509e892 --- /dev/null +++ b/samply-markers/src/macros/samply_timer.rs @@ -0,0 +1,50 @@ +//! This module defines the [`samply_timer!`](crate::samply_timer) macro for scope-based interval timing. + +/// Creates a scoped timer that emits an interval marker when the current scope ends. +/// +/// * The interval marker's start time is the moment the timer is created. +/// * The interval marker's end time is the moment the timer is dropped. +/// +/// The interval marker can be purposely emitted before the end of the scope by invoking the [`emit()`] function. +/// +/// * If [`emit()`] is called explicitly, it will not be called again when the timer is dropped. +/// +/// # Examples +/// +/// ```rust +/// # use samply_markers::samply_timer; +/// # fn update_physics() {} +/// # fn render_scene() {} +/// # fn update_cache() {} +/// fn render_frame() { +/// // Create a timer to represent the entire function. +/// let _timer = samply_timer!({ name: "render frame" }); +/// +/// // Create a timer only for the physics and scene portion. +/// let render_segment = samply_timer!({ name: "render scene" }); +/// +/// update_physics(); +/// render_scene(); +/// +/// // Emit here explicitly, instead of at the end of the frame. +/// render_segment.emit(); +/// +/// // Create a timer only for the cache portion. +/// let cache_segment = samply_timer!({ name: "update cache" }); +/// update_cache(); +/// +/// // The cache_segment timer will be emitted automatically at the end of the frame. +/// // The _timer will be emitted automatically at the end of the frame. +/// } +/// +/// render_frame(); +/// ``` +/// +/// [`emit()`]: crate::marker::SamplyTimer::emit +/// +#[macro_export] +macro_rules! samply_timer { + {{ name: $name:expr $(,)? }} => { + $crate::marker::SamplyTimer::new($name); + }; +} diff --git a/samply-markers/src/marker/mod.rs b/samply-markers/src/marker/mod.rs new file mode 100644 index 000000000..eca124994 --- /dev/null +++ b/samply-markers/src/marker/mod.rs @@ -0,0 +1,9 @@ +//! This module contains the core types for instrumenting code with markers. + +mod samply_marker; +mod samply_timer; +mod timestamp; + +pub use samply_marker::SamplyMarker; +pub use samply_timer::SamplyTimer; +pub use timestamp::SamplyTimestamp; diff --git a/samply-markers/src/marker/samply_marker.rs b/samply-markers/src/marker/samply_marker.rs new file mode 100644 index 000000000..fe7fe9bee --- /dev/null +++ b/samply-markers/src/marker/samply_marker.rs @@ -0,0 +1,213 @@ +use std::borrow::Cow; +use std::cell::Cell; +use std::marker::PhantomData; + +use crate::marker::SamplyTimestamp; +use crate::provider::WriteMarkerImpl; +use crate::provider::WriteMarkerProvider; + +/// A marker that can emit at the current location in the code's execution. +/// +/// * The marker may emit an instant, which represents a single point in time. +/// * The marker may emit an interval, which represents a span between a start time and end time. +/// +/// # Examples +/// +/// ```rust +/// # use samply_markers::prelude::*; +/// # struct Request {} +/// # impl Request { fn id(&self) -> u32 { 0 } } +/// # fn receive_request() -> Request { Request {} } +/// # fn query_database(id: u32) -> Vec { vec![] } +/// # fn serialize_json(data: &[String]) -> String { String::new() } +/// let request = receive_request(); +/// +/// // Emit an instant marker. +/// SamplyMarker::new(format!("received request {}", request.id())).emit_instant(); +/// +/// // Mark the start time for serializing the response. +/// let start = SamplyTimestamp::now(); +/// +/// let data = query_database(request.id()); +/// let json = serialize_json(&data); +/// +/// // Emit an interval marker. +/// SamplyMarker::new("serialize response").emit_interval(start); +/// ``` +#[derive(Debug)] +pub struct SamplyMarker<'data> { + /// The name recorded with every marker emission. + /// + /// Defaults to `"unnamed marker"` if empty. + name: Cow<'data, str>, + + /// This zero-sized member ensures that markers are `!Sync`. + /// + /// Markers are stil `Send`, allowing them to move between threads or be used in async tasks that migrate. + /// When a marker is emitted, it records the TID of the thread that emits it, which accurately represents + /// where the marker event occurred, even if the marker was created on a different thread. + /// + /// However, markers are `!Sync` because I see no valid use case for shared concurrent access to a marker. + /// Markers are meant to be owned and emitted exactly once, not shared and emitted from multiple threads. + /// + /// If we need to remove this restriction in the future, it will be a non-breaking change, but adding this + /// restriction would be a breaking change, so I would prefer to start more restrictively and increase the + /// capabilities if there is an explicit need to do so. + /// + /// This can be removed in favor of `impl !Sync` if negative impls are ever stabilized. + /// * + _no_sync: PhantomData>, +} + +impl<'data> SamplyMarker<'data> { + /// Creates a marker with the given `name`. + /// + /// Accepts [`&str`](str), [`String`], or anything convertible into [`Cow<'data, str>`]. + /// + /// If `name` is an empty string, it will default to `"unnamed marker"`. While every marker _should_ + /// have a descriptive name, providing a default is preferable to panicking, since a third-party crate + /// dependency could emit a marker with an empty name. Panicking in a scenario would mean that the code + /// can no longer be profiled with markers enabled at all. + /// + /// # Examples + /// + /// ```rust + /// # use samply_markers::prelude::*; + /// SamplyMarker::new("database query").emit_instant(); + /// + /// let user_id = 123; + /// SamplyMarker::new(format!("fetch user {user_id}")).emit_instant(); + /// ``` + #[inline] + #[must_use] + pub fn new(name: impl Into> + AsRef) -> Self { + if name.as_ref().is_empty() { + Self { + name: Cow::Borrowed("unnamed marker"), + _no_sync: PhantomData, + } + } else { + Self { + name: name.into(), + _no_sync: PhantomData, + } + } + } + + /// Returns the name of this marker. + /// + /// # Examples + /// + /// ```rust + /// # use samply_markers::prelude::*; + /// let marker = SamplyMarker::new("database query"); + /// assert_eq!(marker.name(), "database query"); + /// ``` + #[inline] + #[must_use] + pub fn name(&self) -> &str { + &self.name + } + + /// Emits an instant marker at the current time. + /// + /// # Examples + /// + /// ```rust + /// # use samply_markers::prelude::*; + /// # fn check_cache() -> Option { None } + /// # fn fetch_from_disk() -> String { String::new() } + /// if let Some(data) = check_cache() { + /// SamplyMarker::new("cache hit").emit_instant(); + /// } else { + /// SamplyMarker::new("cache miss").emit_instant(); + /// fetch_from_disk(); + /// } + /// + /// let request_id = 42; + /// SamplyMarker::new(format!("request {request_id} completed")).emit_instant(); + /// ``` + #[inline] + pub fn emit_instant(self) { + let now = SamplyTimestamp::now(); + ::write_marker(now, now, &self); + } + + /// Emits an interval marker from the given `start_time` to the current time. + /// + /// # Examples + /// + /// ```rust + /// # use samply_markers::prelude::*; + /// # fn check_cache() -> Option { None } + /// # fn fetch_from_disk() -> String { String::new() } + /// let start_time = SamplyTimestamp::now(); + /// + /// let data = if let Some(cached_data) = check_cache() { + /// // Emit an interval only for the cache-check portion. + /// SamplyMarker::new("cache check").emit_interval(start_time); + /// cached_data + /// } else { + /// // Emit an interval only for the cache-check portion. + /// SamplyMarker::new("cache check").emit_interval(start_time); + /// + /// let fetch_start = SamplyTimestamp::now(); + /// let fetched_data = fetch_from_disk(); + /// + /// // Emit an interval only for the fetch portion. + /// SamplyMarker::new("fetch from disk").emit_interval(fetch_start); + /// + /// fetched_data + /// }; + /// + /// // Emit an interval for the total time, including cache check and fetch. + /// SamplyMarker::new("total fetch time").emit_interval(start_time); + /// ``` + #[inline] + pub fn emit_interval(self, start_time: SamplyTimestamp) { + let end = SamplyTimestamp::now(); + ::write_marker(start_time, end, &self); + } +} + +#[cfg(test)] +mod test { + use super::*; + + #[test] + fn new_with_str() { + let marker = SamplyMarker::new("test marker"); + assert_eq!(marker.name(), "test marker"); + } + + #[test] + fn new_with_string() { + let name = String::from("dynamic marker"); + let marker = SamplyMarker::new(name); + assert_eq!(marker.name(), "dynamic marker"); + } + + #[test] + fn new_with_format() { + let five = 5; + let high = "high"; + let marker = SamplyMarker::new(format!("{high} {five}!")); + assert_eq!(marker.name(), "high 5!"); + } + + #[test] + fn marker_is_send() { + fn assert_send() {} + assert_send::(); + } + + #[test] + fn new_with_empty_name_defaults_to_unnamed_marker() { + let marker = SamplyMarker::new(""); + assert_eq!( + marker.name(), + "unnamed marker", + "Empty string should default to 'unnamed marker'" + ); + } +} diff --git a/samply-markers/src/marker/samply_timer.rs b/samply-markers/src/marker/samply_timer.rs new file mode 100644 index 000000000..e7cbd626e --- /dev/null +++ b/samply-markers/src/marker/samply_timer.rs @@ -0,0 +1,197 @@ +use std::borrow::Cow; + +use crate::marker::SamplyMarker; +use crate::marker::SamplyTimestamp; +use crate::provider::WriteMarkerImpl; +use crate::provider::WriteMarkerProvider; + +/// A scoped timer that emits an interval marker when the current scope ends. +/// +/// * The interval marker's start time is the moment the timer is created. +/// * The interval marker's end time is the moment the timer is dropped. +/// +/// The interval marker can be purposely emitted before the end of the scope by invoking the [`emit()`] function. +/// +/// * If [`emit()`] is called explicitly, it will not be called again when the timer is dropped. +/// +/// # Examples +/// +/// ```rust +/// # use samply_markers::prelude::*; +/// # fn update_physics() {} +/// # fn render_scene() {} +/// # fn update_cache() {} +/// fn render_frame() { +/// // Create a timer to represent the entire function. +/// let _timer = SamplyTimer::new("render frame"); +/// +/// // Create a timer only for the physics and scene portion. +/// let render_segment = SamplyTimer::new("render scene"); +/// +/// update_physics(); +/// render_scene(); +/// +/// // Emit here explicitly, instead of at the end of the frame. +/// render_segment.emit(); +/// +/// // Create a timer only for the cache portion. +/// let _cache_segment = SamplyTimer::new("update cache"); +/// update_cache(); +/// +/// // The _cache_segment marker will be emitted automatically at the end of the frame. +/// // The _timer marker will be emitted automatically at the end of the frame. +/// } +/// +/// render_frame(); +/// ``` +/// +/// [`emit()`]: SamplyTimer::emit +#[derive(Debug)] +pub struct SamplyTimer<'data> { + /// The marker that will be emitted when the timer is dropped. + marker: SamplyMarker<'data>, + /// The timestamp captured from when the timer was created. + start_time: SamplyTimestamp, +} + +impl<'data> SamplyTimer<'data> { + /// Starts a new timer called `name`. + /// + /// # Examples + /// + /// ```rust + /// # use samply_markers::prelude::*; + /// # fn compute_result() {} + /// fn expensive_function() { + /// let _timer = SamplyTimer::new("expensive computation"); + /// compute_result(); + /// // _timer emits when it is dropped at the end of scope. + /// } + /// # + /// # expensive_function(); + /// ``` + /// + /// ```rust + /// # use samply_markers::prelude::*; + /// # fn process_batch(batch_id: u32) {} + /// fn process_batches() { + /// for batch_id in 0..10 { + /// let _timer = SamplyTimer::new(format!("process batch {batch_id}")); + /// process_batch(batch_id); + /// // 10 interval markers are emitted, one for each loop iteration. + /// } + /// } + /// # + /// # process_batches(); + /// ``` + #[inline] + #[must_use] + pub fn new(name: impl Into> + AsRef) -> Self { + Self { + marker: SamplyMarker::new(name), + start_time: SamplyTimestamp::now(), + } + } + + /// Emits the interval marker immediately, instead of waiting for the end of scope. + /// + /// # Examples + /// + /// ```rust + /// # use samply_markers::prelude::*; + /// # fn expensive_computation() {} + /// # fn log_results() {} + /// # fn cleanup_temp_files() {} + /// fn process_data() { + /// let timer = SamplyTimer::new("core computation"); + /// expensive_computation(); + /// + /// // Emit the interval marker explicitly here. + /// timer.emit(); + /// + /// // These operations are not included in the interval marker + /// log_results(); + /// cleanup_temp_files(); + /// + /// // The interval marker is not emitted again at the end of scope. + /// } + /// # + /// # process_data(); + /// ``` + #[inline] + pub fn emit(self) { + drop(self); + } +} + +impl Drop for SamplyTimer<'_> { + /// Emits the interval marker when the timer is dropped. + #[inline] + fn drop(&mut self) { + let end = SamplyTimestamp::now(); + ::write_marker(self.start_time, end, &self.marker); + } +} + +#[cfg(test)] +mod test { + use super::*; + + #[test] + fn new_with_str() { + let timer = SamplyTimer::new("timer from str"); + assert_eq!(timer.marker.name(), "timer from str"); + } + + #[test] + fn new_with_string() { + let name = String::from("timer from String"); + let timer = SamplyTimer::new(name); + assert_eq!(timer.marker.name(), "timer from String"); + } + + #[test] + fn new_with_format() { + let five = 5; + let high = "high"; + let timer = SamplyTimer::new(format!("{high} {five}!")); + assert_eq!(timer.marker.name(), "high 5!"); + } + + #[test] + fn new_captures_start_time() { + let before = SamplyTimestamp::now(); + + std::thread::sleep(std::time::Duration::from_micros(10)); + let timer = SamplyTimer::new("timing test"); + std::thread::sleep(std::time::Duration::from_micros(10)); + + let after = SamplyTimestamp::now(); + + #[cfg(feature = "enabled")] + assert!( + timer.start_time > before, + "Expected the start time {:?} to be greater than the before time {before:?}.", + timer.start_time + ); + #[cfg(not(feature = "enabled"))] + assert!( + timer.start_time >= before, + "Expected the start time {:?} to be greater than or equal to the before time {before:?}.", + timer.start_time + ); + + #[cfg(feature = "enabled")] + assert!( + timer.start_time < after, + "Expected the start time {:?} to be less than the after time {after:?}.", + timer.start_time + ); + #[cfg(not(feature = "enabled"))] + assert!( + timer.start_time <= after, + "Expected the start time {:?} to be less than or equal to the after time {after:?}.", + timer.start_time + ); + } +} diff --git a/samply-markers/src/marker/timestamp.rs b/samply-markers/src/marker/timestamp.rs new file mode 100644 index 000000000..9282bc2b4 --- /dev/null +++ b/samply-markers/src/marker/timestamp.rs @@ -0,0 +1,140 @@ +//! This module contains the implementation of an opaque monotonic nanosecond timestamp used by [samply-markers](crate). + +use crate::provider::TimestampNowImpl; +use crate::provider::TimestampNowProvider; + +/// A monotonic timestamp expressed in nanoseconds. +/// +/// This type is intentionally opaque to avoid comparison inconsistencies between builds +/// that have [samply-markers](crate) enabled or disabled. +/// +/// # Examples +/// +/// ```rust +/// # use samply_markers::prelude::*; +/// let start = SamplyTimestamp::now(); +/// ``` +#[derive(Copy, Clone, Debug)] +#[cfg_attr(not(feature = "enabled"), allow(unused))] +pub struct SamplyTimestamp(u64); + +impl SamplyTimestamp { + /// Returns the current monotonic time in nanoseconds. + /// + /// # Examples + /// + /// ```rust + /// # use samply_markers::prelude::*; + /// let start = SamplyTimestamp::now(); + /// ``` + #[inline] + #[must_use] + pub fn now() -> Self { + ::now() + } + + /// Creates a timestamp from the given nanoseconds of monotonic time. + pub(crate) const fn from_monotonic_nanos(nanos: u64) -> Self { + Self(nanos) + } + + /// Returns the inner nanosecond value. + /// + /// This is only exposed within the crate for formatting and testing purposes, + /// keeping [`SamplyTimestamp`] opaque to external consumers. + #[inline] + #[cfg(feature = "enabled")] + pub(crate) const fn as_nanos(self) -> u64 { + self.0 + } +} + +/// The following traits are implemented internally for testing only. +/// The [`SamplyTimestamp`] struct should remain opaque to consumers of this crate. +#[cfg(test)] +mod compare { + use super::*; + + impl Eq for SamplyTimestamp {} + impl PartialEq for SamplyTimestamp { + fn eq(&self, other: &Self) -> bool { + self.0 == other.0 + } + } + + impl PartialOrd for SamplyTimestamp { + fn partial_cmp(&self, other: &Self) -> Option { + Some(self.cmp(other)) + } + } + + impl Ord for SamplyTimestamp { + fn cmp(&self, other: &Self) -> std::cmp::Ordering { + self.0.cmp(&other.0) + } + } +} + +#[cfg(test)] +mod test { + use super::*; + + #[test] + #[cfg(feature = "enabled")] + fn as_nanos_returns_correct_value() { + let time = SamplyTimestamp::from_monotonic_nanos(9876543210); + assert_eq!( + time.as_nanos(), + 9876543210, + "Expected as_nanos to return the underlying nanosecond value." + ); + } + + #[test] + #[cfg(feature = "enabled")] + fn now_is_monotonic() { + const ITERATIONS: usize = 1000; + let mut timestamps = Vec::with_capacity(ITERATIONS); + + // Collect many timestamps in rapid succession. + for _ in 0..ITERATIONS { + timestamps.push(SamplyTimestamp::now()); + } + + // Verify monotonicity: each timestamp should be >= the previous. + assert!( + timestamps + .iter() + .zip(timestamps.iter().skip(1)) + .all(|(lhs, rhs)| lhs <= rhs), + "Timestamps must be monotonically non-decreasing" + ); + + // At least some timestamps should be strictly increasing. + let strictly_increasing_count = timestamps + .iter() + .zip(timestamps.iter().skip(1)) + .filter(|(lhs, rhs)| lhs < rhs) + .count(); + + assert!( + strictly_increasing_count > 0, + "Expected at least some timestamps to be strictly increasing, but all {} were equal", + ITERATIONS + ); + } + + #[test] + #[cfg(not(feature = "enabled"))] + fn now_returns_zero_when_disabled() { + // When markers are disabled, timestamps should always return zero + for _ in 0..10 { + let now = SamplyTimestamp::now(); + assert_eq!( + now, + SamplyTimestamp::from_monotonic_nanos(0), + "Expected disabled timestamps to always be zero" + ); + } + } +} diff --git a/samply-markers/src/provider/default.rs b/samply-markers/src/provider/default.rs new file mode 100644 index 000000000..0f8fb611e --- /dev/null +++ b/samply-markers/src/provider/default.rs @@ -0,0 +1,30 @@ +//! This module contains default internal implementations that no-op when [samply-markers](crate) is not enabled. + +use crate::marker::SamplyMarker; +use crate::marker::SamplyTimestamp; +use crate::provider::TimestampNowProvider; +use crate::provider::WriteMarkerProvider; + +/// A [`TimestampNowProvider`] that always reports zero when the default provider is active. +pub struct TimestampNowImpl; + +impl TimestampNowProvider for TimestampNowImpl { + /// Returns a zero timestamp. + /// + /// This function is intentionally not `const` because the real provider-specific + /// implementations are not `const`. This keeps the API consistent even when + /// [samply-markers](crate) is disabled. + fn now() -> SamplyTimestamp { + SamplyTimestamp::from_monotonic_nanos(0) + } +} + +/// A [`WriteMarkerProvider`] that does nothing when the default provider is active. +pub struct WriteMarkerImpl; + +impl WriteMarkerProvider for WriteMarkerImpl { + /// Does nothing with the marker data. + fn write_marker(_start: SamplyTimestamp, _end: SamplyTimestamp, _marker: &SamplyMarker) { + // no-op when markers are not enabled. + } +} diff --git a/samply-markers/src/provider/mod.rs b/samply-markers/src/provider/mod.rs new file mode 100644 index 000000000..229a37708 --- /dev/null +++ b/samply-markers/src/provider/mod.rs @@ -0,0 +1,44 @@ +//! This module contains context-specific, uniform implementations for the internal APIs used by this crate. +//! +//! The default provider is designed to no-op when the code is not compiled for profiling. +//! +//! When [samply-markers](crate) is enabled, there are platform-specific provider implementations for Unix and Windows systems. +//! +//! * An internal provider must provide a type [`TimestampNowImpl`] that implements the [`TimestampNowProvider`] trait. +//! * An internal provider must provide a type [`WriteMarkerImpl`] that implements the [`WriteMarkerProvider`] trait. +//! +//! [`TimestampNowProvider`]: crate::provider::TimestampNowProvider +//! [`WriteMarkerProvider`]: crate::provider::WriteMarkerProvider + +use crate::marker::SamplyMarker; +use crate::marker::SamplyTimestamp; + +pub use internal_provider::TimestampNowImpl; +pub use internal_provider::WriteMarkerImpl; + +/// A trait implemented by context-specific providers to supply monotonic nanosecond timestamp. +pub trait TimestampNowProvider { + /// Returns a monotonic timestamp in nanoseconds. + fn now() -> SamplyTimestamp; +} + +/// A trait implemented by context-specific providers to write markers for ingestion by samply. +pub trait WriteMarkerProvider { + /// Writes a marker span for profiling consumption. + fn write_marker(start: SamplyTimestamp, end: SamplyTimestamp, marker: &SamplyMarker); +} + +#[cfg(not(feature = "enabled"))] +pub mod r#default; +#[cfg(not(feature = "enabled"))] +pub use r#default as internal_provider; + +#[cfg(all(feature = "enabled", target_family = "unix"))] +pub mod unix; +#[cfg(all(feature = "enabled", target_family = "unix"))] +pub use unix as internal_provider; + +#[cfg(all(feature = "enabled", target_family = "windows"))] +pub mod windows; +#[cfg(all(feature = "enabled", target_family = "windows"))] +pub use windows as internal_provider; diff --git a/samply-markers/src/provider/unix.rs b/samply-markers/src/provider/unix.rs new file mode 100644 index 000000000..1cf10b5f1 --- /dev/null +++ b/samply-markers/src/provider/unix.rs @@ -0,0 +1,278 @@ +//! This module contains internal provider implementations for compiling [samply-markers](crate) on Unix systems. + +use std::cell::RefCell; +use std::fs::File; +use std::io::BufWriter; +use std::io::Write; +use std::num::NonZeroUsize; +use std::path::Path; +use std::path::PathBuf; +use std::sync::LazyLock; +#[cfg(target_os = "macos")] +use std::sync::OnceLock; + +use crate::marker::SamplyMarker; +use crate::marker::SamplyTimestamp; +use crate::provider::TimestampNowProvider; +use crate::provider::WriteMarkerProvider; + +use nix::sys::mman::MapFlags; +use nix::sys::mman::ProtFlags; +#[cfg(target_os = "linux")] +use nix::time::ClockId; +#[cfg(target_os = "linux")] +use nix::time::clock_gettime; + +use tempfile::TempDir; +use tempfile::tempdir; + +/// A wrapper around [`std::io::BufWriter`] that flushes on drop to ensure data is written. +/// +/// This is used in conjunction with [`std::thread_local!`] to ensure that buffers are +/// flushed when the thread exits. +struct FlushOnDrop(BufWriter); + +impl Drop for FlushOnDrop { + fn drop(&mut self) { + if let Err(e) = self.0.flush() { + eprintln!("samply-markers: failed to flush marker-file buffer: {e}"); + } + } +} + +impl std::ops::Deref for FlushOnDrop { + type Target = BufWriter; + fn deref(&self) -> &Self::Target { + &self.0 + } +} + +impl std::ops::DerefMut for FlushOnDrop { + fn deref_mut(&mut self) -> &mut Self::Target { + &mut self.0 + } +} + +/// A lazily created directory that holds per-thread mmapped marker files. +static MARKERS_DIR: LazyLock> = LazyLock::new(|| { + tempdir() + .map(TempDir::keep) + .inspect_err(|e| eprintln!("samply-markers: failed to create temporary directory: {e}")) + .ok() +}); + +thread_local! { + /// A thread-local buffered writer used to append marker lines that samply will ingest. + static MARKER_FILE: RefCell> = RefCell::new(create_marker_file()); +} + +#[cfg(target_os = "macos")] +static NANOS_PER_TICK: OnceLock = OnceLock::new(); + +/// A monotonic nanosecond timestamp implementation. +pub struct TimestampNowImpl; + +impl TimestampNowProvider for TimestampNowImpl { + /// Queries the monotonic clock and converts the result to monotonic nanoseconds. + #[inline] + fn now() -> SamplyTimestamp { + #[cfg(target_os = "linux")] + { + let now = clock_gettime(ClockId::CLOCK_MONOTONIC) + .expect("samply-markers: unable to get time from CLOCK_MONOTONIC"); + + // Monotonic nanoseconds should only ever be positive. + #[allow(clippy::cast_sign_loss)] + SamplyTimestamp::from_monotonic_nanos( + now.tv_sec() as u64 * 1_000_000_000 + now.tv_nsec() as u64, + ) + } + + // Use mach_absolute_time() to match samply's clock source on macOS. + // See https://github.com/mstange/samply/blob/2041b956f650bb92d912990052967d03fef66b75/samply/src/mac/time.rs#L8-L20 + #[cfg(target_os = "macos")] + { + use mach2::mach_time; + + let nanos_per_tick = NANOS_PER_TICK.get_or_init(|| { + let mut info = mach_time::mach_timebase_info::default(); + // SAFETY: mach_timebase_info is an FFI call on macOS. We pass a valid mutable reference + // to a properly initialized mach_timebase_info struct. + // See https://developer.apple.com/documentation/driverkit/3433733-mach_timebase_info + let errno = unsafe { mach_time::mach_timebase_info(&raw mut info) }; + if errno != 0 || info.denom == 0 { + info.numer = 1; + info.denom = 1; + } + info + }); + + // SAFETY: mach_absolute_time is an FFI call on macOS that returns the current + // absolute time value in tick units. + // See https://developer.apple.com/documentation/kernel/1462446-mach_absolute_time + let time = unsafe { mach_time::mach_absolute_time() }; + let nanos = time * u64::from(nanos_per_tick.numer) / u64::from(nanos_per_tick.denom); + + SamplyTimestamp::from_monotonic_nanos(nanos) + } + } +} + +/// A marker writer that appends newline-delimited ranges to the per-thread file. +pub struct WriteMarkerImpl; + +impl WriteMarkerProvider for WriteMarkerImpl { + /// Serializes the marker to the thread-local file, creating it on demand. + #[inline] + fn write_marker(start: SamplyTimestamp, end: SamplyTimestamp, marker: &SamplyMarker) { + let () = MARKER_FILE.with_borrow_mut(|file| { + if let Some(f) = file.as_mut() { + // Use stack-allocated itoa buffers to format timestamps without heap allocation. + // Format: "{start_ns} {end_ns} {marker_name}\n" + let mut start_buf = itoa::Buffer::new(); + let mut end_buf = itoa::Buffer::new(); + + let _ = f.write_all(start_buf.format(start.as_nanos()).as_bytes()); + let _ = f.write_all(b" "); + let _ = f.write_all(end_buf.format(end.as_nanos()).as_bytes()); + let _ = f.write_all(b" "); + let _ = f.write_all(marker.name().as_bytes()); + let _ = f.write_all(b"\n"); + } + }); + } +} + +/// Returns the lazily-created temporary markers directory, if available. +fn markers_dir() -> Option<&'static Path> { + Some(LazyLock::force(&MARKERS_DIR).as_ref()?) +} + +/// Returns a unique thread identifier for the current thread. +#[cfg(target_os = "linux")] +fn get_thread_id() -> u32 { + // Thread IDs on Linux are always positive, so the cast from i32 to u32 is safe. + #[allow(clippy::cast_sign_loss)] + let tid = nix::unistd::gettid().as_raw() as u32; + + tid +} + +/// Returns a unique thread identifier for the current thread. +#[cfg(target_os = "macos")] +fn get_thread_id() -> u32 { + // Use pthread_threadid_np() to get the current thread's system thread ID. + // + // This is the simplest way to get our own thread ID. Samply uses thread_info() + // instead because it's extracting thread IDs from other processes via mach ports. + // + // Both approaches return the same underlying system thread ID value. + // + // See https://github.com/mstange/samply/blob/2041b956f650bb92d912990052967d03fef66b75/samply/src/mac/thread_profiler.rs#L209-L229 + let mut tid: u64 = 0; + + // SAFETY: pthread_threadid_np is an FFI call. We pass pthread_self() provided by libc, + // along with a valid mutable reference to our tid variable. + // See https://docs.rs/libc/latest/x86_64-apple-darwin/libc/fn.pthread_threadid_np.html + unsafe { + libc::pthread_threadid_np(libc::pthread_self(), &raw mut tid); + } + + // Truncate to u32 to match samply's behavior. + #[allow(clippy::cast_possible_truncation)] + let tid = tid as u32; + + tid +} + +/// Creates a new mmapped marker file for the current thread. +fn create_marker_file() -> Option { + let file_name = markers_dir()?.join(format!( + "marker-{}-{}.txt", + nix::unistd::getpid().as_raw(), + get_thread_id() + )); + + let file = File::options() + .create(true) + .truncate(true) + .write(true) + .read({ + // We aren't going to read from the file, so we ordinarily + // wouldn't need read permission, but we're about mmap it and + // mmap always requires read permission. + true + }) + .open(&file_name) + .inspect_err(|e| { + eprintln!( + "samply-markers: failed to create marker file {e}: {}", + file_name.display() + ); + }) + .ok()?; + + // Create an mmap for the file. This cannot be skipped because it + // triggers samply to read and interpret the file. We will not use it + // to write to the file (because writing to a text file via mmap is + // painful and we haven't yet proved that it is a performance problem), + // so it is not necessary to map it with any particular protection or + // flags, so we use PROT_READ because that offers the fewest ways to + // screw up. + // + // SAFETY: This call to mmap is safe because: + // - We're mapping a valid file descriptor that we just opened + // - The size (4096) is a valid, non-zero size + // - The offset is 0 which is valid for any file + // See https://docs.rs/nix/latest/nix/sys/mman/fn.mmap.html + unsafe { + nix::sys::mman::mmap( + None, + NonZeroUsize::new(4096).unwrap_unchecked(), + ProtFlags::PROT_READ, + MapFlags::MAP_SHARED, + &file, + 0, + ) + } + .inspect_err(|e| { + eprintln!( + "samply-markers: failed to mmap marker file {e}: {}", + file_name.display() + ); + }) + .ok()?; + + // I benchmarked the buffer size with hyperfine, using the Fibonacci example + // given n = 30, which generates about 2.7 million markers per run. + // + // Ubuntu results: + // ------------------------------------------ + // 4 KiB: 470.9 ms ± 1.2 ms (5.3% slower) + // 8 KiB: 457.4 ms ± 2.1 ms (2.2% slower) + // 16 KiB: 451.0 ms ± 1.3 ms (0.8% slower) + // 32 KiB: 447.6 ms ± 1.5 ms (0.1% slower) + // 64 KiB: 447.4 ms ± 2.9 ms (optimal speed) + // 128 KiB: 448.6 ms ± 1.1 ms (0.3% slower) + // 256 KiB: 450.5 ms ± 1.4 ms (0.7% slower) + // 512 KiB: 450.1 ms ± 1.1 ms (0.6% slower) + // 1024 KiB: 449.9 ms ± 2.6 ms (0.6% slower) + // + // macOS results: + // ------------------------------------------ + // 4 KiB: 303.0 ms ± 2.5 ms (43.9% slower) + // 8 KiB: 258.3 ms ± 1.2 ms (22.6% slower) + // 16 KiB: 236.4 ms ± 1.2 ms (12.2% slower) + // 32 KiB: 223.4 ms ± 0.7 ms (06.0% slower) + // 64 KiB: 217.2 ms ± 1.2 ms (03.1% slower) + // 128 KiB: 213.3 ms ± 0.7 ms (01.3% slower) + // 256 KiB: 211.9 ms ± 1.3 ms (00.6% slower) + // 512 KiB: 210.6 ms ± 0.7 ms (optimal speed) + // 1024 KiB: 210.7 ms ± 0.7 ms (00.0% slower) + // + // Even though macOS benefitted from a larger buffer size, + // I feel like a 512 KiB buffer per thread feels like overkill. + // + // 64 KiB feels like a good balance based on this benchmark. + Some(FlushOnDrop(BufWriter::with_capacity(64 * 1024, file))) +} diff --git a/samply-markers/src/provider/windows.rs b/samply-markers/src/provider/windows.rs new file mode 100644 index 000000000..062b4894c --- /dev/null +++ b/samply-markers/src/provider/windows.rs @@ -0,0 +1,26 @@ +//! This module contains internal provider implementations for compiling [samply-markers](crate) on Windows systems. +//! +//! Windows is not yet supported at this time. + +use crate::marker::SamplyMarker; +use crate::marker::SamplyTimestamp; +use crate::provider::TimestampNowProvider; +use crate::provider::WriteMarkerProvider; + +/// A [`TimestampNowProvider`] that always panics because Windows is not supported yet. +pub struct TimestampNowImpl; + +impl TimestampNowProvider for TimestampNowImpl { + fn now() -> SamplyTimestamp { + unimplemented!("samply-markers: this crate is not yet available on Windows"); + } +} + +/// A [`WriteMarkerProvider`] that always panics because Windows is not supported yet. +pub struct WriteMarkerImpl; + +impl WriteMarkerProvider for WriteMarkerImpl { + fn write_marker(_start: SamplyTimestamp, _end: SamplyTimestamp, _marker: &SamplyMarker) { + unimplemented!("samply-markers: this crate is not yet available on Windows"); + } +} diff --git a/samply-markers/tests/unix.rs b/samply-markers/tests/unix.rs new file mode 100644 index 000000000..f7a08771a --- /dev/null +++ b/samply-markers/tests/unix.rs @@ -0,0 +1,770 @@ +//! This module contains integration tests for [`samply-markers`](crate) on Unix systems. +//! +//! # Test Design: +//! +//! These tests verify that markers are correctly written to files by inspecting the marker file +//! contents after emission. To ensure deterministic testing, most tests wrap marker emission in +//! `thread::spawn` and join the thread before reading marker files. +//! +//! ## The FlushOnDrop Mechanism +//! +//! Marker files use buffered writes for performance. The buffer is wrapped in a `FlushOnDrop` +//! type that lives in thread-local storage. When a thread exits, the thread-local storage is +//! dropped, triggering an automatic flush of the buffer to disk. +//! +//! ## Why Thread Spawning is Required +//! +//! Without spawning a new thread, markers emitted in the test would be buffered in the main test +//! thread's thread-local storage. The buffer would only flush when the test thread exits, which +//! may happen after the test's assertions run. This creates a race condition where the test might +//! read the marker file before the buffer is flushed, causing spurious failures. +//! +//! ## When Writing New Tests +//! +//! If your test needs to verify marker file contents after emission, wrap the marker-emitting +//! code in `thread::spawn` and join the thread before reading the marker file. +//! +//! Example pattern: +//! ```rust +//! let tid = thread::spawn(move || { +//! samply_marker!({ name: "MyMarker" }); +//! get_thread_id() +//! }) +//! .join() +//! .expect("thread panicked"); +//! +//! // Now it's safe to read and verify the marker file +//! assert_marker_file!(pid, tid, regex: { r"^\d+ \d+ MyMarker$" }); +//! ``` + +#![cfg(all(feature = "enabled", target_family = "unix"))] + +use std::env; +use std::fs; +use std::thread; + +use regex::Regex; +use samply_markers::prelude::*; +use serial_test::serial; + +/// Returns a unique thread identifier for the current thread. +#[cfg(target_os = "linux")] +fn get_thread_id() -> u32 { + nix::unistd::gettid().as_raw() as u32 +} + +/// Returns a unique thread identifier for the current thread. +#[cfg(target_os = "macos")] +fn get_thread_id() -> u32 { + // Use pthread_threadid_np() to get the thread ID, same as samply does. + // This returns a u64 but we cast to u32 to match samply's behavior and + // ensure the thread ID fits in the marker filename format. + unsafe { + let mut tid: u64 = 0; + libc::pthread_threadid_np(libc::pthread_self(), &mut tid); + tid as u32 + } +} + +/// Wraps a test body with automatic cleanup of marker files for the current process. +macro_rules! with_marker_file_cleanup { + ($body:block) => {{ + let pid = nix::unistd::getpid().as_raw() as u32; + cleanup_marker_files(pid); + + let result = $body; + + cleanup_marker_files(pid); + result + }}; +} + +/// Asserts that exactly one marker file exists for the given PID, and verifies that it belongs to the given TID. +/// Returns the marker file paths for further inspection. +macro_rules! assert_single_marker_file { + ($pid:expr, $tid:expr) => {{ + let marker_files = find_all_marker_files($pid); + assert_eq!( + marker_files.len(), + 1, + "Expected exactly one marker file for single-threaded test, found {}", + marker_files.len() + ); + + let marker_file = &marker_files[0]; + let expected_pattern = format!("marker-{}-{}", $pid, $tid); + assert!( + marker_file + .file_name() + .unwrap() + .to_string_lossy() + .starts_with(&expected_pattern), + "Expected marker file to be for TID {}, but found {:?}", + $tid, + marker_file + ); + + marker_files + }}; +} + +/// Asserts that the marker file for the given PID/TID matches the expected regex pattern(s). +/// +/// When patterns are provided in the `regex: { ... }` block, the macro will by default +/// verify that the file contains exactly that many lines (one per pattern). +/// This can be disabled by passing `exact_count: false`. +macro_rules! assert_marker_file { + // Regex patterns with exact line count check (default behavior). + ($pid:expr, $tid:expr, regex: { $($pattern:expr),+ $(,)? }) => {{ + assert_marker_file!($pid, $tid, regex: { $($pattern),+ }, exact_count: true) + }}; + + // Regex patterns with optional exact line count check. + ($pid:expr, $tid:expr, regex: { $($pattern:expr),+ $(,)? }, exact_count: $exact:expr) => {{ + let patterns = &[$($pattern),+]; + let combined_pattern = format!("(?m){}", patterns.join("\n")); + assert_marker_file!($pid, $tid, regex: &combined_pattern, pattern_count: patterns.len(), exact_count: $exact) + }}; + + // Internal implementation with pattern count and exact count flag. + ($pid:expr, $tid:expr, regex: $regex:expr, pattern_count: $count:expr, exact_count: $exact:expr) => {{ + let marker_files = find_all_marker_files($pid); + let pattern_prefix = format!("marker-{}-{}", $pid, $tid); + + let marker_file = marker_files + .iter() + .find(|path| { + path.file_name() + .unwrap() + .to_string_lossy() + .starts_with(&pattern_prefix) + }) + .expect(&format!( + "Expected to find marker file for PID {} TID {}.", + $pid, $tid + )); + + let contents = fs::read_to_string(&marker_file).expect("failed to read marker file"); + let regex = Regex::new($regex).expect("invalid regex pattern"); + + assert!( + regex.is_match(&contents), + "Marker file contents did not match expected pattern:\n\ + Expected pattern:\n{}\n\ + Actual contents:\n{}", + $regex, + contents + ); + + if $exact && $count > 0 { + let line_count = contents.lines().count(); + assert_eq!( + line_count, + $count, + "Expected exactly {} lines in marker file, but found {}", + $count, + line_count + ); + } + + for line in contents.lines() { + let parts = line.split_whitespace().collect::>(); + let start: u64 = parts[0].parse().expect("start time should be a valid u64"); + let end: u64 = parts[1].parse().expect("end time should be a valid u64"); + assert!( + end >= start, + "Expected the end time to be greater than or equal to the start time.", + ); + } + + contents + }}; +} + +/// Helper function to find all marker files for a given PID in the system temp directory. +fn find_all_marker_files(pid: u32) -> Vec { + let temp_dir = env::temp_dir(); + let pattern_prefix = format!("marker-{pid}-"); + + fs::read_dir(&temp_dir) + .ok() + .into_iter() + .flatten() + .filter_map(Result::ok) + .filter(|entry| entry.path().is_dir()) + .flat_map(|entry| { + fs::read_dir(entry.path()) + .ok() + .into_iter() + .flatten() + .filter_map(Result::ok) + .filter(|sub_entry| { + sub_entry + .file_name() + .to_string_lossy() + .starts_with(&pattern_prefix) + }) + .map(|sub_entry| sub_entry.path()) + }) + .collect() +} + +/// Helper function to clean up all marker files for a given PID. +fn cleanup_marker_files(pid: u32) { + let marker_files = find_all_marker_files(pid); + for file in marker_files { + let _ = fs::remove_file(file); + } +} + +#[test] +#[serial] +fn instant_writes_marker_to_file() { + with_marker_file_cleanup!({ + let pid = nix::unistd::getpid().as_raw() as u32; + + let tid = thread::spawn(move || { + samply_marker!({ name: "InstantMarker1" }); + samply_marker!({ name: "InstantMarker2" }); + samply_marker!({ name: "InstantMarker3" }); + + get_thread_id() + }) + .join() + .expect("thread panicked"); + + assert_single_marker_file!(pid, tid); + + let contents = assert_marker_file!( + pid, + tid, + regex: { + r"^\d+ \d+ InstantMarker1$", + r"^\d+ \d+ InstantMarker2$", + r"^\d+ \d+ InstantMarker3$", + } + ); + + assert!( + contents.lines().all(|line| { + let parts = line.split_whitespace().collect::>(); + let start: u64 = parts[0].parse().expect("start time should be a valid u64"); + let end: u64 = parts[1].parse().expect("end time should be a valid u64"); + start == end + }), + "Expected all instant markers to have same start and end time." + ); + }); +} + +#[test] +#[serial] +#[should_panic( + expected = "assertion `left == right` failed: Expected exactly 1 lines in marker file, but found 2" +)] +fn assert_marker_file_panics_on_wrong_line_count() { + with_marker_file_cleanup!({ + let pid = nix::unistd::getpid().as_raw() as u32; + + let tid = thread::spawn(move || { + // Emit exactly 2 markers. + SamplyMarker::new("test marker").emit_instant(); + SamplyMarker::new("test marker").emit_instant(); + + get_thread_id() + }) + .join() + .expect("thread panicked"); + + assert_single_marker_file!(pid, tid); + + // Try to assert only 1 pattern when there are 2 lines. + assert_marker_file!( + pid, + tid, + regex: { + r"^\d+ \d+ test marker$", + } + ); + }); +} + +#[test] +#[serial] +fn empty_name_defaults_to_unnamed_marker() { + with_marker_file_cleanup!({ + let pid = nix::unistd::getpid().as_raw() as u32; + + let tid = thread::spawn(move || { + SamplyMarker::new("").emit_instant(); + SamplyMarker::new(format!("")).emit_instant(); + + get_thread_id() + }) + .join() + .expect("thread panicked"); + + assert_single_marker_file!(pid, tid); + + assert_marker_file!( + pid, + tid, + regex: { + r"^\d+ \d+ unnamed marker$", + r"^\d+ \d+ unnamed marker$", + } + ); + }); +} + +#[test] +#[serial] +fn timer_writes_marker_to_file() { + with_marker_file_cleanup!({ + let pid = nix::unistd::getpid().as_raw() as u32; + + let tid = thread::spawn(move || { + { + let _timer1 = samply_timer!({ name: "TimerMarker1" }); + thread::sleep(std::time::Duration::from_millis(2)); + } + { + let _timer2 = samply_timer!({ name: "TimerMarker2" }); + thread::sleep(std::time::Duration::from_millis(3)); + } + { + let _timer3 = samply_timer!({ name: "TimerMarker3" }); + thread::sleep(std::time::Duration::from_millis(4)); + } + + get_thread_id() + }) + .join() + .expect("thread panicked"); + + assert_single_marker_file!(pid, tid); + + assert_marker_file!( + pid, + tid, + regex: { + r"^\d+ \d+ TimerMarker1$", + r"^\d+ \d+ TimerMarker2$", + r"^\d+ \d+ TimerMarker3$", + } + ); + }); +} + +#[test] +#[serial] +fn measure_writes_marker_to_file() { + with_marker_file_cleanup!({ + let pid = nix::unistd::getpid().as_raw() as u32; + + let tid = thread::spawn(move || { + let result1 = samply_measure!({ + thread::sleep(std::time::Duration::from_millis(2)); + 42 + } marker: { + name: "MeasureMarker1", + }); + + let result2 = samply_measure!({ + thread::sleep(std::time::Duration::from_millis(3)); + "hello" + } marker: { + name: "MeasureMarker2", + }); + + let result3 = samply_measure!({ + thread::sleep(std::time::Duration::from_millis(4)); + vec![1, 2, 3] + } marker: { + name: "MeasureMarker3", + }); + + assert_eq!(result1, 42, "Expected measure to preserve return value."); + assert_eq!( + result2, "hello", + "Expected measure to preserve return value." + ); + assert_eq!( + result3, + vec![1, 2, 3], + "Expected measure to preserve return value." + ); + + get_thread_id() + }) + .join() + .expect("thread panicked"); + + assert_single_marker_file!(pid, tid); + + assert_marker_file!( + pid, + tid, + regex: { + r"^\d+ \d+ MeasureMarker1$", + r"^\d+ \d+ MeasureMarker2$", + r"^\d+ \d+ MeasureMarker3$", + } + ); + }); +} + +#[test] +#[serial] +fn multiple_threads_create_separate_files() { + with_marker_file_cleanup!({ + let handles = (0..3) + .map(|i| { + thread::spawn(move || { + samply_marker!({ name: format!("thread {i} marker A") }); + samply_marker!({ name: format!("thread {i} marker B") }); + samply_marker!({ name: format!("thread {i} marker C") }); + thread::sleep(std::time::Duration::from_millis(10)); + + get_thread_id() + }) + }) + .collect::>(); + + let tids = handles + .into_iter() + .map(|h| h.join().expect("thread panicked")) + .collect::>(); + + let pid = nix::unistd::getpid().as_raw() as u32; + + // Multi-threaded test should produce exactly one marker file per thread. + let marker_files = find_all_marker_files(pid); + assert_eq!( + marker_files.len(), + 3, + "Expected exactly 3 marker files (one per thread), found {}", + marker_files.len() + ); + + for tid in tids { + assert_marker_file!( + pid, + tid, + regex: { + r"^\d+ \d+ thread \d marker A$", + r"^\d+ \d+ thread \d marker B$", + r"^\d+ \d+ thread \d marker C$", + } + ); + } + }); +} + +#[serial] +#[tokio::test] +async fn measure_async_writes_marker_to_file() { + use tokio::time::{Duration, sleep}; + + with_marker_file_cleanup!({ + let pid = nix::unistd::getpid().as_raw() as u32; + + let tid = thread::spawn(move || { + let runtime = tokio::runtime::Runtime::new().unwrap(); + + runtime.block_on(async { + let result = samply_measure!(async { + sleep(Duration::from_millis(5)).await; + 42 + }, marker: { + name: "AsyncMeasure", + }) + .await; + + assert_eq!(result, 42, "Expected measure to preserve return value."); + }); + + get_thread_id() + }) + .join() + .expect("thread panicked"); + + assert_single_marker_file!(pid, tid); + + assert_marker_file!( + pid, + tid, + regex: { + r"^\d+ \d+ AsyncMeasure$", + } + ); + }); +} + +#[test] +#[serial] +fn timer_emit_prevents_double_emit_on_drop() { + with_marker_file_cleanup!({ + let pid = nix::unistd::getpid().as_raw() as u32; + + let tid = thread::spawn(move || { + { + let timer = samply_timer!({ name: "ExplicitEmit" }); + thread::sleep(std::time::Duration::from_millis(2)); + timer.emit(); // Explicitly emit the timer. + // The timer drops here, but should not emit a second time. + } + + get_thread_id() + }) + .join() + .expect("thread panicked"); + + assert_single_marker_file!(pid, tid); + + assert_marker_file!( + pid, + tid, + regex: { + r"^\d+ \d+ ExplicitEmit$", + } + ); + }); +} + +#[serial] +#[tokio::test] +async fn measure_async_with_early_return_writes_marker() { + use tokio::time::{Duration, sleep}; + + with_marker_file_cleanup!({ + let pid = nix::unistd::getpid().as_raw() as u32; + + let tid = thread::spawn(move || { + let runtime = tokio::runtime::Runtime::new().unwrap(); + + runtime.block_on(async { + async fn fallible_operation(should_fail: bool) -> Result { + samply_measure!(async { + sleep(Duration::from_millis(2)).await; + + if should_fail { + return Err("operation failed"); + } + + sleep(Duration::from_millis(2)).await; + Ok(String::from("success")) + }, marker: { + name: "FallibleAsync", + }) + .await + } + + let success_result = fallible_operation(false).await; + assert!(success_result.is_ok()); + + let failure_result = fallible_operation(true).await; + assert!(failure_result.is_err()); + }); + + get_thread_id() + }) + .join() + .expect("thread panicked"); + + assert_single_marker_file!(pid, tid); + + assert_marker_file!( + pid, + tid, + regex: { + r"^\d+ \d+ FallibleAsync$", + r"^\d+ \d+ FallibleAsync$", + } + ); + }); +} + +#[test] +#[serial] +fn tokio_spawn_writes_markers_across_threads() { + use tokio::time::{Duration, sleep}; + + with_marker_file_cleanup!({ + let handles = (0..3) + .map(|i| { + thread::spawn(move || { + // Create a tokio runtime on this thread to test async markers + let runtime = tokio::runtime::Runtime::new().unwrap(); + + runtime.block_on(async move { + // Emit async markers with awaits + samply_measure!(async { + sleep(Duration::from_millis(2)).await; + }, marker: { + name: format!("async task {i} marker A"), + }) + .await; + + samply_measure!(async { + sleep(Duration::from_millis(3)).await; + }, marker: { + name: format!("async task {i} marker B"), + }) + .await; + + samply_measure!(async { + sleep(Duration::from_millis(4)).await; + }, marker: { + name: format!("async task {i} marker C"), + }) + .await; + }); + + // Return the thread ID where markers were emitted. + // Buffer will auto-flush when this thread exits (FlushOnDrop) + get_thread_id() + }) + }) + .collect::>(); + + let _tids = handles + .into_iter() + .map(|h| h.join().expect("thread panicked")) + .collect::>(); + + let pid = nix::unistd::getpid().as_raw() as u32; + + // Verify that markers were written across multiple threads. + // Each thread gets its own marker file. + let marker_files = find_all_marker_files(pid); + + // With 3 threads, we should have exactly 3 marker files. + assert_eq!( + marker_files.len(), + 3, + "Expected exactly 3 marker files (one per thread), found {}", + marker_files.len() + ); + + let all_contents = marker_files + .into_iter() + .filter_map(|path| fs::read_to_string(path).ok()) + .collect::>() + .join("\n"); + + // Verify that all 9 markers (3 tasks × 3 markers each) appear somewhere + for n in 0..3 { + for marker in ["marker A", "marker B", "marker C"] { + let expected = format!("async task {n} {marker}"); + assert!( + all_contents.contains(&expected), + "Expected to find '{expected}' in marker files but didn't.\nAll contents:\n{all_contents}" + ); + } + } + }); +} + +#[test] +#[serial] +fn tokio_task_migration_writes_markers_correctly() { + use tokio::time::{Duration, sleep}; + + with_marker_file_cleanup!({ + // Create a shared multi-threaded runtime that allows task migration between threads. + let runtime = tokio::runtime::Builder::new_multi_thread() + .worker_threads(8) + .enable_time() + .build() + .unwrap(); + + runtime.block_on(async { + // Spawn tasks using tokio::spawn, which allows migration between worker threads. + let handles = (0..8) + .map(|i| { + tokio::spawn(async move { + for marker_num in 0..10 { + samply_measure!(async { + sleep(Duration::from_millis(2)).await; + }, marker: { + name: format!("migrating task {i} marker {marker_num}"), + }) + .await; + + // Yield to encourage task migration. + tokio::task::yield_now().await; + } + + get_thread_id() + }) + }) + .collect::>(); + + // Wait for all tasks to complete. + let _tids = futures::future::join_all(handles) + .await + .into_iter() + .map(|result| result.expect("task panicked")) + .collect::>(); + }); + + // Drop the runtime, which causes worker threads to exit and flush their buffers. + drop(runtime); + + let pid = nix::unistd::getpid().as_raw() as u32; + let marker_files = find_all_marker_files(pid); + + // With 8 worker threads, we should have 1-8 marker files depending on task migration. + // The total number of markers across the 1-8 files should always be exactly 80. + // + // Run the following command to see this output: + // ❯ cargo test -p samply-markers --features enabled tokio_task_migration_writes_markers_correctly -- --nocapture + println!("\n=== Marker File Distribution ===\n"); + println!("Total marker files created: {}\n", marker_files.len()); + + assert!( + !marker_files.is_empty() && marker_files.len() <= 8, + "Expected 1-8 marker files, found {}", + marker_files.len() + ); + + let all_contents = marker_files + .iter() + .filter_map(|path| { + fs::read_to_string(path).ok().map(|contents| { + let line_count = contents.lines().count(); + println!( + " - {} has {} markers", + path.file_name().unwrap().to_string_lossy(), + line_count + ); + contents + }) + }) + .collect::>() + .join(""); + + let total_marker_count = all_contents.lines().count(); + println!("\nTotal markers across all files: {}\n", total_marker_count); + + assert_eq!( + total_marker_count, 80, + "Expected exactly 80 markers (8 tasks x 10 markers each), but found {}", + total_marker_count + ); + + // Verify all 80 markers appear with the correct names. + for task_num in 0..8 { + for marker_num in 0..10 { + let expected = format!("migrating task {task_num} marker {marker_num}"); + assert!( + all_contents.contains(&expected), + "Expected to find '{expected}' in marker files but didn't.\n\ + This proves FlushOnDrop successfully flushed when tokio runtime shut down.\n\ + All contents:\n{all_contents}" + ); + } + } + }); +} diff --git a/samply-markers/tests/windows.rs b/samply-markers/tests/windows.rs new file mode 100644 index 000000000..272a313d8 --- /dev/null +++ b/samply-markers/tests/windows.rs @@ -0,0 +1,21 @@ +//! This module contains integration tests for [`samply-markers`](crate) on Windows systems. +//! +//! Windows support is not yet implemented, so these tests verify that attempting to use +//! markers on Windows results in a panic. + +#![cfg(all(feature = "enabled", target_family = "windows"))] + +use samply_markers::marker::SamplyMarker; +use samply_markers::marker::SamplyTimestamp; + +#[test] +#[should_panic(expected = "not yet available on Windows")] +fn timestamp_now_panics() { + let _ = SamplyTimestamp::now(); +} + +#[test] +#[should_panic(expected = "not yet available on Windows")] +fn emit_instant_panics() { + SamplyMarker::new("test marker").emit_instant(); +} diff --git a/samply/src/shared/process_sample_data.rs b/samply/src/shared/process_sample_data.rs index 1bdbf31ab..cec9a52bf 100644 --- a/samply/src/shared/process_sample_data.rs +++ b/samply/src/shared/process_sample_data.rs @@ -116,12 +116,26 @@ impl ProcessSampleData { } for marker in marker_spans { - let marker_name_string_index = profile.handle_for_string(&marker.name); - profile.add_marker( - marker.thread_handle, - MarkerTiming::Interval(marker.start_time, marker.end_time), - SimpleMarker(marker_name_string_index), - ); + let MarkerSpanOnThread { + thread_handle, + start_time, + end_time, + name, + } = marker; + + let marker_name_string_index = profile.handle_for_string(&name); + let timing = Self::marker_timing_for_span(start_time, end_time); + let marker = SimpleMarker(marker_name_string_index); + + profile.add_marker(thread_handle, timing, marker); + } + } + + fn marker_timing_for_span(start_time: Timestamp, end_time: Timestamp) -> MarkerTiming { + if start_time == end_time { + MarkerTiming::Instant(start_time) + } else { + MarkerTiming::Interval(start_time, end_time) } } } @@ -285,3 +299,35 @@ impl Marker for SimpleMarker { self.0 } } + +#[cfg(test)] +mod tests { + use super::*; + + #[test] + fn test_marker_timing_for_span() { + let same_time = Timestamp::from_millis_since_reference(5.0); + let different_start = Timestamp::from_millis_since_reference(10.0); + let different_end = Timestamp::from_millis_since_reference(15.0); + + let zero_duration_timing = ProcessSampleData::marker_timing_for_span(same_time, same_time); + assert!( + matches!(zero_duration_timing, MarkerTiming::Instant(_)), + "Zero duration span should return Instant timing" + ); + if let MarkerTiming::Instant(t) = zero_duration_timing { + assert_eq!(t, same_time); + } + + let non_zero_duration_timing = + ProcessSampleData::marker_timing_for_span(different_start, different_end); + assert!( + matches!(non_zero_duration_timing, MarkerTiming::Interval(_, _)), + "Non-zero duration span should return Interval timing" + ); + if let MarkerTiming::Interval(start, end) = non_zero_duration_timing { + assert_eq!(start, different_start); + assert_eq!(end, different_end); + } + } +}