Introduce structured logging

We're enabling the log crate feature everywhere, but only using it on the server for now.

Co-Authored-By: Antonio Scandurra <me@as-cii.com>

Cargo.lock

@@ -614,7 +614,7 @@ dependencies = [
  "cexpr",
  "clang-sys",
  "clap 2.33.3",
- "env_logger",
+ "env_logger 0.8.3",
  "lazy_static",
  "lazycell",
  "log",
@@ -1634,7 +1634,7 @@ dependencies = [
  "clock",
  "collections",
  "ctor",
- "env_logger",
+ "env_logger 0.8.3",
  "futures",
  "fuzzy",
  "gpui",
@@ -1702,6 +1702,15 @@ version = "1.0.1"
 source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "b5320ae4c3782150d900b79807611a59a99fc9a1d61d686faafc24b93fc8d7ca"
 
+[[package]]
+name = "env_logger"
+version = "0.7.1"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "44533bbbb3bb3c1fa17d9f2e4e38bbbaf8396ba82193c4cb1b6445d711445d36"
+dependencies = [
+ "log",
+]
+
 [[package]]
 name = "env_logger"
 version = "0.8.3"
@@ -1724,6 +1733,15 @@ dependencies = [
  "serde",
 ]
 
+[[package]]
+name = "erased-serde"
+version = "0.3.20"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "ad132dd8d0d0b546348d7d86cb3191aad14b34e5f979781fc005c80d4ac67ffd"
+dependencies = [
+ "serde",
+]
+
 [[package]]
 name = "etagere"
 version = "0.2.4"
@@ -1806,7 +1824,7 @@ version = "0.1.0"
 dependencies = [
  "ctor",
  "editor",
- "env_logger",
+ "env_logger 0.8.3",
  "fuzzy",
  "gpui",
  "postage",
@@ -2235,7 +2253,7 @@ dependencies = [
  "core-text",
  "ctor",
  "dhat",
- "env_logger",
+ "env_logger 0.8.3",
  "etagere",
  "font-kit",
  "foreign-types",
@@ -2652,6 +2670,18 @@ dependencies = [
  "wasm-bindgen",
 ]
 
+[[package]]
+name = "json_env_logger"
+version = "0.1.1"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "4e2ec540ea0448b187d3a8b4a9f13e75527d06ef76b3a2baa1cd982aecb62ce2"
+dependencies = [
+ "env_logger 0.7.1",
+ "kv-log-macro",
+ "log",
+ "serde_json",
+]
+
 [[package]]
 name = "jwt-simple"
 version = "0.10.1"
@@ -2715,7 +2745,7 @@ dependencies = [
  "clock",
  "collections",
  "ctor",
- "env_logger",
+ "env_logger 0.8.3",
  "futures",
  "fuzzy",
  "gpui",
@@ -2834,11 +2864,12 @@ dependencies = [
 
 [[package]]
 name = "log"
-version = "0.4.14"
+version = "0.4.16"
 source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "51b9bbe6c47d51fc3e1a9b945965946b4c44142ab8792c50835a980d362c2710"
+checksum = "6389c490849ff5bc16be905ae24bc913a9c8892e19b2341dbc175e14c341c2b8"
 dependencies = [
  "cfg-if 1.0.0",
+ "serde",
  "value-bag",
 ]
 
@@ -2871,7 +2902,7 @@ dependencies = [
  "async-pipe",
  "collections",
  "ctor",
- "env_logger",
+ "env_logger 0.8.3",
  "futures",
  "gpui",
  "log",
@@ -4342,6 +4373,15 @@ dependencies = [
  "syn",
 ]
 
+[[package]]
+name = "serde_fmt"
+version = "1.0.1"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "2963a69a2b3918c1dc75a45a18bd3fcd1120e31d3f59deb1b2f9b5d5ffb8baa4"
+dependencies = [
+ "serde",
+]
+
 [[package]]
 name = "serde_json"
 version = "1.0.64"
@@ -4986,7 +5026,7 @@ version = "0.1.0"
 dependencies = [
  "arrayvec 0.7.1",
  "ctor",
- "env_logger",
+ "env_logger 0.8.3",
  "log",
  "rand 0.8.3",
 ]
@@ -5018,6 +5058,9 @@ name = "sval"
 version = "1.0.0-alpha.5"
 source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "45f6ee7c7b87caf59549e9fe45d6a69c75c8019e79e212a835c5da0e92f0ba08"
+dependencies = [
+ "serde",
+]
 
 [[package]]
 name = "svg_fmt"
@@ -5116,7 +5159,7 @@ dependencies = [
  "clock",
  "collections",
  "ctor",
- "env_logger",
+ "env_logger 0.8.3",
  "gpui",
  "lazy_static",
  "log",
@@ -5704,11 +5747,14 @@ checksum = "bc5cf98d8186244414c848017f0e2676b3fcb46807f6668a97dfe67359a3c4b7"
 
 [[package]]
 name = "value-bag"
-version = "1.0.0-alpha.7"
+version = "1.0.0-alpha.8"
 source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "dd320e1520f94261153e96f7534476ad869c14022aee1e59af7c778075d840ae"
+checksum = "79923f7731dc61ebfba3633098bf3ac533bbd35ccd8c57e7088d9a5eebe0263f"
 dependencies = [
  "ctor",
+ "erased-serde",
+ "serde",
+ "serde_fmt",
  "sval",
  "version_check",
 ]
@@ -6030,7 +6076,7 @@ dependencies = [
  "dirs 3.0.1",
  "easy-parallel",
  "editor",
- "env_logger",
+ "env_logger 0.8.3",
  "file_finder",
  "fsevent",
  "futures",
@@ -6108,16 +6154,18 @@ dependencies = [
  "ctor",
  "editor",
  "either",
- "env_logger",
+ "env_logger 0.8.3",
  "envy",
  "futures",
  "gpui",
  "handlebars",
  "http-auth-basic",
+ "json_env_logger",
  "jwt-simple",
  "language",
  "lazy_static",
  "lipsum",
+ "log",
  "lsp",
  "oauth2",
  "oauth2-surf",

crates/client/Cargo.toml

@@ -21,7 +21,7 @@ async-tungstenite = { version = "0.16", features = ["async-tls"] }
 futures = "0.3"
 image = "0.23"
 lazy_static = "1.4.0"
-log = "0.4"
+log = { version = "0.4.16", features = ["kv_unstable_serde"] }
 parking_lot = "0.11.1"
 postage = { version = "0.4.1", features = ["futures-traits"] }
 rand = "0.8.3"

crates/editor/Cargo.toml

@@ -40,7 +40,7 @@ futures = "0.3"
 indoc = "1.0.4"
 itertools = "0.10"
 lazy_static = "1.4"
-log = "0.4"
+log = { version = "0.4.16", features = ["kv_unstable_serde"] }
 ordered-float = "2.1.1"
 parking_lot = "0.11"
 postage = { version = "0.4", features = ["futures-traits"] }

crates/gpui/Cargo.toml

@@ -25,7 +25,7 @@ etagere = "0.2"
 futures = "0.3"
 image = "0.23"
 lazy_static = "1.4.0"
-log = "0.4"
+log = { version = "0.4.16", features = ["kv_unstable_serde"] }
 num_cpus = "1.13"
 ordered-float = "2.1.1"
 parking = "2.0.0"
@@ -67,6 +67,6 @@ core-graphics = "0.22.2"
 core-text = "19.2"
 font-kit = { git = "https://github.com/zed-industries/font-kit", rev = "8eaf7a918eafa28b0a37dc759e2e0e7683fa24f1" }
 foreign-types = "0.3"
-log = "0.4"
+log = { version = "0.4.16", features = ["kv_unstable_serde"] }
 metal = "0.21.0"
 objc = "0.2"

crates/journal/Cargo.toml

@@ -14,4 +14,4 @@ util = { path = "../util" }
 workspace = { path = "../workspace" }
 chrono = "0.4"
 dirs = "4.0"
-log = "0.4"
+log = { version = "0.4.16", features = ["kv_unstable_serde"] }

crates/language/Cargo.toml

@@ -35,7 +35,7 @@ async-broadcast = "0.3.4"
 async-trait = "0.1"
 futures = "0.3"
 lazy_static = "1.4"
-log = "0.4"
+log = { version = "0.4.16", features = ["kv_unstable_serde"] }
 parking_lot = "0.11.1"
 postage = { version = "0.4.1", features = ["futures-traits"] }
 rand = { version = "0.8.3", optional = true }

crates/lsp/Cargo.toml

@@ -17,7 +17,7 @@ util = { path = "../util" }
 anyhow = "1.0"
 async-pipe = { git = "https://github.com/zed-industries/async-pipe-rs", rev = "82d00a04211cf4e1236029aa03e6b6ce2a74c553", optional = true }
 futures = "0.3"
-log = "0.4"
+log = { version = "0.4.16", features = ["kv_unstable_serde"] }
 lsp-types = "0.91"
 parking_lot = "0.11"
 postage = { version = "0.4.1", features = ["futures-traits"] }

crates/project/Cargo.toml

@@ -35,7 +35,7 @@ futures = "0.3"
 ignore = "0.4"
 lazy_static = "1.4.0"
 libc = "0.2"
-log = "0.4"
+log = { version = "0.4.16", features = ["kv_unstable_serde"] }
 parking_lot = "0.11.1"
 postage = { version = "0.4.1", features = ["futures-traits"] }
 rand = "0.8.3"

crates/rpc/Cargo.toml

@@ -17,7 +17,7 @@ async-lock = "2.4"
 async-tungstenite = "0.16"
 base64 = "0.13"
 futures = "0.3"
-log = "0.4"
+log = { version = "0.4.16", features = ["kv_unstable_serde"] }
 parking_lot = "0.11.1"
 postage = { version = "0.4.1", features = ["futures-traits"] }
 prost = "0.8"

crates/search/Cargo.toml

@@ -18,7 +18,7 @@ theme = { path = "../theme" }
 util = { path = "../util" }
 workspace = { path = "../workspace" }
 anyhow = "1.0"
-log = "0.4"
+log = { version = "0.4.16", features = ["kv_unstable_serde"] }
 postage = { version = "0.4.1", features = ["futures-traits"] }
 
 [dev-dependencies]

crates/server/Cargo.toml

@@ -29,8 +29,10 @@ envy = "0.4.2"
 futures = "0.3"
 handlebars = "3.5"
 http-auth-basic = "0.1.3"
+json_env_logger = "0.1"
 jwt-simple = "0.10.0"
 lipsum = { version = "0.8", optional = true }
+log = { version = "0.4.16", features = ["kv_unstable_serde"] }
 oauth2 = { version = "4.0.0", default_features = false }
 oauth2-surf = "0.1.1"
 parking_lot = "0.11.1"

crates/server/src/home.rs

@@ -1,7 +1,8 @@
 use crate::{AppState, Request, RequestExt as _};
-use serde::Deserialize;
+use log::as_serde;
+use serde::{Deserialize, Serialize};
 use std::sync::Arc;
-use tide::{http::mime, log, Server};
+use tide::{http::mime, Server};
 
 pub fn add_routes(app: &mut Server<Arc<AppState>>) {
     app.at("/").get(get_home);
@@ -18,7 +19,7 @@ async fn get_home(mut request: Request) -> tide::Result {
 }
 
 async fn post_signup(mut request: Request) -> tide::Result {
-    #[derive(Debug, Deserialize)]
+    #[derive(Debug, Deserialize, Serialize)]
     struct Form {
         github_login: String,
         email_address: String,
@@ -38,7 +39,7 @@ async fn post_signup(mut request: Request) -> tide::Result {
         .map(str::to_string)
         .unwrap_or(form.github_login);
 
-    log::info!("Signup submitted: {:?}", form);
+    log::info!(form = as_serde!(form); "signup submitted");
 
     // Save signup in the database
     request

crates/server/src/main.rs

@@ -27,7 +27,7 @@ use rust_embed::RustEmbed;
 use serde::{Deserialize, Serialize};
 use std::sync::Arc;
 use surf::http::cookies::SameSite;
-use tide::{log, sessions::SessionMiddleware};
+use tide::sessions::SessionMiddleware;
 use tide_compress::CompressMiddleware;
 
 type Request = tide::Request<Arc<AppState>>;
@@ -138,7 +138,11 @@ struct LayoutData {
 
 #[async_std::main]
 async fn main() -> tide::Result<()> {
-    log::start();
+    if std::env::var("LOG_JSON").is_ok() {
+        json_env_logger::init();
+    } else {
+        tide::log::start();
+    }
 
     if let Err(error) = env::load_dotenv() {
         log::error!(

crates/server/src/rpc.rs

@@ -11,6 +11,7 @@ use async_std::task;
 use async_tungstenite::{tungstenite::protocol::Role, WebSocketStream};
 use collections::{HashMap, HashSet};
 use futures::{channel::mpsc, future::BoxFuture, FutureExt, SinkExt, StreamExt};
+use log::{as_debug, as_display};
 use parking_lot::{RwLock, RwLockReadGuard, RwLockWriteGuard};
 use rpc::{
     proto::{self, AnyTypedEnvelope, EntityMessage, EnvelopedMessage, RequestMessage},
@@ -25,7 +26,6 @@ use std::{
 };
 use store::{Store, Worktree};
 use surf::StatusCode;
-use tide::log;
 use tide::{
     http::headers::{HeaderName, CONNECTION, UPGRADE},
     Request, Response,
@@ -218,16 +218,16 @@ impl Server {
                         if let Some(message) = message {
                             let start_time = Instant::now();
                             let type_name = message.payload_type_name();
-                            log::info!("rpc message received. connection:{}, type:{}", connection_id, type_name);
+                            log::info!(connection_id = connection_id.0, type_name = type_name; "rpc message received");
                             if let Some(handler) = this.handlers.get(&message.payload_type_id()) {
                                 let notifications = this.notifications.clone();
                                 let is_background = message.is_background();
                                 let handle_message = (handler)(this.clone(), message);
                                 let handle_message = async move {
                                     if let Err(err) = handle_message.await {
-                                        log::error!("rpc message error. connection:{}, type:{}, error:{:?}", connection_id, type_name, err);
+                                        log::error!(connection_id = connection_id.0, type = type_name, error = as_display!(err); "rpc message error");
                                     } else {
-                                        log::info!("rpc message handled. connection:{}, type:{}, duration:{:?}", connection_id, type_name, start_time.elapsed());
+                                        log::info!(connection_id = connection_id.0, type = type_name, duration = as_debug!(start_time.elapsed()); "rpc message handled");
                                     }
                                     if let Some(mut notifications) = notifications {
                                         let _ = notifications.send(()).await;
@@ -242,7 +242,7 @@ impl Server {
                                 log::warn!("unhandled message: {}", type_name);
                             }
                         } else {
-                            log::info!("rpc connection closed {:?}", addr);
+                            log::info!(address = as_debug!(addr); "rpc connection closed");
                             break;
                         }
                     }

crates/sum_tree/Cargo.toml

@@ -9,7 +9,7 @@ doctest = false
 
 [dependencies]
 arrayvec = "0.7.1"
-log = "0.4"
+log = { version = "0.4.16", features = ["kv_unstable_serde"] }
 
 [dev-dependencies]
 ctor = "0.1"

crates/text/Cargo.toml

@@ -17,7 +17,7 @@ sum_tree = { path = "../sum_tree" }
 anyhow = "1.0.38"
 arrayvec = "0.7.1"
 lazy_static = "1.4"
-log = "0.4"
+log = { version = "0.4.16", features = ["kv_unstable_serde"] }
 parking_lot = "0.11"
 postage = { version = "0.4.1", features = ["futures-traits"] }
 rand = { version = "0.8.3", optional = true }

crates/theme_selector/Cargo.toml

@@ -14,7 +14,7 @@ gpui = { path = "../gpui" }
 theme = { path = "../theme" }
 settings = { path = "../settings" }
 workspace = { path = "../workspace" }
-log = "0.4"
+log = { version = "0.4.16", features = ["kv_unstable_serde"] }
 parking_lot = "0.11.1"
 postage = { version = "0.4.1", features = ["futures-traits"] }
 smol = "1.2.5"

crates/theme_selector/src/theme_selector.rs

@@ -7,9 +7,9 @@ use gpui::{
     AppContext, Axis, Element, ElementBox, Entity, MutableAppContext, RenderContext, View,
     ViewContext, ViewHandle,
 };
+use settings::Settings;
 use std::{cmp, sync::Arc};
 use theme::{Theme, ThemeRegistry};
-use settings::Settings;
 use workspace::{
     menu::{Confirm, SelectNext, SelectPrev},
     Workspace,

crates/util/Cargo.toml

@@ -12,7 +12,7 @@ test-support = ["rand", "serde_json", "tempdir"]
 [dependencies]
 anyhow = "1.0.38"
 futures = "0.3"
-log = "0.4"
+log = { version = "0.4.16", features = ["kv_unstable_serde"] }
 rand = { version = "0.8", optional = true }
 surf = "2.2"
 tempdir = { version = "0.3.7", optional = true }

crates/vim/Cargo.toml

@@ -14,7 +14,7 @@ gpui = { path = "../gpui" }
 language = { path = "../language" }
 settings = { path = "../settings" }
 workspace = { path = "../workspace" }
-log = "0.4"
+log = { version = "0.4.16", features = ["kv_unstable_serde"] }
 
 [dev-dependencies]
 indoc = "1.0.4"

crates/workspace/Cargo.toml

@@ -22,7 +22,7 @@ theme = { path = "../theme" }
 util = { path = "../util" }
 anyhow = "1.0.38"
 futures = "0.3"
-log = "0.4"
+log = { version = "0.4.16", features = ["kv_unstable_serde"] }
 parking_lot = "0.11.1"
 postage = { version = "0.4.1", features = ["futures-traits"] }
 serde = { version = "1", features = ["derive", "rc"] }

crates/zed/Cargo.toml

@@ -75,7 +75,7 @@ image = "0.23"
 indexmap = "1.6.2"
 lazy_static = "1.4.0"
 libc = "0.2"
-log = "0.4"
+log = { version = "0.4.16", features = ["kv_unstable_serde"] }
 log-panics = { version = "2.0", features = ["with-backtrace"] }
 num_cpus = "1.13.0"
 parking_lot = "0.11.1"