feat(tvix/store): add logging with tracing

This uses [tracing](https://github.com/tokio-rs/tracing) for logs/
tracing.

Annotate all method handlers with an instrument macro, and warn! a
message for them being unimplemented.

Co-Authored-By: Márton Boros <martonboros@gmail.com>
Change-Id: Id42a41db33782d82abfb8dc0e49a8915000e5d89
Reviewed-on: https://cl.tvl.fyi/c/depot/+/7665
Reviewed-by: tazjin <tazjin@tvl.su>
Tested-by: BuildkiteCI
This commit is contained in:
Florian Klink 2022-12-28 17:17:53 +01:00 committed by flokli
parent 0bf2b0ef11
commit 319c03f634
7 changed files with 327 additions and 10 deletions

68
tvix/Cargo.lock generated
View file

@ -1049,6 +1049,16 @@ dependencies = [
"tempfile",
]
[[package]]
name = "nu-ansi-term"
version = "0.46.0"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "77a8165726e8236064dbb45459242600304b42a5ea24ee2948e18e023bf7ba84"
dependencies = [
"overload",
"winapi",
]
[[package]]
name = "num-traits"
version = "0.2.15"
@ -1104,6 +1114,12 @@ dependencies = [
"winapi",
]
[[package]]
name = "overload"
version = "0.1.1"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "b15813163c1d831bf4a13c3610c05c0d03b39feb07f7e09fa234dac9b15aaf39"
[[package]]
name = "path-clean"
version = "0.1.0"
@ -1646,6 +1662,15 @@ dependencies = [
"serde",
]
[[package]]
name = "sharded-slab"
version = "0.1.4"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "900fba806f70c630b0a382d0d825e17a0f19fcd059a2ade1ff237bcddf446b31"
dependencies = [
"lazy_static",
]
[[package]]
name = "slab"
version = "0.4.7"
@ -1868,6 +1893,15 @@ dependencies = [
"syn 1.0.103",
]
[[package]]
name = "thread_local"
version = "1.1.4"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "5516c27b78311c50bf42c071425c560ac799b11c30b31f87e3081965fe5e0180"
dependencies = [
"once_cell",
]
[[package]]
name = "tinytemplate"
version = "1.2.1"
@ -2084,6 +2118,7 @@ source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "24eb03ba0eab1fd845050058ce5e616558e8f8d8fca633e6b163fe25c797213a"
dependencies = [
"once_cell",
"valuable",
]
[[package]]
@ -2096,6 +2131,31 @@ dependencies = [
"tracing",
]
[[package]]
name = "tracing-log"
version = "0.1.3"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "78ddad33d2d10b1ed7eb9d1f518a5674713876e97e5bb9b7345a7984fbb4f922"
dependencies = [
"lazy_static",
"log",
"tracing-core",
]
[[package]]
name = "tracing-subscriber"
version = "0.3.16"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "a6176eae26dd70d0c919749377897b54a9276bd7061339665dd68777926b5a70"
dependencies = [
"nu-ansi-term",
"sharded-slab",
"smallvec",
"thread_local",
"tracing-core",
"tracing-log",
]
[[package]]
name = "try-lock"
version = "0.2.3"
@ -2172,6 +2232,8 @@ dependencies = [
"tonic",
"tonic-build",
"tonic-reflection",
"tracing",
"tracing-subscriber",
]
[[package]]
@ -2210,6 +2272,12 @@ version = "0.2.0"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "936e4b492acfd135421d8dca4b1aa80a7bfc26e702ef3af710e0752684df5372"
[[package]]
name = "valuable"
version = "0.1.0"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "830b7e5d4d90034032940e4ace0d9a9a057e7a45cd94e6c007832e39edb82f6d"
[[package]]
name = "version_check"
version = "0.9.4"

View file

@ -2729,6 +2729,7 @@ rec {
"sval" = [ "dep:sval" ];
"value-bag" = [ "dep:value-bag" ];
};
resolvedDefaultFeatures = [ "std" ];
};
"matchit" = rec {
crateName = "matchit";
@ -3013,6 +3014,34 @@ rec {
features = { };
resolvedDefaultFeatures = [ "integration_tests" ];
};
"nu-ansi-term" = rec {
crateName = "nu-ansi-term";
version = "0.46.0";
edition = "2018";
sha256 = "115sywxh53p190lyw97alm14nc004qj5jm5lvdj608z84rbida3p";
authors = [
"ogham@bsago.me"
"Ryan Scheel (Havvy) <ryan.havvy@gmail.com>"
"Josh Triplett <josh@joshtriplett.org>"
"The Nushell Project Developers"
];
dependencies = [
{
name = "overload";
packageId = "overload";
}
{
name = "winapi";
packageId = "winapi";
target = { target, features }: ("windows" == target."os");
features = [ "consoleapi" "errhandlingapi" "fileapi" "handleapi" "processenv" ];
}
];
features = {
"derive_serde_style" = [ "serde" ];
"serde" = [ "dep:serde" ];
};
};
"num-traits" = rec {
crateName = "num-traits";
version = "0.2.15";
@ -3154,6 +3183,16 @@ rec {
}
];
};
"overload" = rec {
crateName = "overload";
version = "0.1.1";
edition = "2018";
sha256 = "0fdgbaqwknillagy1xq7xfgv60qdbk010diwl7s1p0qx7hb16n5i";
authors = [
"Daniel Salvadori <danaugrs@gmail.com>"
];
};
"path-clean" = rec {
crateName = "path-clean";
@ -4726,6 +4765,24 @@ rec {
};
resolvedDefaultFeatures = [ "default" "std" ];
};
"sharded-slab" = rec {
crateName = "sharded-slab";
version = "0.1.4";
edition = "2018";
sha256 = "0cbb8kgwsyr3zzhsv8jrs3y1j3vsw4jxil42lfq31ikhdy0bl3wh";
authors = [
"Eliza Weisman <eliza@buoyant.io>"
];
dependencies = [
{
name = "lazy_static";
packageId = "lazy_static";
}
];
features = {
"loom" = [ "dep:loom" ];
};
};
"slab" = rec {
crateName = "slab";
version = "0.4.7";
@ -5283,6 +5340,24 @@ rec {
];
};
"thread_local" = rec {
crateName = "thread_local";
version = "1.1.4";
edition = "2018";
sha256 = "1001bvz6a688wf3izcrh3jqrkiqaarf44wf08azm071ig1xw45jm";
authors = [
"Amanieu d'Antras <amanieu@gmail.com>"
];
dependencies = [
{
name = "once_cell";
packageId = "once_cell";
}
];
features = {
"criterion" = [ "dep:criterion" ];
};
};
"tinytemplate" = rec {
crateName = "tinytemplate";
version = "1.2.1";
@ -6155,6 +6230,13 @@ rec {
packageId = "once_cell";
optional = true;
}
{
name = "valuable";
packageId = "valuable";
optional = true;
usesDefaultFeatures = false;
target = { target, features }: (target."tracing_unstable" or false);
}
];
features = {
"default" = [ "std" "valuable/std" ];
@ -6162,7 +6244,7 @@ rec {
"std" = [ "once_cell" ];
"valuable" = [ "dep:valuable" ];
};
resolvedDefaultFeatures = [ "once_cell" "std" ];
resolvedDefaultFeatures = [ "default" "once_cell" "std" "valuable" ];
};
"tracing-futures" = rec {
crateName = "tracing-futures";
@ -6200,6 +6282,117 @@ rec {
};
resolvedDefaultFeatures = [ "default" "pin-project" "std" "std-future" ];
};
"tracing-log" = rec {
crateName = "tracing-log";
version = "0.1.3";
edition = "2018";
sha256 = "08prnkxq8yas6jvvjnvyx5v3hwblas5527wxxgbiw2yis8rsvpbq";
authors = [
"Tokio Contributors <team@tokio.rs>"
];
dependencies = [
{
name = "lazy_static";
packageId = "lazy_static";
}
{
name = "log";
packageId = "log";
}
{
name = "tracing-core";
packageId = "tracing-core";
}
];
features = {
"ahash" = [ "dep:ahash" ];
"default" = [ "log-tracer" "trace-logger" "std" ];
"env_logger" = [ "dep:env_logger" ];
"interest-cache" = [ "lru" "ahash" ];
"lru" = [ "dep:lru" ];
"std" = [ "log/std" ];
};
resolvedDefaultFeatures = [ "log-tracer" "std" ];
};
"tracing-subscriber" = rec {
crateName = "tracing-subscriber";
version = "0.3.16";
edition = "2018";
sha256 = "0w2sdf97g1ynbmk3j4q6sxmjgaalgf4pg4vl374x0w6x4sp6w5x6";
authors = [
"Eliza Weisman <eliza@buoyant.io>"
"David Barsky <me@davidbarsky.com>"
"Tokio Contributors <team@tokio.rs>"
];
dependencies = [
{
name = "nu-ansi-term";
packageId = "nu-ansi-term";
optional = true;
}
{
name = "sharded-slab";
packageId = "sharded-slab";
optional = true;
}
{
name = "smallvec";
packageId = "smallvec";
optional = true;
}
{
name = "thread_local";
packageId = "thread_local";
optional = true;
}
{
name = "tracing-core";
packageId = "tracing-core";
usesDefaultFeatures = false;
}
{
name = "tracing-log";
packageId = "tracing-log";
optional = true;
usesDefaultFeatures = false;
features = [ "log-tracer" "std" ];
}
];
devDependencies = [
{
name = "tracing-log";
packageId = "tracing-log";
}
];
features = {
"ansi" = [ "fmt" "nu-ansi-term" ];
"default" = [ "smallvec" "fmt" "ansi" "tracing-log" "std" ];
"env-filter" = [ "matchers" "regex" "once_cell" "tracing" "std" "thread_local" ];
"fmt" = [ "registry" "std" ];
"json" = [ "tracing-serde" "serde" "serde_json" ];
"local-time" = [ "time/local-offset" ];
"matchers" = [ "dep:matchers" ];
"nu-ansi-term" = [ "dep:nu-ansi-term" ];
"once_cell" = [ "dep:once_cell" ];
"parking_lot" = [ "dep:parking_lot" ];
"regex" = [ "dep:regex" ];
"registry" = [ "sharded-slab" "thread_local" "std" ];
"serde" = [ "dep:serde" ];
"serde_json" = [ "dep:serde_json" ];
"sharded-slab" = [ "dep:sharded-slab" ];
"smallvec" = [ "dep:smallvec" ];
"std" = [ "alloc" "tracing-core/std" ];
"thread_local" = [ "dep:thread_local" ];
"time" = [ "dep:time" ];
"tracing" = [ "dep:tracing" ];
"tracing-log" = [ "dep:tracing-log" ];
"tracing-serde" = [ "dep:tracing-serde" ];
"valuable" = [ "tracing-core/valuable" "valuable_crate" "valuable-serde" "tracing-serde/valuable" ];
"valuable-serde" = [ "dep:valuable-serde" ];
"valuable_crate" = [ "dep:valuable_crate" ];
};
resolvedDefaultFeatures = [ "alloc" "ansi" "default" "fmt" "nu-ansi-term" "registry" "sharded-slab" "smallvec" "std" "thread_local" "tracing-log" ];
};
"try-lock" = rec {
crateName = "try-lock";
version = "0.2.3";
@ -6482,6 +6675,14 @@ rec {
packageId = "tonic-reflection";
optional = true;
}
{
name = "tracing";
packageId = "tracing";
}
{
name = "tracing-subscriber";
packageId = "tracing-subscriber";
}
];
buildDependencies = [
{
@ -6583,6 +6784,19 @@ rec {
features = { };
resolvedDefaultFeatures = [ "default" ];
};
"valuable" = rec {
crateName = "valuable";
version = "0.1.0";
edition = "2018";
sha256 = "0v9gp3nkjbl30z0fd56d8mx7w1csk86wwjhfjhr400wh9mfpw2w3";
features = {
"default" = [ "std" ];
"derive" = [ "valuable-derive" ];
"std" = [ "alloc" ];
"valuable-derive" = [ "dep:valuable-derive" ];
};
resolvedDefaultFeatures = [ "alloc" "std" ];
};
"version_check" = rec {
crateName = "version_check";
version = "0.9.4";

View file

@ -14,6 +14,8 @@ thiserror = "1.0.38"
tokio = { version = "1.23.0", features = ["rt-multi-thread"] }
tokio-stream = "0.1.11"
tonic = "0.8.2"
tracing-subscriber = "0.3.16"
tracing = "0.1.37"
[dependencies.tonic-reflection]
optional = true

View file

@ -7,6 +7,9 @@ use crate::proto::PutBlobResponse;
use crate::proto::ReadBlobRequest;
use crate::proto::StatBlobRequest;
use tonic::{Request, Response, Result, Status, Streaming};
use tracing::{instrument, warn};
const NOT_IMPLEMENTED_MSG: &str = "not implemented";
pub struct DummyBlobService {}
@ -14,21 +17,27 @@ pub struct DummyBlobService {}
impl BlobService for DummyBlobService {
type ReadStream = ReceiverStream<Result<BlobChunk>>;
#[instrument(skip(self))]
async fn stat(&self, _request: Request<StatBlobRequest>) -> Result<Response<BlobMeta>> {
Err(Status::unimplemented("not implemented"))
warn!(NOT_IMPLEMENTED_MSG);
Err(Status::unimplemented(NOT_IMPLEMENTED_MSG))
}
#[instrument(skip(self))]
async fn read(
&self,
_request: Request<ReadBlobRequest>,
) -> Result<Response<Self::ReadStream>, Status> {
Err(Status::unimplemented("not implemented"))
warn!(NOT_IMPLEMENTED_MSG);
Err(Status::unimplemented(NOT_IMPLEMENTED_MSG))
}
#[instrument(skip(self, _request))]
async fn put(
&self,
_request: Request<Streaming<BlobChunk>>,
) -> Result<Response<PutBlobResponse>> {
Err(Status::unimplemented("not implemented"))
warn!(NOT_IMPLEMENTED_MSG);
Err(Status::unimplemented(NOT_IMPLEMENTED_MSG))
}
}

View file

@ -5,6 +5,9 @@ use crate::proto::Directory;
use crate::proto::GetDirectoryRequest;
use crate::proto::PutDirectoryResponse;
use tonic::{Request, Response, Result, Status, Streaming};
use tracing::{instrument, warn};
const NOT_IMPLEMENTED_MSG: &str = "not implemented";
pub struct DummyDirectoryService {}
@ -12,17 +15,21 @@ pub struct DummyDirectoryService {}
impl DirectoryService for DummyDirectoryService {
type GetStream = ReceiverStream<Result<Directory>>;
#[instrument(skip(self))]
async fn get(
&self,
_request: Request<GetDirectoryRequest>,
) -> Result<Response<Self::GetStream>, Status> {
Err(Status::unimplemented("not implemented"))
warn!(NOT_IMPLEMENTED_MSG);
Err(Status::unimplemented(NOT_IMPLEMENTED_MSG))
}
#[instrument(skip(self, _request))]
async fn put(
&self,
_request: Request<Streaming<Directory>>,
) -> Result<Response<PutDirectoryResponse>> {
Err(Status::unimplemented("not implemented"))
warn!(NOT_IMPLEMENTED_MSG);
Err(Status::unimplemented(NOT_IMPLEMENTED_MSG))
}
}

View file

@ -4,23 +4,32 @@ use crate::proto::GetPathInfoRequest;
use crate::proto::Node;
use crate::proto::PathInfo;
use tonic::{Request, Response, Result, Status};
use tracing::{instrument, warn};
pub struct DummyPathInfoService {}
const NOT_IMPLEMENTED_MSG: &str = "not implemented";
#[tonic::async_trait]
impl PathInfoService for DummyPathInfoService {
#[instrument(skip(self))]
async fn get(&self, _request: Request<GetPathInfoRequest>) -> Result<Response<PathInfo>> {
Err(Status::unimplemented("not implemented"))
warn!(NOT_IMPLEMENTED_MSG);
Err(Status::unimplemented(NOT_IMPLEMENTED_MSG))
}
#[instrument(skip(self))]
async fn put(&self, _request: Request<PathInfo>) -> Result<Response<PathInfo>> {
Err(Status::unimplemented("not implemented"))
warn!(NOT_IMPLEMENTED_MSG);
Err(Status::unimplemented(NOT_IMPLEMENTED_MSG))
}
#[instrument(skip(self))]
async fn calculate_nar(
&self,
_request: Request<Node>,
) -> Result<Response<CalculateNarResponse>> {
Err(Status::unimplemented("not implemented"))
warn!(NOT_IMPLEMENTED_MSG);
Err(Status::unimplemented(NOT_IMPLEMENTED_MSG))
}
}

View file

@ -7,6 +7,7 @@ use crate::proto::FILE_DESCRIPTOR_SET;
use clap::Parser;
use tonic::{transport::Server, Result};
use tracing::{info, Level};
mod dummy_blob_service;
mod dummy_directory_service;
@ -23,6 +24,9 @@ mod tests;
struct Cli {
#[clap(long, short = 'l')]
listen_address: Option<String>,
#[clap(long)]
log_level: Option<Level>,
}
#[tokio::main]
@ -34,6 +38,10 @@ async fn main() -> Result<(), Box<dyn std::error::Error>> {
.parse()
.unwrap();
let level = cli.log_level.unwrap_or(Level::INFO);
let subscriber = tracing_subscriber::fmt().with_max_level(level).finish();
tracing::subscriber::set_global_default(subscriber).ok();
let mut server = Server::builder();
let blob_service = dummy_blob_service::DummyBlobService {};
@ -53,7 +61,7 @@ async fn main() -> Result<(), Box<dyn std::error::Error>> {
router = router.add_service(reflection_svc);
}
println!("tvix-store listening on {}", listen_address);
info!("tvix-store listening on {}", listen_address);
router.serve(listen_address).await?;