From ea1bcab919bd609e76ac9b0f3f313bc1f68eeff5 Mon Sep 17 00:00:00 2001 From: Daniel Wagner-Hall Date: Tue, 27 Feb 2018 15:25:27 +0000 Subject: [PATCH 1/2] Use rust logging API When in the engine, this passes messages up to python to log. When in a standalone binary, this registers an env_logger. Examples: ``` $ RUST_LOG=debug ./target/debug/process_executor --server=localhost:50000 --cas-server=localhost:50001 --local-store-path=${HOME}/tmp/store --input-digest=6f9a33e23a007c58c1e83f29bcf52979c797aba200cec0058695ff72d181e6ed --input-digest-length=85 -- /bin/bash -c "exit 42" DEBUG 2018-02-27T15:23:19Z: process_execution::remote: Executing remotely request: action {command_digest {hash: "8a1eb3dc8694551ee161e6f616de205f7c2d5b52c8f5b93d2745d67c3b750e6a" size_bytes: 24} input_root_digest {hash: "6f9a33e23a007c58c1e83f29bcf52979c797aba200cec0058695ff72d181e6ed" size_bytes: 85}} (command: arguments: "/bin/bash" arguments: "-c" arguments: "exit 42") DEBUG 2018-02-27T15:23:20Z: process_execution::remote: Got operation response: name: "b15e0908-7956-4dfa-7fc7-48dffc8aff8d" metadata {type_url: "type.googleapis.com/google.devtools.remoteexecution.v1test.ExecuteOperationMetadata" value: "\010\002\022E\n@81d6ae5c2323235c8633ffa63a1867bcc40306e0da9012a3d387df2eead80e3d\020\214\001"} response {type_url: "type.googleapis.com/google.devtools.remoteexecution.v1test.ExecuteResponse"} ``` ``` $ ./pants -ldebug clean-all >/dev/null 2>/dev/null ; ./pants -ldebug list 3rdparty:: 2>&1 | grep Launching DEBUG] Launching 2 roots. DEBUG] Launching 1 roots. DEBUG] Launching 2 roots. ``` --- src/rust/engine/Cargo.lock | 2 + src/rust/engine/Cargo.toml | 1 + src/rust/engine/fs/fs_util/Cargo.lock | 47 +++++++++++ src/rust/engine/fs/fs_util/Cargo.toml | 1 + src/rust/engine/fs/fs_util/src/main.rs | 3 + src/rust/engine/process_execution/Cargo.toml | 1 + src/rust/engine/process_execution/src/lib.rs | 2 + .../engine/process_execution/src/remote.rs | 7 +- src/rust/engine/process_executor/Cargo.lock | 48 +++++++++++ src/rust/engine/process_executor/Cargo.toml | 1 + src/rust/engine/process_executor/src/main.rs | 3 + src/rust/engine/src/externs.rs | 81 +++++++++++++++---- src/rust/engine/src/lib.rs | 10 ++- src/rust/engine/src/scheduler.rs | 11 +-- 14 files changed, 185 insertions(+), 33 deletions(-) diff --git a/src/rust/engine/Cargo.lock b/src/rust/engine/Cargo.lock index 6dc522cd96b..d119c6b75da 100644 --- a/src/rust/engine/Cargo.lock +++ b/src/rust/engine/Cargo.lock @@ -109,6 +109,7 @@ dependencies = [ "futures 0.1.17 (registry+https://github.com/rust-lang/crates.io-index)", "hashing 0.0.1", "lazy_static 0.2.11 (registry+https://github.com/rust-lang/crates.io-index)", + "log 0.4.1 (registry+https://github.com/rust-lang/crates.io-index)", "ordermap 0.2.13 (registry+https://github.com/rust-lang/crates.io-index)", "petgraph 0.4.11 (registry+https://github.com/rust-lang/crates.io-index)", "process_execution 0.0.1", @@ -393,6 +394,7 @@ dependencies = [ "futures 0.1.17 (registry+https://github.com/rust-lang/crates.io-index)", "grpcio 0.2.0 (registry+https://github.com/rust-lang/crates.io-index)", "hashing 0.0.1", + "log 0.4.1 (registry+https://github.com/rust-lang/crates.io-index)", "protobuf 1.4.3 (registry+https://github.com/rust-lang/crates.io-index)", "sha2 0.6.0 (registry+https://github.com/rust-lang/crates.io-index)", "tempdir 0.3.5 (registry+https://github.com/rust-lang/crates.io-index)", diff --git a/src/rust/engine/Cargo.toml b/src/rust/engine/Cargo.toml index 7beb9eb66b6..84e10ff62cf 100644 --- a/src/rust/engine/Cargo.toml +++ b/src/rust/engine/Cargo.toml @@ -28,6 +28,7 @@ fs = { path = "fs" } futures = "0.1.16" hashing = { path = "hashing" } lazy_static = "0.2.2" +log = "0.4" ordermap = "0.2.8" petgraph = "0.4.5" process_execution = { path = "process_execution" } diff --git a/src/rust/engine/fs/fs_util/Cargo.lock b/src/rust/engine/fs/fs_util/Cargo.lock index 98ef6370b92..10b6582f789 100644 --- a/src/rust/engine/fs/fs_util/Cargo.lock +++ b/src/rust/engine/fs/fs_util/Cargo.lock @@ -126,6 +126,18 @@ name = "either" version = "1.4.0" source = "registry+https://github.com/rust-lang/crates.io-index" +[[package]] +name = "env_logger" +version = "0.5.4" +source = "registry+https://github.com/rust-lang/crates.io-index" +dependencies = [ + "atty 0.2.6 (registry+https://github.com/rust-lang/crates.io-index)", + "humantime 1.1.0 (registry+https://github.com/rust-lang/crates.io-index)", + "log 0.4.1 (registry+https://github.com/rust-lang/crates.io-index)", + "regex 0.2.6 (registry+https://github.com/rust-lang/crates.io-index)", + "termcolor 0.3.5 (registry+https://github.com/rust-lang/crates.io-index)", +] + [[package]] name = "fake-simd" version = "0.1.2" @@ -169,6 +181,7 @@ dependencies = [ "boxfuture 0.0.1", "bytes 0.4.6 (registry+https://github.com/rust-lang/crates.io-index)", "clap 2.30.0 (registry+https://github.com/rust-lang/crates.io-index)", + "env_logger 0.5.4 (registry+https://github.com/rust-lang/crates.io-index)", "fs 0.0.1", "futures 0.1.18 (registry+https://github.com/rust-lang/crates.io-index)", "hashing 0.0.1", @@ -272,6 +285,14 @@ name = "hex" version = "0.3.1" source = "registry+https://github.com/rust-lang/crates.io-index" +[[package]] +name = "humantime" +version = "1.1.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +dependencies = [ + "quick-error 1.2.1 (registry+https://github.com/rust-lang/crates.io-index)", +] + [[package]] name = "ignore" version = "0.3.1" @@ -404,6 +425,11 @@ dependencies = [ "bytes 0.4.6 (registry+https://github.com/rust-lang/crates.io-index)", ] +[[package]] +name = "quick-error" +version = "1.2.1" +source = "registry+https://github.com/rust-lang/crates.io-index" + [[package]] name = "rand" version = "0.4.2" @@ -487,6 +513,14 @@ dependencies = [ "remove_dir_all 0.3.0 (registry+https://github.com/rust-lang/crates.io-index)", ] +[[package]] +name = "termcolor" +version = "0.3.5" +source = "registry+https://github.com/rust-lang/crates.io-index" +dependencies = [ + "wincolor 0.1.6 (registry+https://github.com/rust-lang/crates.io-index)", +] + [[package]] name = "termion" version = "1.5.1" @@ -585,6 +619,14 @@ name = "winapi-x86_64-pc-windows-gnu" version = "0.4.0" source = "registry+https://github.com/rust-lang/crates.io-index" +[[package]] +name = "wincolor" +version = "0.1.6" +source = "registry+https://github.com/rust-lang/crates.io-index" +dependencies = [ + "winapi 0.3.4 (registry+https://github.com/rust-lang/crates.io-index)", +] + [metadata] "checksum aho-corasick 0.6.4 (registry+https://github.com/rust-lang/crates.io-index)" = "d6531d44de723825aa81398a6415283229725a00fa30713812ab9323faa82fc4" "checksum ansi_term 0.10.2 (registry+https://github.com/rust-lang/crates.io-index)" = "6b3568b48b7cefa6b8ce125f9bb4989e52fbcc29ebea88df04cc7c5f12f70455" @@ -602,6 +644,7 @@ source = "registry+https://github.com/rust-lang/crates.io-index" "checksum crossbeam 0.2.12 (registry+https://github.com/rust-lang/crates.io-index)" = "bd66663db5a988098a89599d4857919b3acf7f61402e61365acfd3919857b9be" "checksum digest 0.6.2 (registry+https://github.com/rust-lang/crates.io-index)" = "e5b29bf156f3f4b3c4f610a25ff69370616ae6e0657d416de22645483e72af0a" "checksum either 1.4.0 (registry+https://github.com/rust-lang/crates.io-index)" = "740178ddf48b1a9e878e6d6509a1442a2d42fd2928aae8e7a6f8a36fb01981b3" +"checksum env_logger 0.5.4 (registry+https://github.com/rust-lang/crates.io-index)" = "f3cc21490995c841d68e00276eba02071ebb269ec24011d5728bd00eabd39e31" "checksum fake-simd 0.1.2 (registry+https://github.com/rust-lang/crates.io-index)" = "e88a8acf291dafb59c2d96e8f59828f3838bb1a70398823ade51a84de6a6deed" "checksum fnv 1.0.6 (registry+https://github.com/rust-lang/crates.io-index)" = "2fad85553e09a6f881f739c29f0b00b0f01357c743266d478b68951ce23285f3" "checksum fuchsia-zircon 0.3.3 (registry+https://github.com/rust-lang/crates.io-index)" = "2e9763c69ebaae630ba35f74888db465e49e259ba1bc0eda7d06f4a067615d82" @@ -615,6 +658,7 @@ source = "registry+https://github.com/rust-lang/crates.io-index" "checksum grpcio 0.2.0 (registry+https://github.com/rust-lang/crates.io-index)" = "473a8a5620d6a58a17f236588c8e5bfb05f4a55a7c406e100a5afe888a923536" "checksum grpcio-sys 0.2.0 (registry+https://github.com/rust-lang/crates.io-index)" = "8253f10312996bfa7ad164f05ec89d9d5c0d7277c36846379aea7c91daac412a" "checksum hex 0.3.1 (registry+https://github.com/rust-lang/crates.io-index)" = "459d3cf58137bb02ad4adeef5036377ff59f066dbb82517b7192e3a5462a2abc" +"checksum humantime 1.1.0 (registry+https://github.com/rust-lang/crates.io-index)" = "5369e01a05e3404c421b5d6dcfea6ecf7d5e65eba8a275948151358cd8282042" "checksum ignore 0.3.1 (registry+https://github.com/rust-lang/crates.io-index)" = "bb2f0238094bd1b41800fb6eb9b16fdd5e9832ed6053ed91409f0cd5bf28dcfd" "checksum iovec 0.1.2 (registry+https://github.com/rust-lang/crates.io-index)" = "dbe6e417e7d0975db6512b90796e8ce223145ac4e33c377e4a42882a0e88bb08" "checksum itertools 0.7.6 (registry+https://github.com/rust-lang/crates.io-index)" = "b07332223953b5051bceb67e8c4700aa65291535568e1f12408c43c4a42c0394" @@ -632,6 +676,7 @@ source = "registry+https://github.com/rust-lang/crates.io-index" "checksum ordermap 0.2.13 (registry+https://github.com/rust-lang/crates.io-index)" = "b81cf3b8cb96aa0e73bbedfcdc9708d09fec2854ba8d474be4e6f666d7379e8b" "checksum pkg-config 0.3.9 (registry+https://github.com/rust-lang/crates.io-index)" = "3a8b4c6b8165cd1a1cd4b9b120978131389f64bdaf456435caa41e630edba903" "checksum protobuf 1.4.3 (registry+https://github.com/rust-lang/crates.io-index)" = "bec26e67194b7d991908145fdf21b7cae8b08423d96dcb9e860cd31f854b9506" +"checksum quick-error 1.2.1 (registry+https://github.com/rust-lang/crates.io-index)" = "eda5fe9b71976e62bc81b781206aaa076401769b2143379d3eb2118388babac4" "checksum rand 0.4.2 (registry+https://github.com/rust-lang/crates.io-index)" = "eba5f8cb59cc50ed56be8880a5c7b496bfd9bd26394e176bc67884094145c2c5" "checksum redox_syscall 0.1.37 (registry+https://github.com/rust-lang/crates.io-index)" = "0d92eecebad22b767915e4d529f89f28ee96dbbf5a4810d2b844373f136417fd" "checksum redox_termios 0.1.1 (registry+https://github.com/rust-lang/crates.io-index)" = "7e891cfe48e9100a70a3b6eb652fef28920c117d366339687bd5576160db0f76" @@ -642,6 +687,7 @@ source = "registry+https://github.com/rust-lang/crates.io-index" "checksum sha2 0.6.0 (registry+https://github.com/rust-lang/crates.io-index)" = "7d963c78ce367df26d7ea8b8cc655c651b42e8a1e584e869c1e17dae3ccb116a" "checksum strsim 0.7.0 (registry+https://github.com/rust-lang/crates.io-index)" = "bb4f380125926a99e52bc279241539c018323fab05ad6368b56f93d9369ff550" "checksum tempdir 0.3.6 (registry+https://github.com/rust-lang/crates.io-index)" = "f73eebdb68c14bcb24aef74ea96079830e7fa7b31a6106e42ea7ee887c1e134e" +"checksum termcolor 0.3.5 (registry+https://github.com/rust-lang/crates.io-index)" = "56c456352e44f9f91f774ddeeed27c1ec60a2455ed66d692059acfb1d731bda1" "checksum termion 1.5.1 (registry+https://github.com/rust-lang/crates.io-index)" = "689a3bdfaab439fd92bc87df5c4c78417d3cbe537487274e9b0b2dce76e92096" "checksum textwrap 0.9.0 (registry+https://github.com/rust-lang/crates.io-index)" = "c0b59b6b4b44d867f1370ef1bd91bfb262bf07bf0ae65c202ea2fbc16153b693" "checksum thread_local 0.3.5 (registry+https://github.com/rust-lang/crates.io-index)" = "279ef31c19ededf577bfd12dfae728040a21f635b06a24cd670ff510edd38963" @@ -657,3 +703,4 @@ source = "registry+https://github.com/rust-lang/crates.io-index" "checksum winapi-build 0.1.1 (registry+https://github.com/rust-lang/crates.io-index)" = "2d315eee3b34aca4797b2da6b13ed88266e6d612562a0c46390af8299fc699bc" "checksum winapi-i686-pc-windows-gnu 0.4.0 (registry+https://github.com/rust-lang/crates.io-index)" = "ac3b87c63620426dd9b991e5ce0329eff545bccbbb34f3be09ff6fb6ab51b7b6" "checksum winapi-x86_64-pc-windows-gnu 0.4.0 (registry+https://github.com/rust-lang/crates.io-index)" = "712e227841d057c1ee1cd2fb22fa7e5a5461ae8e48fa2ca79ec42cfc1931183f" +"checksum wincolor 0.1.6 (registry+https://github.com/rust-lang/crates.io-index)" = "eeb06499a3a4d44302791052df005d5232b927ed1a9658146d842165c4de7767" diff --git a/src/rust/engine/fs/fs_util/Cargo.toml b/src/rust/engine/fs/fs_util/Cargo.toml index b8389d6a663..56d058dfe0e 100644 --- a/src/rust/engine/fs/fs_util/Cargo.toml +++ b/src/rust/engine/fs/fs_util/Cargo.toml @@ -8,6 +8,7 @@ bazel_protos = { path = "../../process_execution/bazel_protos" } boxfuture = { path = "../../boxfuture" } bytes = "0.4.5" clap = "2" +env_logger = "0.5.4" fs = { path = ".." } futures = "0.1.16" hashing = { path = "../../hashing" } diff --git a/src/rust/engine/fs/fs_util/src/main.rs b/src/rust/engine/fs/fs_util/src/main.rs index 58c821c97df..fe0291dd866 100644 --- a/src/rust/engine/fs/fs_util/src/main.rs +++ b/src/rust/engine/fs/fs_util/src/main.rs @@ -2,6 +2,7 @@ extern crate bazel_protos; extern crate boxfuture; extern crate bytes; extern crate clap; +extern crate env_logger; extern crate fs; extern crate futures; extern crate hashing; @@ -37,6 +38,8 @@ impl From for ExitError { } fn main() { + env_logger::init(); + match execute( App::new("fs_util") .subcommand( diff --git a/src/rust/engine/process_execution/Cargo.toml b/src/rust/engine/process_execution/Cargo.toml index 9fb29a301d4..ae5cfd3281c 100644 --- a/src/rust/engine/process_execution/Cargo.toml +++ b/src/rust/engine/process_execution/Cargo.toml @@ -12,6 +12,7 @@ fs = { path = "../fs" } futures = "0.1.16" grpcio = { version = "0.2.0", features = ["secure"] } hashing = { path = "../hashing" } +log = "0.4" protobuf = { version = "1.4.1", features = ["with-bytes"] } sha2 = "0.6.0" tempdir = "0.3.5" diff --git a/src/rust/engine/process_execution/src/lib.rs b/src/rust/engine/process_execution/src/lib.rs index a21811a17d6..81abbe53843 100644 --- a/src/rust/engine/process_execution/src/lib.rs +++ b/src/rust/engine/process_execution/src/lib.rs @@ -6,6 +6,8 @@ extern crate fs; extern crate futures; extern crate grpcio; extern crate hashing; +#[macro_use] +extern crate log; #[cfg(test)] extern crate mock; extern crate protobuf; diff --git a/src/rust/engine/process_execution/src/remote.rs b/src/rust/engine/process_execution/src/remote.rs index 414a9dc7f68..4edb307ce41 100644 --- a/src/rust/engine/process_execution/src/remote.rs +++ b/src/rust/engine/process_execution/src/remote.rs @@ -80,8 +80,7 @@ impl CommandRunner { Ok((command, execute_request)) => { self.upload_command(&command, execute_request.get_action().get_command_digest().into()) .and_then(move |_| { - // TODO: Log less verbosely - println!("Executing remotely request: {:?} (command: {:?})", execute_request, command); + debug!("Executing remotely request: {:?} (command: {:?})", execute_request, command); map_grpc_result(execution_client.execute(&execute_request)) .map(|result| (Arc::new(execute_request), result)) @@ -194,7 +193,7 @@ fn extract_execute_response( mut operation: bazel_protos::operations::Operation, ) -> Result { // TODO: Log less verbosely - println!("Got operation response: {:?}", operation); + debug!("Got operation response: {:?}", operation); if !operation.get_done() { return Err(ExecutionError::NotFinished(operation.take_name())); } @@ -213,7 +212,7 @@ fn extract_execute_response( ExecutionError::Fatal(format!("Invalid ExecuteResponse: {:?}", e)) })?; // TODO: Log less verbosely - println!("Got (nested) execute response: {:?}", execute_response); + debug!("Got (nested) execute response: {:?}", execute_response); match grpcio::RpcStatusCode::from(execute_response.get_status().get_code()) { grpcio::RpcStatusCode::Ok => Ok(ExecuteProcessResult { diff --git a/src/rust/engine/process_executor/Cargo.lock b/src/rust/engine/process_executor/Cargo.lock index 97ccd674570..fbe5d4cf1f0 100644 --- a/src/rust/engine/process_executor/Cargo.lock +++ b/src/rust/engine/process_executor/Cargo.lock @@ -126,6 +126,18 @@ name = "either" version = "1.4.0" source = "registry+https://github.com/rust-lang/crates.io-index" +[[package]] +name = "env_logger" +version = "0.5.4" +source = "registry+https://github.com/rust-lang/crates.io-index" +dependencies = [ + "atty 0.2.6 (registry+https://github.com/rust-lang/crates.io-index)", + "humantime 1.1.0 (registry+https://github.com/rust-lang/crates.io-index)", + "log 0.4.1 (registry+https://github.com/rust-lang/crates.io-index)", + "regex 0.2.6 (registry+https://github.com/rust-lang/crates.io-index)", + "termcolor 0.3.5 (registry+https://github.com/rust-lang/crates.io-index)", +] + [[package]] name = "fake-simd" version = "0.1.2" @@ -258,6 +270,14 @@ name = "hex" version = "0.3.1" source = "registry+https://github.com/rust-lang/crates.io-index" +[[package]] +name = "humantime" +version = "1.1.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +dependencies = [ + "quick-error 1.2.1 (registry+https://github.com/rust-lang/crates.io-index)", +] + [[package]] name = "ignore" version = "0.3.1" @@ -394,6 +414,7 @@ dependencies = [ "futures 0.1.18 (registry+https://github.com/rust-lang/crates.io-index)", "grpcio 0.2.0 (registry+https://github.com/rust-lang/crates.io-index)", "hashing 0.0.1", + "log 0.4.1 (registry+https://github.com/rust-lang/crates.io-index)", "protobuf 1.4.3 (registry+https://github.com/rust-lang/crates.io-index)", "sha2 0.6.0 (registry+https://github.com/rust-lang/crates.io-index)", "tempdir 0.3.6 (registry+https://github.com/rust-lang/crates.io-index)", @@ -405,6 +426,7 @@ version = "0.0.1" dependencies = [ "boxfuture 0.0.1", "clap 2.30.0 (registry+https://github.com/rust-lang/crates.io-index)", + "env_logger 0.5.4 (registry+https://github.com/rust-lang/crates.io-index)", "fs 0.0.1", "futures 0.1.18 (registry+https://github.com/rust-lang/crates.io-index)", "hashing 0.0.1", @@ -420,6 +442,11 @@ dependencies = [ "bytes 0.4.6 (registry+https://github.com/rust-lang/crates.io-index)", ] +[[package]] +name = "quick-error" +version = "1.2.1" +source = "registry+https://github.com/rust-lang/crates.io-index" + [[package]] name = "rand" version = "0.4.2" @@ -503,6 +530,14 @@ dependencies = [ "remove_dir_all 0.3.0 (registry+https://github.com/rust-lang/crates.io-index)", ] +[[package]] +name = "termcolor" +version = "0.3.5" +source = "registry+https://github.com/rust-lang/crates.io-index" +dependencies = [ + "wincolor 0.1.6 (registry+https://github.com/rust-lang/crates.io-index)", +] + [[package]] name = "termion" version = "1.5.1" @@ -601,6 +636,14 @@ name = "winapi-x86_64-pc-windows-gnu" version = "0.4.0" source = "registry+https://github.com/rust-lang/crates.io-index" +[[package]] +name = "wincolor" +version = "0.1.6" +source = "registry+https://github.com/rust-lang/crates.io-index" +dependencies = [ + "winapi 0.3.4 (registry+https://github.com/rust-lang/crates.io-index)", +] + [metadata] "checksum aho-corasick 0.6.4 (registry+https://github.com/rust-lang/crates.io-index)" = "d6531d44de723825aa81398a6415283229725a00fa30713812ab9323faa82fc4" "checksum ansi_term 0.10.2 (registry+https://github.com/rust-lang/crates.io-index)" = "6b3568b48b7cefa6b8ce125f9bb4989e52fbcc29ebea88df04cc7c5f12f70455" @@ -618,6 +661,7 @@ source = "registry+https://github.com/rust-lang/crates.io-index" "checksum crossbeam 0.2.12 (registry+https://github.com/rust-lang/crates.io-index)" = "bd66663db5a988098a89599d4857919b3acf7f61402e61365acfd3919857b9be" "checksum digest 0.6.2 (registry+https://github.com/rust-lang/crates.io-index)" = "e5b29bf156f3f4b3c4f610a25ff69370616ae6e0657d416de22645483e72af0a" "checksum either 1.4.0 (registry+https://github.com/rust-lang/crates.io-index)" = "740178ddf48b1a9e878e6d6509a1442a2d42fd2928aae8e7a6f8a36fb01981b3" +"checksum env_logger 0.5.4 (registry+https://github.com/rust-lang/crates.io-index)" = "f3cc21490995c841d68e00276eba02071ebb269ec24011d5728bd00eabd39e31" "checksum fake-simd 0.1.2 (registry+https://github.com/rust-lang/crates.io-index)" = "e88a8acf291dafb59c2d96e8f59828f3838bb1a70398823ade51a84de6a6deed" "checksum fnv 1.0.6 (registry+https://github.com/rust-lang/crates.io-index)" = "2fad85553e09a6f881f739c29f0b00b0f01357c743266d478b68951ce23285f3" "checksum fuchsia-zircon 0.3.3 (registry+https://github.com/rust-lang/crates.io-index)" = "2e9763c69ebaae630ba35f74888db465e49e259ba1bc0eda7d06f4a067615d82" @@ -631,6 +675,7 @@ source = "registry+https://github.com/rust-lang/crates.io-index" "checksum grpcio 0.2.0 (registry+https://github.com/rust-lang/crates.io-index)" = "473a8a5620d6a58a17f236588c8e5bfb05f4a55a7c406e100a5afe888a923536" "checksum grpcio-sys 0.2.0 (registry+https://github.com/rust-lang/crates.io-index)" = "8253f10312996bfa7ad164f05ec89d9d5c0d7277c36846379aea7c91daac412a" "checksum hex 0.3.1 (registry+https://github.com/rust-lang/crates.io-index)" = "459d3cf58137bb02ad4adeef5036377ff59f066dbb82517b7192e3a5462a2abc" +"checksum humantime 1.1.0 (registry+https://github.com/rust-lang/crates.io-index)" = "5369e01a05e3404c421b5d6dcfea6ecf7d5e65eba8a275948151358cd8282042" "checksum ignore 0.3.1 (registry+https://github.com/rust-lang/crates.io-index)" = "bb2f0238094bd1b41800fb6eb9b16fdd5e9832ed6053ed91409f0cd5bf28dcfd" "checksum iovec 0.1.2 (registry+https://github.com/rust-lang/crates.io-index)" = "dbe6e417e7d0975db6512b90796e8ce223145ac4e33c377e4a42882a0e88bb08" "checksum itertools 0.7.6 (registry+https://github.com/rust-lang/crates.io-index)" = "b07332223953b5051bceb67e8c4700aa65291535568e1f12408c43c4a42c0394" @@ -648,6 +693,7 @@ source = "registry+https://github.com/rust-lang/crates.io-index" "checksum ordermap 0.2.13 (registry+https://github.com/rust-lang/crates.io-index)" = "b81cf3b8cb96aa0e73bbedfcdc9708d09fec2854ba8d474be4e6f666d7379e8b" "checksum pkg-config 0.3.9 (registry+https://github.com/rust-lang/crates.io-index)" = "3a8b4c6b8165cd1a1cd4b9b120978131389f64bdaf456435caa41e630edba903" "checksum protobuf 1.4.3 (registry+https://github.com/rust-lang/crates.io-index)" = "bec26e67194b7d991908145fdf21b7cae8b08423d96dcb9e860cd31f854b9506" +"checksum quick-error 1.2.1 (registry+https://github.com/rust-lang/crates.io-index)" = "eda5fe9b71976e62bc81b781206aaa076401769b2143379d3eb2118388babac4" "checksum rand 0.4.2 (registry+https://github.com/rust-lang/crates.io-index)" = "eba5f8cb59cc50ed56be8880a5c7b496bfd9bd26394e176bc67884094145c2c5" "checksum redox_syscall 0.1.37 (registry+https://github.com/rust-lang/crates.io-index)" = "0d92eecebad22b767915e4d529f89f28ee96dbbf5a4810d2b844373f136417fd" "checksum redox_termios 0.1.1 (registry+https://github.com/rust-lang/crates.io-index)" = "7e891cfe48e9100a70a3b6eb652fef28920c117d366339687bd5576160db0f76" @@ -658,6 +704,7 @@ source = "registry+https://github.com/rust-lang/crates.io-index" "checksum sha2 0.6.0 (registry+https://github.com/rust-lang/crates.io-index)" = "7d963c78ce367df26d7ea8b8cc655c651b42e8a1e584e869c1e17dae3ccb116a" "checksum strsim 0.7.0 (registry+https://github.com/rust-lang/crates.io-index)" = "bb4f380125926a99e52bc279241539c018323fab05ad6368b56f93d9369ff550" "checksum tempdir 0.3.6 (registry+https://github.com/rust-lang/crates.io-index)" = "f73eebdb68c14bcb24aef74ea96079830e7fa7b31a6106e42ea7ee887c1e134e" +"checksum termcolor 0.3.5 (registry+https://github.com/rust-lang/crates.io-index)" = "56c456352e44f9f91f774ddeeed27c1ec60a2455ed66d692059acfb1d731bda1" "checksum termion 1.5.1 (registry+https://github.com/rust-lang/crates.io-index)" = "689a3bdfaab439fd92bc87df5c4c78417d3cbe537487274e9b0b2dce76e92096" "checksum textwrap 0.9.0 (registry+https://github.com/rust-lang/crates.io-index)" = "c0b59b6b4b44d867f1370ef1bd91bfb262bf07bf0ae65c202ea2fbc16153b693" "checksum thread_local 0.3.5 (registry+https://github.com/rust-lang/crates.io-index)" = "279ef31c19ededf577bfd12dfae728040a21f635b06a24cd670ff510edd38963" @@ -673,3 +720,4 @@ source = "registry+https://github.com/rust-lang/crates.io-index" "checksum winapi-build 0.1.1 (registry+https://github.com/rust-lang/crates.io-index)" = "2d315eee3b34aca4797b2da6b13ed88266e6d612562a0c46390af8299fc699bc" "checksum winapi-i686-pc-windows-gnu 0.4.0 (registry+https://github.com/rust-lang/crates.io-index)" = "ac3b87c63620426dd9b991e5ce0329eff545bccbbb34f3be09ff6fb6ab51b7b6" "checksum winapi-x86_64-pc-windows-gnu 0.4.0 (registry+https://github.com/rust-lang/crates.io-index)" = "712e227841d057c1ee1cd2fb22fa7e5a5461ae8e48fa2ca79ec42cfc1931183f" +"checksum wincolor 0.1.6 (registry+https://github.com/rust-lang/crates.io-index)" = "eeb06499a3a4d44302791052df005d5232b927ed1a9658146d842165c4de7767" diff --git a/src/rust/engine/process_executor/Cargo.toml b/src/rust/engine/process_executor/Cargo.toml index 25ba4235d16..f9f6996df13 100644 --- a/src/rust/engine/process_executor/Cargo.toml +++ b/src/rust/engine/process_executor/Cargo.toml @@ -6,6 +6,7 @@ authors = [ "Pants Build " ] [dependencies] boxfuture = { path = "../boxfuture" } clap = "2" +env_logger = "0.5.4" fs = { path = "../fs" } hashing = { path = "../hashing" } futures = "0.1.16" diff --git a/src/rust/engine/process_executor/src/main.rs b/src/rust/engine/process_executor/src/main.rs index b8128f94476..6dc358dda40 100644 --- a/src/rust/engine/process_executor/src/main.rs +++ b/src/rust/engine/process_executor/src/main.rs @@ -1,5 +1,6 @@ extern crate boxfuture; extern crate clap; +extern crate env_logger; extern crate fs; extern crate hashing; extern crate futures; @@ -24,6 +25,8 @@ use std::time::Duration; /// /// It does not perform $PATH lookup or shell expansion. fn main() { + env_logger::init(); + let args = App::new("process_executor") .arg( Arg::with_name("local-store-path") diff --git a/src/rust/engine/src/externs.rs b/src/rust/engine/src/externs.rs index 60444b7e5ee..3fa275e7186 100644 --- a/src/rust/engine/src/externs.rs +++ b/src/rust/engine/src/externs.rs @@ -11,14 +11,9 @@ use std::sync::RwLock; use core::{Failure, Function, Key, TypeConstraint, TypeId, Value}; use handles::Handle; use interning::Interns; +use log; -pub fn log(level: LogLevel, msg: &str) { - with_externs(|e| { - (e.log)(e.context, level as u8, msg.as_ptr(), msg.len() as u64) - }) -} - pub fn eval(python: &str) -> Result { with_externs(|e| { (e.eval)(e.context, python.as_ptr(), python.len() as u64) @@ -192,6 +187,7 @@ pub fn unsafe_call(func: &Function, args: &[Value]) -> Value { lazy_static! { static ref EXTERNS: RwLock> = RwLock::new(None); static ref INTERNS: RwLock = RwLock::new(Interns::new()); + static ref LOGGER: FfiLogger = FfiLogger{}; } /// @@ -201,6 +197,7 @@ lazy_static! { pub fn set_externs(externs: Externs) { let mut externs_ref = EXTERNS.write().unwrap(); *externs_ref = Some(externs); + LOGGER.init(); } fn with_externs(f: F) -> T @@ -325,16 +322,6 @@ pub type ProjectExtern = extern "C" fn(*const ExternContext, *const TypeId) -> Value; -// Not all log levels are always in use. -#[allow(dead_code)] -#[repr(u8)] -pub enum LogLevel { - Debug = 0, - Info = 1, - Warn = 2, - Critical = 3, -} - #[repr(C)] #[derive(Debug)] pub struct PyResult { @@ -500,3 +487,65 @@ where mem::forget(cs); output } + + + + +#[repr(u8)] +enum PythonLogLevel { + Debug = 0, + Info = 1, + Warn = 2, + Critical = 3, +} + +/// +/// FfiLogger is an implementation of log::Log which asks the Python logging system to log via cffi. +/// +struct FfiLogger {} + +impl FfiLogger { + // init must only be called once in the lifetime of the program. No other loggers may be init'd. + // If either of the above are violated, expect a panic. + pub fn init(&'static self) { + log::set_logger(self).expect( + "Failed to set logger (maybe you tried to call init multiple times?)", + ); + + // TODO: Set this to whatever the value Python is using is. + log::set_max_level(log::LevelFilter::Trace); + } +} + +impl log::Log for FfiLogger { + fn enabled(&self, _metadata: &log::Metadata) -> bool { + // TODO: Inspect the current log setting from the python and actually filter. + // This is only used when people call log_enabled! to decide whether to do expensive + // computation before logging, which we don't currently do anywhere. + true + } + + fn log(&self, record: &log::Record) { + if !self.enabled(record.metadata()) { + return; + } + let level = match record.level() { + log::Level::Error => PythonLogLevel::Critical, + log::Level::Warn => PythonLogLevel::Warn, + log::Level::Info => PythonLogLevel::Info, + log::Level::Debug => PythonLogLevel::Debug, + log::Level::Trace => PythonLogLevel::Debug, + }; + let message = format!("{}", record.args()); + with_externs(|e| { + (e.log)( + e.context, + level as u8, + message.as_ptr(), + message.len() as u64, + ) + }) + } + + fn flush(&self) {} +} diff --git a/src/rust/engine/src/lib.rs b/src/rust/engine/src/lib.rs index 691b6246dd8..15a67ab3769 100644 --- a/src/rust/engine/src/lib.rs +++ b/src/rust/engine/src/lib.rs @@ -21,6 +21,8 @@ extern crate futures; extern crate hashing; #[macro_use] extern crate lazy_static; +#[macro_use] +extern crate log; extern crate ordermap; extern crate petgraph; extern crate process_execution; @@ -531,10 +533,10 @@ pub extern "C" fn set_panic_handler() { panic_str.push_str(&panic_location_str); } - externs::log(externs::LogLevel::Critical, &panic_str); + error!("{}", panic_str); let panic_file_bug_str = "Please file a bug at https://github.com/pantsbuild/pants/issues."; - externs::log(externs::LogLevel::Critical, &panic_file_bug_str); + error!("{}", panic_file_bug_str); })); } @@ -545,7 +547,7 @@ pub extern "C" fn garbage_collect_store(scheduler_ptr: *mut Scheduler) { .store .garbage_collect() { Ok(_) => {} - Err(err) => externs::log(externs::LogLevel::Critical, &err), + Err(err) => error!("{}", err), }); } @@ -555,7 +557,7 @@ pub extern "C" fn lease_files_in_graph(scheduler_ptr: *mut Scheduler) { let digests = scheduler.core.graph.all_digests(); match scheduler.core.store.lease_all(digests.iter()) { Ok(_) => {} - Err(err) => externs::log(externs::LogLevel::Critical, &err), + Err(err) => error!("{}", &err), } }); } diff --git a/src/rust/engine/src/scheduler.rs b/src/rust/engine/src/scheduler.rs index 6477c18a047..1cd8d267843 100644 --- a/src/rust/engine/src/scheduler.rs +++ b/src/rust/engine/src/scheduler.rs @@ -10,7 +10,6 @@ use futures::future::{self, Future}; use boxfuture::{Boxable, BoxFuture}; use context::{Context, ContextFactory, Core}; use core::{Failure, Key, TypeConstraint, TypeId, Value}; -use externs::{self, LogLevel}; use graph::EntryId; use nodes::{NodeKey, Select}; use rule_graph; @@ -129,10 +128,7 @@ impl Scheduler { // Otherwise (if it is a success, some other type of Failure, or if we've run // out of retries) recover to complete the join, which will cause the results to // propagate to the user. - externs::log( - LogLevel::Debug, - &format!("Root {} completed.", NodeKey::Select(root).format()), - ); + debug!("Root {} completed.", NodeKey::Select(root).format()); Ok(other) } } @@ -156,10 +152,7 @@ impl Scheduler { request: &'e ExecutionRequest, ) -> Vec<(&'e Key, &'e TypeConstraint, RootResult)> { // Bootstrap tasks for the roots, and then wait for all of them. - externs::log( - LogLevel::Debug, - &format!("Launching {} roots.", request.roots.len()), - ); + debug!("Launching {} roots.", request.roots.len()); // Wait for all roots to complete. Failure here should be impossible, because each // individual Future in the join was (eventually) mapped into success. From 570b0de29268a00ddbfa55ca8f45cf73b4013816 Mon Sep 17 00:00:00 2001 From: Daniel Wagner-Hall Date: Wed, 28 Feb 2018 10:04:44 +0000 Subject: [PATCH 2/2] Remove excess newlines --- src/rust/engine/src/externs.rs | 3 --- 1 file changed, 3 deletions(-) diff --git a/src/rust/engine/src/externs.rs b/src/rust/engine/src/externs.rs index 3fa275e7186..f9c3a022aa7 100644 --- a/src/rust/engine/src/externs.rs +++ b/src/rust/engine/src/externs.rs @@ -488,9 +488,6 @@ where output } - - - #[repr(u8)] enum PythonLogLevel { Debug = 0,