diff --git a/Cargo.lock b/Cargo.lock index a1ae7289c..50b55eee3 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -1,5 +1,13 @@ # This file is automatically @generated by Cargo. # It is not intended for manual editing. +[[package]] +name = "aho-corasick" +version = "0.7.10" +source = "registry+https://github.com/rust-lang/crates.io-index" +dependencies = [ + "memchr 2.3.3 (registry+https://github.com/rust-lang/crates.io-index)", +] + [[package]] name = "arc-swap" version = "0.4.5" @@ -15,6 +23,16 @@ dependencies = [ "syn 1.0.17 (registry+https://github.com/rust-lang/crates.io-index)", ] +[[package]] +name = "atty" +version = "0.2.14" +source = "registry+https://github.com/rust-lang/crates.io-index" +dependencies = [ + "hermit-abi 0.1.10 (registry+https://github.com/rust-lang/crates.io-index)", + "libc 0.2.68 (registry+https://github.com/rust-lang/crates.io-index)", + "winapi 0.3.8 (registry+https://github.com/rust-lang/crates.io-index)", +] + [[package]] name = "autocfg" version = "1.0.0" @@ -25,15 +43,6 @@ name = "base64" version = "0.11.0" source = "registry+https://github.com/rust-lang/crates.io-index" -[[package]] -name = "bincode" -version = "1.2.1" -source = "registry+https://github.com/rust-lang/crates.io-index" -dependencies = [ - "byteorder 1.3.4 (registry+https://github.com/rust-lang/crates.io-index)", - "serde 1.0.106 (registry+https://github.com/rust-lang/crates.io-index)", -] - [[package]] name = "bitflags" version = "1.2.1" @@ -155,6 +164,18 @@ dependencies = [ "generic-array 0.12.3 (registry+https://github.com/rust-lang/crates.io-index)", ] +[[package]] +name = "env_logger" +version = "0.7.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +dependencies = [ + "atty 0.2.14 (registry+https://github.com/rust-lang/crates.io-index)", + "humantime 1.3.0 (registry+https://github.com/rust-lang/crates.io-index)", + "log 0.4.8 (registry+https://github.com/rust-lang/crates.io-index)", + "regex 1.3.7 (registry+https://github.com/rust-lang/crates.io-index)", + "termcolor 1.1.0 (registry+https://github.com/rust-lang/crates.io-index)", +] + [[package]] name = "err-derive" version = "0.2.3" @@ -297,7 +318,6 @@ version = "0.1.0" dependencies = [ "arc-swap 0.4.5 (registry+https://github.com/rust-lang/crates.io-index)", "async-trait 0.1.30 (registry+https://github.com/rust-lang/crates.io-index)", - "bincode 1.2.1 (registry+https://github.com/rust-lang/crates.io-index)", "bytes 0.4.12 (registry+https://github.com/rust-lang/crates.io-index)", "err-derive 0.2.3 (registry+https://github.com/rust-lang/crates.io-index)", "futures 0.3.4 (registry+https://github.com/rust-lang/crates.io-index)", @@ -309,8 +329,9 @@ dependencies = [ "http 0.2.1 (registry+https://github.com/rust-lang/crates.io-index)", "hyper 0.13.4 (registry+https://github.com/rust-lang/crates.io-index)", "hyper-rustls 0.20.0 (registry+https://github.com/rust-lang/crates.io-index)", + "log 0.4.8 (registry+https://github.com/rust-lang/crates.io-index)", + "pretty_env_logger 0.4.0 (registry+https://github.com/rust-lang/crates.io-index)", "rand 0.7.3 (registry+https://github.com/rust-lang/crates.io-index)", - "reduce 0.1.2 (registry+https://github.com/rust-lang/crates.io-index)", "rmp-serde 0.14.3 (registry+https://github.com/rust-lang/crates.io-index)", "rustls 0.17.0 (registry+https://github.com/rust-lang/crates.io-index)", "serde 1.0.106 (registry+https://github.com/rust-lang/crates.io-index)", @@ -415,6 +436,14 @@ name = "httparse" version = "1.3.4" source = "registry+https://github.com/rust-lang/crates.io-index" +[[package]] +name = "humantime" +version = "1.3.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +dependencies = [ + "quick-error 1.2.3 (registry+https://github.com/rust-lang/crates.io-index)", +] + [[package]] name = "hyper" version = "0.13.4" @@ -681,6 +710,15 @@ name = "ppv-lite86" version = "0.2.6" source = "registry+https://github.com/rust-lang/crates.io-index" +[[package]] +name = "pretty_env_logger" +version = "0.4.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +dependencies = [ + "env_logger 0.7.1 (registry+https://github.com/rust-lang/crates.io-index)", + "log 0.4.8 (registry+https://github.com/rust-lang/crates.io-index)", +] + [[package]] name = "proc-macro-error" version = "0.4.12" @@ -723,6 +761,11 @@ dependencies = [ "unicode-xid 0.2.0 (registry+https://github.com/rust-lang/crates.io-index)", ] +[[package]] +name = "quick-error" +version = "1.2.3" +source = "registry+https://github.com/rust-lang/crates.io-index" + [[package]] name = "quote" version = "1.0.3" @@ -774,8 +817,19 @@ version = "0.1.56" source = "registry+https://github.com/rust-lang/crates.io-index" [[package]] -name = "reduce" -version = "0.1.2" +name = "regex" +version = "1.3.7" +source = "registry+https://github.com/rust-lang/crates.io-index" +dependencies = [ + "aho-corasick 0.7.10 (registry+https://github.com/rust-lang/crates.io-index)", + "memchr 2.3.3 (registry+https://github.com/rust-lang/crates.io-index)", + "regex-syntax 0.6.17 (registry+https://github.com/rust-lang/crates.io-index)", + "thread_local 1.0.1 (registry+https://github.com/rust-lang/crates.io-index)", +] + +[[package]] +name = "regex-syntax" +version = "0.6.17" source = "registry+https://github.com/rust-lang/crates.io-index" [[package]] @@ -1002,6 +1056,14 @@ dependencies = [ "unicode-xid 0.2.0 (registry+https://github.com/rust-lang/crates.io-index)", ] +[[package]] +name = "termcolor" +version = "1.1.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +dependencies = [ + "winapi-util 0.1.5 (registry+https://github.com/rust-lang/crates.io-index)", +] + [[package]] name = "textwrap" version = "0.11.0" @@ -1010,6 +1072,14 @@ dependencies = [ "unicode-width 0.1.7 (registry+https://github.com/rust-lang/crates.io-index)", ] +[[package]] +name = "thread_local" +version = "1.0.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +dependencies = [ + "lazy_static 1.4.0 (registry+https://github.com/rust-lang/crates.io-index)", +] + [[package]] name = "time" version = "0.1.42" @@ -1230,6 +1300,14 @@ name = "winapi-i686-pc-windows-gnu" version = "0.4.0" source = "registry+https://github.com/rust-lang/crates.io-index" +[[package]] +name = "winapi-util" +version = "0.1.5" +source = "registry+https://github.com/rust-lang/crates.io-index" +dependencies = [ + "winapi 0.3.8 (registry+https://github.com/rust-lang/crates.io-index)", +] + [[package]] name = "winapi-x86_64-pc-windows-gnu" version = "0.4.0" @@ -1245,11 +1323,12 @@ dependencies = [ ] [metadata] +"checksum aho-corasick 0.7.10 (registry+https://github.com/rust-lang/crates.io-index)" = "8716408b8bc624ed7f65d223ddb9ac2d044c0547b6fa4b0d554f3a9540496ada" "checksum arc-swap 0.4.5 (registry+https://github.com/rust-lang/crates.io-index)" = "d663a8e9a99154b5fb793032533f6328da35e23aac63d5c152279aa8ba356825" "checksum async-trait 0.1.30 (registry+https://github.com/rust-lang/crates.io-index)" = "da71fef07bc806586090247e971229289f64c210a278ee5ae419314eb386b31d" +"checksum atty 0.2.14 (registry+https://github.com/rust-lang/crates.io-index)" = "d9b39be18770d11421cdb1b9947a45dd3f37e93092cbf377614828a319d5fee8" "checksum autocfg 1.0.0 (registry+https://github.com/rust-lang/crates.io-index)" = "f8aac770f1885fd7e387acedd76065302551364496e46b3dd00860b2f8359b9d" "checksum base64 0.11.0 (registry+https://github.com/rust-lang/crates.io-index)" = "b41b7ea54a0c9d92199de89e20e58d49f02f8e699814ef3fdf266f6f748d15c7" -"checksum bincode 1.2.1 (registry+https://github.com/rust-lang/crates.io-index)" = "5753e2a71534719bf3f4e57006c3a4f0d2c672a4b676eec84161f763eca87dbf" "checksum bitflags 1.2.1 (registry+https://github.com/rust-lang/crates.io-index)" = "cf1de2fe8c75bc145a2f577add951f8134889b4795d47466a54a5c846d691693" "checksum block-buffer 0.7.3 (registry+https://github.com/rust-lang/crates.io-index)" = "c0940dc441f31689269e10ac70eb1002a3a1d3ad1390e030043662eb7fe4688b" "checksum block-padding 0.1.5 (registry+https://github.com/rust-lang/crates.io-index)" = "fa79dedbb091f449f1f39e53edf88d5dbe95f895dae6135a8d7b881fb5af73f5" @@ -1266,6 +1345,7 @@ dependencies = [ "checksum crossbeam-epoch 0.8.2 (registry+https://github.com/rust-lang/crates.io-index)" = "058ed274caafc1f60c4997b5fc07bf7dc7cca454af7c6e81edffe5f33f70dace" "checksum crossbeam-utils 0.7.2 (registry+https://github.com/rust-lang/crates.io-index)" = "c3c7c73a2d1e9fc0886a08b93e98eb643461230d5f1925e4036204d5f2e261a8" "checksum digest 0.8.1 (registry+https://github.com/rust-lang/crates.io-index)" = "f3d0c8c8752312f9713efd397ff63acb9f85585afbf179282e720e7704954dd5" +"checksum env_logger 0.7.1 (registry+https://github.com/rust-lang/crates.io-index)" = "44533bbbb3bb3c1fa17d9f2e4e38bbbaf8396ba82193c4cb1b6445d711445d36" "checksum err-derive 0.2.3 (registry+https://github.com/rust-lang/crates.io-index)" = "82f46c91bbed409ee74495549acbfcc7fae856e712e1df15afe75d0775eedc6c" "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" @@ -1292,6 +1372,7 @@ dependencies = [ "checksum http 0.2.1 (registry+https://github.com/rust-lang/crates.io-index)" = "28d569972648b2c512421b5f2a405ad6ac9666547189d0c5477a3f200f3e02f9" "checksum http-body 0.3.1 (registry+https://github.com/rust-lang/crates.io-index)" = "13d5ff830006f7646652e057693569bfe0d51760c0085a071769d142a205111b" "checksum httparse 1.3.4 (registry+https://github.com/rust-lang/crates.io-index)" = "cd179ae861f0c2e53da70d892f5f3029f9594be0c41dc5269cd371691b1dc2f9" +"checksum humantime 1.3.0 (registry+https://github.com/rust-lang/crates.io-index)" = "df004cfca50ef23c36850aaaa59ad52cc70d0e90243c3c7737a4dd32dc7a3c4f" "checksum hyper 0.13.4 (registry+https://github.com/rust-lang/crates.io-index)" = "ed6081100e960d9d74734659ffc9cc91daf1c0fc7aceb8eaa94ee1a3f5046f2e" "checksum hyper-rustls 0.20.0 (registry+https://github.com/rust-lang/crates.io-index)" = "ac965ea399ec3a25ac7d13b8affd4b8f39325cca00858ddf5eb29b79e6b14b08" "checksum indexmap 1.3.2 (registry+https://github.com/rust-lang/crates.io-index)" = "076f042c5b7b98f31d205f1249267e12a6518c1481e9dae9764af19b707d2292" @@ -1322,18 +1403,21 @@ dependencies = [ "checksum pin-project-lite 0.1.4 (registry+https://github.com/rust-lang/crates.io-index)" = "237844750cfbb86f67afe27eee600dfbbcb6188d734139b534cbfbf4f96792ae" "checksum pin-utils 0.1.0-alpha.4 (registry+https://github.com/rust-lang/crates.io-index)" = "5894c618ce612a3fa23881b152b608bafb8c56cfc22f434a3ba3120b40f7b587" "checksum ppv-lite86 0.2.6 (registry+https://github.com/rust-lang/crates.io-index)" = "74490b50b9fbe561ac330df47c08f3f33073d2d00c150f719147d7c54522fa1b" +"checksum pretty_env_logger 0.4.0 (registry+https://github.com/rust-lang/crates.io-index)" = "926d36b9553851b8b0005f1275891b392ee4d2d833852c417ed025477350fb9d" "checksum proc-macro-error 0.4.12 (registry+https://github.com/rust-lang/crates.io-index)" = "18f33027081eba0a6d8aba6d1b1c3a3be58cbb12106341c2d5759fcd9b5277e7" "checksum proc-macro-error-attr 0.4.12 (registry+https://github.com/rust-lang/crates.io-index)" = "8a5b4b77fdb63c1eca72173d68d24501c54ab1269409f6b672c85deb18af69de" "checksum proc-macro-hack 0.5.15 (registry+https://github.com/rust-lang/crates.io-index)" = "0d659fe7c6d27f25e9d80a1a094c223f5246f6a6596453e09d7229bf42750b63" "checksum proc-macro-nested 0.1.4 (registry+https://github.com/rust-lang/crates.io-index)" = "8e946095f9d3ed29ec38de908c22f95d9ac008e424c7bcae54c75a79c527c694" "checksum proc-macro2 1.0.10 (registry+https://github.com/rust-lang/crates.io-index)" = "df246d292ff63439fea9bc8c0a270bed0e390d5ebd4db4ba15aba81111b5abe3" +"checksum quick-error 1.2.3 (registry+https://github.com/rust-lang/crates.io-index)" = "a1d01941d82fa2ab50be1e79e6714289dd7cde78eba4c074bc5a4374f650dfe0" "checksum quote 1.0.3 (registry+https://github.com/rust-lang/crates.io-index)" = "2bdc6c187c65bca4260c9011c9e3132efe4909da44726bad24cf7572ae338d7f" "checksum rand 0.7.3 (registry+https://github.com/rust-lang/crates.io-index)" = "6a6b1679d49b24bbfe0c803429aa1874472f50d9b363131f0e89fc356b544d03" "checksum rand_chacha 0.2.2 (registry+https://github.com/rust-lang/crates.io-index)" = "f4c8ed856279c9737206bf725bf36935d8666ead7aa69b52be55af369d193402" "checksum rand_core 0.5.1 (registry+https://github.com/rust-lang/crates.io-index)" = "90bde5296fc891b0cef12a6d03ddccc162ce7b2aff54160af9338f8d40df6d19" "checksum rand_hc 0.2.0 (registry+https://github.com/rust-lang/crates.io-index)" = "ca3129af7b92a17112d59ad498c6f81eaf463253766b90396d39ea7a39d6613c" "checksum redox_syscall 0.1.56 (registry+https://github.com/rust-lang/crates.io-index)" = "2439c63f3f6139d1b57529d16bc3b8bb855230c8efcc5d3a896c8bea7c3b1e84" -"checksum reduce 0.1.2 (registry+https://github.com/rust-lang/crates.io-index)" = "75b1fa5668b02f2a69746bba558f8f98cc087b123a587fd959122872ad9a3f3c" +"checksum regex 1.3.7 (registry+https://github.com/rust-lang/crates.io-index)" = "a6020f034922e3194c711b82a627453881bc4682166cabb07134a10c26ba7692" +"checksum regex-syntax 0.6.17 (registry+https://github.com/rust-lang/crates.io-index)" = "7fe5bd57d1d7414c6b5ed48563a2c855d995ff777729dcd91c369ec7fea395ae" "checksum ring 0.16.12 (registry+https://github.com/rust-lang/crates.io-index)" = "1ba5a8ec64ee89a76c98c549af81ff14813df09c3e6dc4766c3856da48597a0c" "checksum rmp 0.8.9 (registry+https://github.com/rust-lang/crates.io-index)" = "0f10b46df14cf1ee1ac7baa4d2fbc2c52c0622a4b82fa8740e37bc452ac0184f" "checksum rmp-serde 0.14.3 (registry+https://github.com/rust-lang/crates.io-index)" = "4c1ee98f14fe8b8e9c5ea13d25da7b2a1796169202c57a09d7288de90d56222b" @@ -1358,7 +1442,9 @@ dependencies = [ "checksum syn 1.0.17 (registry+https://github.com/rust-lang/crates.io-index)" = "0df0eb663f387145cab623dea85b09c2c5b4b0aef44e945d928e682fce71bb03" "checksum syn-mid 0.5.0 (registry+https://github.com/rust-lang/crates.io-index)" = "7be3539f6c128a931cf19dcee741c1af532c7fd387baa739c03dd2e96479338a" "checksum synstructure 0.12.3 (registry+https://github.com/rust-lang/crates.io-index)" = "67656ea1dc1b41b1451851562ea232ec2e5a80242139f7e679ceccfb5d61f545" +"checksum termcolor 1.1.0 (registry+https://github.com/rust-lang/crates.io-index)" = "bb6bfa289a4d7c5766392812c0a1f4c1ba45afa1ad47803c11e1f407d846d75f" "checksum textwrap 0.11.0 (registry+https://github.com/rust-lang/crates.io-index)" = "d326610f408c7a4eb6f51c37c330e496b08506c9457c9d34287ecc38809fb060" +"checksum thread_local 1.0.1 (registry+https://github.com/rust-lang/crates.io-index)" = "d40c6d1b69745a6ec6fb1ca717914848da4b44ae29d9b3080cbee91d72a69b14" "checksum time 0.1.42 (registry+https://github.com/rust-lang/crates.io-index)" = "db8dcfca086c1143c9270ac42a2bbd8a7ee477b78ac8e45b19abfb0cbede4b6f" "checksum tokio 0.2.16 (registry+https://github.com/rust-lang/crates.io-index)" = "ee5a0dd887e37d37390c13ff8ac830f992307fe30a1fff0ab8427af67211ba28" "checksum tokio-macros 0.2.5 (registry+https://github.com/rust-lang/crates.io-index)" = "f0c3acc6aa564495a0f2e1d59fab677cd7f81a19994cfc7f3ad0e64301560389" @@ -1386,5 +1472,6 @@ dependencies = [ "checksum winapi 0.3.8 (registry+https://github.com/rust-lang/crates.io-index)" = "8093091eeb260906a183e6ae1abdba2ef5ef2257a21801128899c3fc699229c6" "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-util 0.1.5 (registry+https://github.com/rust-lang/crates.io-index)" = "70ec6ce85bb158151cae5e5c87f95a8e97d2c0c4b001223f33a334e3ce5de178" "checksum winapi-x86_64-pc-windows-gnu 0.4.0 (registry+https://github.com/rust-lang/crates.io-index)" = "712e227841d057c1ee1cd2fb22fa7e5a5461ae8e48fa2ca79ec42cfc1931183f" "checksum ws2_32-sys 0.2.1 (registry+https://github.com/rust-lang/crates.io-index)" = "d59cefebd0c892fa2dd6de581e937301d8552cb44489cdff035c6187cb63fa5e" diff --git a/Cargo.toml b/Cargo.toml index 72528b987..e6c27b4ae 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -8,35 +8,39 @@ edition = "2018" [dependencies] bytes = "0.4" -http = "0.2" -hyper = "0.13" +rand = "0.7" +hex = "0.3" +sha2 = "0.8" +arc-swap = "0.4" +gethostname = "0.2" +err-derive = "0.2.3" +log = "0.4" +pretty_env_logger = "0.4" + sled = "0.31" + +structopt = { version = "0.3", default-features = false } +toml = "0.5" +rmp-serde = "0.14.3" +serde = { version = "1.0", features = ["derive", "rc"] } +serde_bytes = "0.11" +serde_json = "1.0" + +async-trait = "0.1.30" futures = "0.3" futures-core = "0.3" futures-channel = "0.3" futures-util = "0.3" tokio = { version = "0.2", features = ["full"] } -serde = { version = "1.0", features = ["derive", "rc"] } -serde_bytes = "0.11" -bincode = "1.2.1" -err-derive = "0.2.3" -rmp-serde = "0.14.3" -toml = "0.5" -structopt = { version = "0.3", default-features = false } -rand = "0.7" -hex = "0.3" -sha2 = "0.8" -async-trait = "0.1.30" -reduce = "0.1.2" -serde_json = "1.0" -arc-swap = "0.4" -gethostname = "0.2" +http = "0.2" +hyper = "0.13" rustls = "0.17" tokio-rustls = "0.13" hyper-rustls = { version = "0.20", default-features = false } webpki = "0.21" + [profile.dev] lto = "off" diff --git a/README.md b/README.md index 337fdb815..cc6402e58 100644 --- a/README.md +++ b/README.md @@ -3,3 +3,9 @@ THIS IS ALL WORK IN PROGRESS. NOTHING TO SEE YET BUT THANKS FOR YOUR INTEREST. Garage implements an S3-compatible object store with high resiliency to network failures, machine failure, and sysadmin failure. + +## To log: + +``` +RUST_LOG=garage=debug cargo run --release -- server -c config_file.toml +``` diff --git a/src/admin_rpc.rs b/src/admin_rpc.rs index 125f897ea..0e9d2338a 100644 --- a/src/admin_rpc.rs +++ b/src/admin_rpc.rs @@ -222,12 +222,15 @@ impl AdminRpcHandler { let version_exists = match object { Some(o) => o.versions.iter().any(|x| x.uuid == version.uuid), None => { - eprintln!("No object entry found for version {:?}", version); + warn!( + "Repair versions: object for version {:?} not found", + version + ); false } }; if !version_exists { - eprintln!("Marking deleted version: {:?}", version); + info!("Repair versions: marking version as deleted: {:?}", version); self.garage .version_table .insert(&Version { @@ -265,12 +268,18 @@ impl AdminRpcHandler { let ref_exists = match version { Some(v) => !v.deleted, None => { - eprintln!("No version found for block ref {:?}", block_ref); + warn!( + "Block ref repair: version for block ref {:?} not found", + block_ref + ); false } }; if !ref_exists { - eprintln!("Marking deleted block_ref: {:?}", block_ref); + info!( + "Repair block ref: marking block_ref as deleted: {:?}", + block_ref + ); self.garage .block_ref_table .insert(&BlockRef { diff --git a/src/api_server.rs b/src/api_server.rs index fbff7b2f6..6487d5fe9 100644 --- a/src/api_server.rs +++ b/src/api_server.rs @@ -42,7 +42,7 @@ pub async fn run_api_server( let server = Server::bind(&addr).serve(service); let graceful = server.with_graceful_shutdown(shutdown_signal); - println!("API server listening on http://{}", addr); + info!("API server listening on http://{}", addr); graceful.await?; Ok(()) @@ -69,7 +69,7 @@ async fn handler_inner( req: Request, addr: SocketAddr, ) -> Result, Error> { - eprintln!("{} {} {}", addr, req.method(), req.uri()); + info!("{} {} {}", addr, req.method(), req.uri()); let bucket = req .headers() @@ -231,7 +231,7 @@ impl BodyChunker { while !self.read_all && self.buf.len() < self.block_size { if let Some(block) = self.body.next().await { let bytes = block?; - eprintln!("Body next: {} bytes", bytes.len()); + trace!("Body next: {} bytes", bytes.len()); self.buf.extend(&bytes[..]); } else { self.read_all = true; diff --git a/src/background.rs b/src/background.rs index b9a4684a2..1f04e49b3 100644 --- a/src/background.rs +++ b/src/background.rs @@ -77,9 +77,9 @@ impl BackgroundRunner { let stop_signal = self.stop_signal.clone(); workers.push(tokio::spawn(async move { if let Err(e) = worker(stop_signal).await { - eprintln!("Worker stopped with error: {}, error: {}", name, e); + error!("Worker stopped with error: {}, error: {}", name, e); } else { - println!("Worker exited successfully: {}", name); + info!("Worker exited successfully: {}", name); } })); } @@ -90,11 +90,11 @@ impl BackgroundRunner { let must_exit: bool = *stop_signal.borrow(); if let Some(job) = self.dequeue_job(must_exit).await { if let Err(e) = job.await { - eprintln!("Job failed: {}", e) + error!("Job failed: {}", e) } } else { if must_exit { - eprintln!("Background runner {} exiting", i); + info!("Background runner {} exiting", i); return; } tokio::time::delay_for(Duration::from_secs(1)).await; diff --git a/src/block.rs b/src/block.rs index 81b111ce9..ec29db128 100644 --- a/src/block.rs +++ b/src/block.rs @@ -153,7 +153,7 @@ impl BlockManager { if data::hash(&data[..]) != *hash { let _lock = self.lock.lock().await; - eprintln!("Block {:?} is corrupted. Deleting and resyncing.", hash); + warn!("Block {:?} is corrupted. Deleting and resyncing.", hash); fs::remove_file(path).await?; self.put_to_resync(&hash, 0)?; return Err(Error::CorruptData(hash.clone())); @@ -211,7 +211,7 @@ impl BlockManager { fn put_to_resync(&self, hash: &Hash, delay_millis: u64) -> Result<(), Error> { let when = now_msec() + delay_millis; - eprintln!("Put resync_queue: {} {:?}", when, hash); + trace!("Put resync_queue: {} {:?}", when, hash); let mut key = u64::to_be_bytes(when).to_vec(); key.extend(hash.as_ref()); self.resync_queue.insert(key, hash.as_ref())?; @@ -222,7 +222,7 @@ impl BlockManager { while !*must_exit.borrow() { if let Some((time_bytes, hash_bytes)) = self.resync_queue.pop_min()? { let time_msec = u64_from_bytes(&time_bytes[0..8]); - eprintln!( + trace!( "First in resync queue: {} (now = {})", time_msec, now_msec() @@ -233,7 +233,7 @@ impl BlockManager { let hash = Hash::from(hash); if let Err(e) = self.resync_iter(&hash).await { - eprintln!("Failed to resync block {:?}, retrying later: {}", hash, e); + warn!("Failed to resync block {:?}, retrying later: {}", hash, e); self.put_to_resync(&hash, RESYNC_RETRY_TIMEOUT.as_millis() as u64)?; } continue; @@ -256,10 +256,12 @@ impl BlockManager { .map(|x| u64_from_bytes(x.as_ref()) > 0) .unwrap_or(false); - eprintln!( - "Resync block {:?}: exists {}, needed {}", - hash, exists, needed - ); + if exists != needed { + info!( + "Resync block {:?}: exists {}, needed {}", + hash, exists, needed + ); + } if exists && !needed { let garage = self.garage.load_full().unwrap(); @@ -396,7 +398,7 @@ impl BlockManager { let mut ls_data_dir_2 = match fs::read_dir(data_dir_ent.path()).await { Err(e) => { - eprintln!( + warn!( "Warning: could not list dir {:?}: {}", data_dir_ent.path().to_str(), e diff --git a/src/main.rs b/src/main.rs index 11890e571..9b75740de 100644 --- a/src/main.rs +++ b/src/main.rs @@ -1,5 +1,8 @@ #![recursion_limit = "1024"] +#[macro_use] +extern crate log; + mod data; mod error; @@ -190,6 +193,8 @@ pub struct RepairOpt { #[tokio::main] async fn main() { + pretty_env_logger::init(); + let opt = Opt::from_args(); let tls_config = match (opt.ca_cert, opt.client_cert, opt.client_key) { @@ -200,7 +205,7 @@ async fn main() { }), (None, None, None) => None, _ => { - eprintln!("Missing one of: --ca-cert, --node-cert, --node-key. Not using TLS."); + warn!("Missing one of: --ca-cert, --node-cert, --node-key. Not using TLS."); None } }; @@ -215,7 +220,7 @@ async fn main() { Command::Server(server_opt) => { // Abort on panic (same behavior as in Go) std::panic::set_hook(Box::new(|panic_info| { - eprintln!("{}", panic_info.to_string()); + error!("{}", panic_info.to_string()); std::process::abort(); })); @@ -237,7 +242,7 @@ async fn main() { }; if let Err(e) = resp { - eprintln!("Error: {}", e); + error!("Error: {}", e); } } @@ -414,7 +419,7 @@ async fn cmd_admin( println!("{:?}", bucket); } r => { - eprintln!("Unexpected response: {:?}", r); + error!("Unexpected response: {:?}", r); } } Ok(()) diff --git a/src/membership.rs b/src/membership.rs index 193b59360..6f6dd47d5 100644 --- a/src/membership.rs +++ b/src/membership.rs @@ -133,7 +133,7 @@ impl Status { ); match old_status { None => { - eprintln!("Newly pingable node: {}", hex::encode(&info.id)); + info!("Newly pingable node: {}", hex::encode(&info.id)); true } Some(x) => x.addr != addr, @@ -145,12 +145,12 @@ impl Status { nodes.sort_unstable_by_key(|(id, _status)| *id); let mut hasher = Sha256::new(); - eprintln!("Current set of pingable nodes: --"); + debug!("Current set of pingable nodes: --"); for (id, status) in nodes { - eprintln!("{} {}", hex::encode(&id), status.addr); + debug!("{} {}", hex::encode(&id), status.addr); hasher.input(format!("{} {}\n", hex::encode(&id), status.addr)); } - eprintln!("END --"); + debug!("END --"); self.hash .as_slice_mut() .copy_from_slice(&hasher.result()[..]); @@ -263,7 +263,7 @@ impl System { let net_config = match read_network_config(&config.metadata_dir) { Ok(x) => x, Err(e) => { - println!( + info!( "No valid previous network configuration stored ({}), starting fresh.", e ); @@ -448,7 +448,7 @@ impl System { .map(|x| x.remaining_ping_attempts) .unwrap_or(0); if remaining_attempts == 0 { - eprintln!( + warn!( "Removing node {} after too many failed pings", hex::encode(&id) ); @@ -465,7 +465,7 @@ impl System { status.recalculate_hash(); } if let Err(e) = update_locked.0.broadcast(Arc::new(status)) { - eprintln!("In ping_nodes: could not save status update ({})", e); + error!("In ping_nodes: could not save status update ({})", e); } drop(update_locked); diff --git a/src/rpc_client.rs b/src/rpc_client.rs index b2a0cf221..2b9944029 100644 --- a/src/rpc_client.rs +++ b/src/rpc_client.rs @@ -221,7 +221,7 @@ impl RpcHttpClient { let resp = tokio::time::timeout(timeout, resp_fut) .await? .map_err(|e| { - eprintln!( + warn!( "RPC HTTP client error when connecting to {}: {}", to_addr, e ); diff --git a/src/rpc_server.rs b/src/rpc_server.rs index f78c27f11..4541e4daf 100644 --- a/src/rpc_server.rs +++ b/src/rpc_server.rs @@ -1,6 +1,7 @@ use std::collections::HashMap; use std::net::SocketAddr; use std::pin::Pin; +use std::time::Instant; use std::sync::Arc; use bytes::IntoBuf; @@ -36,17 +37,21 @@ async fn handle_func( handler: Arc, req: Request, sockaddr: SocketAddr, + name: Arc, ) -> Result, Error> where M: RpcMessage + 'static, F: Fn(M, SocketAddr) -> Fut + Send + Sync + 'static, Fut: Future> + Send + 'static, { + let begin_time = Instant::now(); let whole_body = hyper::body::to_bytes(req.into_body()).await?; let msg = rmp_serde::decode::from_read::<_, M>(whole_body.into_buf())?; + let req_str = debug_serialize(&msg); match handler(msg, sockaddr).await { Ok(resp) => { let resp_bytes = rmp_to_vec_all_named::>(&Ok(resp))?; + trace!("]RPC:{},ok ({} ms)", name, (Instant::now()-begin_time).as_millis()); Ok(Response::new(Body::from(resp_bytes))) } Err(e) => { @@ -54,6 +59,7 @@ where let rep_bytes = rmp_to_vec_all_named::>(&Err(err_str))?; let mut err_response = Response::new(Body::from(rep_bytes)); *err_response.status_mut() = e.http_status_code(); + warn!("RPC error ({}): {} ({} ms), request: {}", name, e, (Instant::now()-begin_time).as_millis(), req_str); Ok(err_response) } } @@ -74,10 +80,11 @@ impl RpcServer { F: Fn(M, SocketAddr) -> Fut + Send + Sync + 'static, Fut: Future> + Send + 'static, { + let name2 = Arc::new(name.clone()); let handler_arc = Arc::new(handler); let handler = Box::new(move |req: Request, sockaddr: SocketAddr| { let handler2 = handler_arc.clone(); - let b: ResponseFuture = Box::pin(handle_func(handler2, req, sockaddr)); + let b: ResponseFuture = Box::pin(handle_func(handler2, req, sockaddr, name2.clone())); b }); self.handlers.insert(name, handler); @@ -107,7 +114,7 @@ impl RpcServer { let resp_waiter = tokio::spawn(handler(req, addr)); match resp_waiter.await { Err(err) => { - eprintln!("Handler await error: {}", err); + warn!("Handler await error: {}", err); let mut ise = Response::default(); *ise.status_mut() = StatusCode::INTERNAL_SERVER_ERROR; Ok(ise) @@ -163,7 +170,7 @@ impl RpcServer { async move { Ok::<_, Error>(service_fn(move |req: Request| { self_arc.clone().handler(req, client_addr).map_err(|e| { - eprintln!("RPC handler error: {}", e); + warn!("RPC handler error: {}", e); e }) })) @@ -173,7 +180,7 @@ impl RpcServer { let server = Server::builder(incoming).serve(service); let graceful = server.with_graceful_shutdown(shutdown_signal); - println!("RPC server listening on http://{}", self.bind_addr); + info!("RPC server listening on http://{}", self.bind_addr); graceful.await?; } else { @@ -184,7 +191,7 @@ impl RpcServer { async move { Ok::<_, Error>(service_fn(move |req: Request| { self_arc.clone().handler(req, client_addr).map_err(|e| { - eprintln!("RPC handler error: {}", e); + warn!("RPC handler error: {}", e); e }) })) @@ -194,7 +201,7 @@ impl RpcServer { let server = Server::bind(&self.bind_addr).serve(service); let graceful = server.with_graceful_shutdown(shutdown_signal); - println!("RPC server listening on http://{}", self.bind_addr); + info!("RPC server listening on http://{}", self.bind_addr); graceful.await?; } diff --git a/src/server.rs b/src/server.rs index 464d550bd..542c8675f 100644 --- a/src/server.rs +++ b/src/server.rs @@ -87,10 +87,10 @@ impl Garage { background: Arc, rpc_server: &mut RpcServer, ) -> Arc { - println!("Initialize membership management system..."); + info!("Initialize membership management system..."); let system = System::new(config.clone(), id, background.clone(), rpc_server); - println!("Initialize block manager..."); + info!("Initialize block manager..."); let block_manager = BlockManager::new(&db, config.data_dir.clone(), system.clone(), rpc_server); @@ -111,7 +111,7 @@ impl Garage { (system.config.meta_epidemic_factor + 1) / 2, ); - println!("Initialize block_ref_table..."); + info!("Initialize block_ref_table..."); let block_ref_table = Table::new( BlockRefTable { background: background.clone(), @@ -125,7 +125,7 @@ impl Garage { ) .await; - println!("Initialize version_table..."); + info!("Initialize version_table..."); let version_table = Table::new( VersionTable { background: background.clone(), @@ -139,7 +139,7 @@ impl Garage { ) .await; - println!("Initialize object_table..."); + info!("Initialize object_table..."); let object_table = Table::new( ObjectTable { background: background.clone(), @@ -153,7 +153,7 @@ impl Garage { ) .await; - println!("Initialize bucket_table..."); + info!("Initialize bucket_table..."); let bucket_table = Table::new( BucketTable, control_rep_param.clone(), @@ -164,7 +164,7 @@ impl Garage { ) .await; - println!("Initialize Garage..."); + info!("Initialize Garage..."); let garage = Arc::new(Self { db, system: system.clone(), @@ -176,10 +176,10 @@ impl Garage { block_ref_table, }); - println!("Crate admin RPC handler..."); + info!("Crate admin RPC handler..."); AdminRpcHandler::new(garage.clone()).register_handler(rpc_server); - println!("Start block manager background thread..."); + info!("Start block manager background thread..."); garage.block_manager.garage.swap(Some(garage.clone())); garage.block_manager.clone().spawn_background_worker().await; @@ -226,7 +226,7 @@ async fn shutdown_signal(send_cancel: watch::Sender) -> Result<(), Error> tokio::signal::ctrl_c() .await .expect("failed to install CTRL+C signal handler"); - println!("Received CTRL+C, shutting down."); + info!("Received CTRL+C, shutting down."); send_cancel.broadcast(true)?; Ok(()) } @@ -240,51 +240,51 @@ async fn wait_from(mut chan: watch::Receiver) -> () { } pub async fn run_server(config_file: PathBuf) -> Result<(), Error> { - println!("Loading configuration..."); + info!("Loading configuration..."); let config = read_config(config_file).expect("Unable to read config file"); let id = gen_node_id(&config.metadata_dir).expect("Unable to read or generate node ID"); - println!("Node ID: {}", hex::encode(&id)); + info!("Node ID: {}", hex::encode(&id)); - println!("Opening database..."); + info!("Opening database..."); let mut db_path = config.metadata_dir.clone(); db_path.push("db"); let db = sled::open(db_path).expect("Unable to open DB"); - println!("Initialize RPC server..."); + info!("Initialize RPC server..."); let mut rpc_server = RpcServer::new(config.rpc_bind_addr.clone(), config.rpc_tls.clone()); - println!("Initializing background runner..."); + info!("Initializing background runner..."); let (send_cancel, watch_cancel) = watch::channel(false); let background = BackgroundRunner::new(8, watch_cancel.clone()); let garage = Garage::new(config, id, db, background.clone(), &mut rpc_server).await; - println!("Initializing RPC and API servers..."); + info!("Initializing RPC and API servers..."); let run_rpc_server = Arc::new(rpc_server).run(wait_from(watch_cancel.clone())); let api_server = api_server::run_api_server(garage.clone(), wait_from(watch_cancel.clone())); futures::try_join!( garage.system.clone().bootstrap().map(|rv| { - println!("Bootstrap done"); + info!("Bootstrap done"); Ok(rv) }), run_rpc_server.map(|rv| { - println!("RPC server exited"); + info!("RPC server exited"); rv }), api_server.map(|rv| { - println!("API server exited"); + info!("API server exited"); rv }), background.run().map(|rv| { - println!("Background runner exited"); + info!("Background runner exited"); Ok(rv) }), shutdown_signal(send_cancel), )?; - println!("Cleaning up..."); + info!("Cleaning up..."); Ok(()) } diff --git a/src/table.rs b/src/table.rs index d9b505c96..8bcb3c66b 100644 --- a/src/table.rs +++ b/src/table.rs @@ -489,7 +489,7 @@ where pub async fn delete_range(&self, begin: &Hash, end: &Hash) -> Result<(), Error> { let syncer = self.syncer.load_full().unwrap(); - eprintln!("({}) Deleting range {:?} - {:?}", self.name, begin, end); + debug!("({}) Deleting range {:?} - {:?}", self.name, begin, end); let mut count = 0; while let Some((key, _value)) = self.store.get_lt(end.as_slice())? { if key.as_ref() < begin.as_slice() { @@ -504,7 +504,7 @@ where count += 1; } } - eprintln!("({}) {} entries deleted", self.name, count); + debug!("({}) {} entries deleted", self.name, count); Ok(()) } diff --git a/src/table_sync.rs b/src/table_sync.rs index a750e04ee..cb6d87aa9 100644 --- a/src/table_sync.rs +++ b/src/table_sync.rs @@ -134,7 +134,7 @@ where select! { new_ring_r = s_ring_recv => { if let Some(new_ring) = new_ring_r { - eprintln!("({}) Adding ring difference to syncer todo list", self.table.name); + debug!("({}) Adding ring difference to syncer todo list", self.table.name); self.todo.lock().await.add_ring_difference(&self.table, &prev_ring, &new_ring); prev_ring = new_ring; } @@ -158,7 +158,7 @@ where _ = s_timeout => { if nothing_to_do_since.map(|t| Instant::now() - t >= SCAN_INTERVAL).unwrap_or(false) { nothing_to_do_since = None; - eprintln!("({}) Adding full scan to syncer todo list", self.table.name); + debug!("({}) Adding full scan to syncer todo list", self.table.name); self.todo.lock().await.add_full_scan(&self.table); } } @@ -180,7 +180,7 @@ where .sync_partition(&partition, &mut must_exit) .await; if let Err(e) = res { - eprintln!( + warn!( "({}) Error while syncing {:?}: {}", self.table.name, partition, e ); @@ -198,7 +198,7 @@ where partition: &TodoPartition, must_exit: &mut watch::Receiver, ) -> Result<(), Error> { - eprintln!("({}) Preparing to sync {:?}...", self.table.name, partition); + debug!("({}) Preparing to sync {:?}...", self.table.name, partition); let root_cks = self .root_checksum(&partition.begin, &partition.end, must_exit) .await?; @@ -226,7 +226,7 @@ where while let Some(r) = sync_futures.next().await { if let Err(e) = r { n_errors += 1; - eprintln!("({}) Sync error: {}", self.table.name, e); + warn!("({}) Sync error: {}", self.table.name, e); } } if n_errors > self.table.replication.max_write_errors() { @@ -284,7 +284,7 @@ where drop(cache); let v = self.range_checksum_inner(&range, must_exit).await?; - eprintln!( + trace!( "({}) New checksum calculated for {}-{}/{}, {} children", self.table.name, hex::encode(&range.begin[..]), @@ -418,7 +418,7 @@ where while !todo.is_empty() && !*must_exit.borrow() { let total_children = todo.iter().map(|x| x.children.len()).fold(0, |x, y| x + y); - eprintln!( + trace!( "({}) Sync with {:?}: {} ({}) remaining", self.table.name, who, @@ -442,7 +442,7 @@ where rpc_resp { if diff_ranges.len() > 0 || diff_items.len() > 0 { - eprintln!( + info!( "({}) Sync with {:?}: difference {} ranges, {} items", self.table.name, who, @@ -479,7 +479,7 @@ where } async fn send_items(self: Arc, who: UUID, item_list: Vec>) -> Result<(), Error> { - eprintln!( + info!( "({}) Sending {} items to {:?}", self.table.name, item_list.len(), @@ -594,7 +594,7 @@ where .map(|x| x.children.len()) .fold(0, |x, y| x + y); if ret_ranges.len() > 0 || ret_items.len() > 0 { - eprintln!( + trace!( "({}) Checksum comparison RPC: {} different + {} items for {} received", self.table.name, ret_ranges.len(),