Configure logging (-vv for debug level logs)

6 files changed, 126 insertions, 57 deletions

diff --git a/Cargo.lock b/Cargo.lock
index 29a86a36..bc3da508 100644
--- a/Cargo.lock
+++ b/Cargo.lock
@@ -209,6 +209,19 @@ source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "4785bdd1c96b2a846b2bd7cc02e86b6b3dbf14e7e53446c4f54c92a361040822"
 
 [[package]]
+name = "chrono"
+version = "0.4.19"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "670ad68c9088c2a963aaa298cb369688cf3f9465ce5e2d4ca10e6e0098a1ce73"
+dependencies = [
+ "libc",
+ "num-integer",
+ "num-traits",
+ "time",
+ "winapi",
+]
+
+[[package]]
 name = "clap"
 version = "3.0.0-beta.2"
 source = "registry+https://github.com/rust-lang/crates.io-index"
@@ -321,6 +334,15 @@ dependencies = [
 ]
 
 [[package]]
+name = "fern"
+version = "0.6.0"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "8c9a4820f0ccc8a7afd67c39a0f1a0f4b07ca1725164271a64939d7aeb9af065"
+dependencies = [
+ "log",
+]
+
+[[package]]
 name = "futf"
 version = "0.1.4"
 source = "registry+https://github.com/rust-lang/crates.io-index"
@@ -408,7 +430,7 @@ checksum = "fc587bc0ec293155d5bfa6b9891ec18a1e330c234f896ea47fbada4cadbe47e6"
 dependencies = [
  "cfg-if",
  "libc",
- "wasi",
+ "wasi 0.9.0+wasi-snapshot-preview1",
 ]
 
 [[package]]
@@ -449,6 +471,7 @@ dependencies = [
  "helix-core",
  "helix-view",
  "jsonrpc-core",
+ "log",
  "lsp-types",
  "pathdiff",
  "serde",
@@ -472,12 +495,15 @@ name = "helix-term"
 version = "0.1.0"
 dependencies = [
  "anyhow",
+ "chrono",
  "clap",
  "crossterm",
+ "fern",
  "futures-util",
  "helix-core",
  "helix-lsp",
  "helix-view",
+ "log",
  "num_cpus",
  "smol",
  "tui",
@@ -673,6 +699,25 @@ dependencies = [
 ]
 
 [[package]]
+name = "num-integer"
+version = "0.1.43"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "8d59457e662d541ba17869cf51cf177c0b5f0cbf476c66bdc90bf1edac4f875b"
+dependencies = [
+ "autocfg",
+ "num-traits",
+]
+
+[[package]]
+name = "num-traits"
+version = "0.2.12"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "ac267bcc07f48ee5f8935ab0d24f316fb722d7a1292e2913f0cc196b29ffd611"
+dependencies = [
+ "autocfg",
+]
+
+[[package]]
 name = "num_cpus"
 version = "1.13.0"
 source = "registry+https://github.com/rust-lang/crates.io-index"
@@ -997,9 +1042,9 @@ dependencies = [
 
 [[package]]
 name = "syn"
-version = "1.0.45"
+version = "1.0.46"
 source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "ea9c5432ff16d6152371f808fb5a871cd67368171b09bb21b43df8e4a47a3556"
+checksum = "5ad5de3220ea04da322618ded2c42233d02baca219d6f160a3e9c87cda16c942"
 dependencies = [
  "proc-macro2",
  "quote",
@@ -1055,6 +1100,17 @@ dependencies = [
 ]
 
 [[package]]
+name = "time"
+version = "0.1.44"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "6db9e6914ab8b1ae1c260a4ae7a49b6c5611b40328a735b21862567685e73255"
+dependencies = [
+ "libc",
+ "wasi 0.10.0+wasi-snapshot-preview1",
+ "winapi",
+]
+
+[[package]]
 name = "tinyvec"
 version = "0.3.4"
 source = "registry+https://github.com/rust-lang/crates.io-index"
@@ -1161,6 +1217,12 @@ source = "registry+https://github.com/rust-lang/crates.io-index"
 checksum = "cccddf32554fecc6acb585f82a32a72e28b48f8c4c1883ddfeeeaa96f7d8e519"
 
 [[package]]
+name = "wasi"
+version = "0.10.0+wasi-snapshot-preview1"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "1a143597ca7c7793eff794def352d41792a93c481eb1042423ff7ff72ba2c31f"
+
+[[package]]
 name = "wepoll-sys"
 version = "3.0.1"
 source = "registry+https://github.com/rust-lang/crates.io-index"
diff --git a/helix-lsp/Cargo.toml b/helix-lsp/Cargo.toml
index 351c3b0e..ffd909a4 100644
--- a/helix-lsp/Cargo.toml
+++ b/helix-lsp/Cargo.toml
@@ -13,12 +13,13 @@ helix-view = { path = "../helix-view" }
 lsp-types = { version = "0.82", features = ["proposed"] }
 smol = "1.2"
 url = "2"
-pathdiff = "0.2.0"
-shellexpand = "2.0.0"
+pathdiff = "0.2"
+shellexpand = "2.0"
 glob = "0.3"
 anyhow = "1"
 serde_json = "1.0"
 serde = { version = "1.0", features = ["derive"] }
 jsonrpc-core = "15.1"
 futures-util = "0.3"
-thiserror = "1.0.21"
+thiserror = "1"
+log = "0.4"
diff --git a/helix-lsp/log b/helix-lsp/log
deleted file mode 100644
index d8370f16..00000000
--- a/helix-lsp/log
+++ /dev/null
@@ -1,45 +0,0 @@
-Sun Oct 18 21:15:33 2020:["lsp#register_server", "server registered", "typescript-language-server"]
-Sun Oct 18 21:15:33 2020:["lsp#register_server", "server registered", "elixir-ls"]
-Sun Oct 18 21:15:33 2020:["lsp#register_server", "server registered", "vue-language-server"]
-Sun Oct 18 21:15:33 2020:["lsp#register_server", "server registered", "rust-analyzer"]
-Sun Oct 18 21:15:33 2020:["s:on_text_document_did_open()", 1, "", "/Users/speed/src/helix/helix-lsp", ""]
-Sun Oct 18 21:15:34 2020:["s:on_text_document_did_close()", 1]
-Sun Oct 18 21:15:34 2020:["s:on_text_document_did_open()", 1, "rust", "/Users/speed/src/helix", "file:///Users/speed/src/helix/helix-lsp/src/lib.rs"]
-Sun Oct 18 21:15:34 2020:["Starting server", "rust-analyzer", ["rust-analyzer"]]
-Sun Oct 18 21:15:34 2020:[{"response": {"data": {"__data__": "vim-lsp", "lsp_id": 7, "server_name": "rust-analyzer"}, "message": "started lsp server successfully"}}]
-Sun Oct 18 21:15:34 2020:["--->", 7, "rust-analyzer", {"method": "initialize", "params": {"rootUri": "file:///Users/speed/src/helix/helix-lsp", "capabilities": {"workspace": {"configuration": true, "applyEdit": true}, "textDocument": {"implementation": {"linkSupport": true}, "documentSymbol": {"symbolKind": {"valueSet": [10, 11, 12, 13, 14, 15, 16, 17, 18, 19, 20, 21, 22, 23, 24, 25, 26, 1, 2, 3, 4, 5, 6, 7, 8, 9]}, "hierarchicalDocumentSymbolSupport": false}, "semanticHighlightingCapabilities": {"semanticHighlighting": false}, "codeAction": {"codeActionLiteralSupport": {"codeActionKind": {"valueSet": ["", "quickfix", "refactor", "refactor.extract", "refactor.inline", "refactor.rewrite", "source", "source.organizeImports"]}}, "dynamicRegistration": false}, "completion": {"completionItem": {"snippetSupport": false, "documentationFormat": ["plaintext"]}, "completionItemKind": {"valueSet": [10, 11, 12, 13, 14, 15, 16, 17, 18, 19, 20, 21, 22, 23, 24, 25, 1, 2, 3, 4, 5, 6, 7, 8, 9]}}, "foldingRange": {"lineFoldingOnly": true}, "typeDefinition": {"linkSupport": true}, "typeHierarchy": false, "declaration": {"linkSupport": true}, "definition": {"linkSupport": true}}}, "rootPath": "/Users/speed/src/helix/helix-lsp", "processId": 22973, "trace": "off"}}]
-Sun Oct 18 21:15:34 2020:["<---", 7, "rust-analyzer", {"response": {"id": 1, "jsonrpc": "2.0", "result": {"capabilities": {"documentHighlightProvider": true, "hoverProvider": true, "typeDefinitionProvider": true, "workspaceSymbolProvider": true, "referencesProvider": true, "signatureHelpProvider": {"triggerCharacters": ["(", ","]}, "foldingRangeProvider": true, "callHierarchyProvider": true, "codeActionProvider": {"codeActionKinds": ["", "quickfix", "refactor", "refactor.extract", "refactor.inline", "refactor.rewrite"]}, "textDocumentSync": {"save": {}, "change": 2, "openClose": true}, "codeLensProvider": {"resolveProvider": true}, "implementationProvider": true, "documentOnTypeFormattingProvider": {"moreTriggerCharacter": [".", ">"], "firstTriggerCharacter": "="}, "definitionProvider": true, "selectionRangeProvider": true, "semanticTokensProvider": {"legend": {"tokenTypes": ["comment", "keyword", "string", "number", "regexp", "operator", "namespace", "type", "struct", "class", "interface", "enum", "typeParameter", "function", "member", "property", "macro", "variable", "parameter", "label", "attribute", "boolean", "builtinType", "enumMember", "escapeSequence", "formatSpecifier", "generic", "lifetime", "punctuation", "selfKeyword", "typeAlias", "union", "unresolvedReference"], "tokenModifiers": ["documentation", "declaration", "definition", "static", "abstract", "deprecated", "readonly", "constant", "controlFlow", "injected", "mutable", "unsafe", "attribute"]}, "documentProvider": true, "rangeProvider": true}, "documentFormattingProvider": true, "documentSymbolProvider": true, "experimental": {"parentModule": true, "onEnter": true, "runnables": {"kinds": ["cargo"]}, "ssr": true, "joinLines": true}, "renameProvider": {"prepareProvider": true}, "completionProvider": {"triggerCharacters": [":", "."]}}, "serverInfo": {"version": "???????", "name": "rust-analyzer"}}}, "request": {"id": 1, "jsonrpc": "2.0", "method": "initialize", "params": {"rootUri": "file:///Users/speed/src/helix/helix-lsp", "capabilities": {"workspace": {"configuration": true, "applyEdit": true}, "textDocument": {"implementation": {"linkSupport": true}, "documentSymbol": {"symbolKind": {"valueSet": [10, 11, 12, 13, 14, 15, 16, 17, 18, 19, 20, 21, 22, 23, 24, 25, 26, 1, 2, 3, 4, 5, 6, 7, 8, 9]}, "hierarchicalDocumentSymbolSupport": false}, "semanticHighlightingCapabilities": {"semanticHighlighting": false}, "codeAction": {"codeActionLiteralSupport": {"codeActionKind": {"valueSet": ["", "quickfix", "refactor", "refactor.extract", "refactor.inline", "refactor.rewrite", "source", "source.organizeImports"]}}, "dynamicRegistration": false}, "completion": {"completionItem": {"snippetSupport": false, "documentationFormat": ["plaintext"]}, "completionItemKind": {"valueSet": [10, 11, 12, 13, 14, 15, 16, 17, 18, 19, 20, 21, 22, 23, 24, 25, 1, 2, 3, 4, 5, 6, 7, 8, 9]}}, "foldingRange": {"lineFoldingOnly": true}, "typeDefinition": {"linkSupport": true}, "typeHierarchy": false, "declaration": {"linkSupport": true}, "definition": {"linkSupport": true}}}, "rootPath": "/Users/speed/src/helix/helix-lsp", "processId": 22973, "trace": "off"}}}]
-Sun Oct 18 21:15:34 2020:["--->", 7, "rust-analyzer", {"method": "initialized", "params": {}}]
-Sun Oct 18 21:15:34 2020:[{"response": {"data": {"__data__": "vim-lsp", "server_name": "rust-analyzer"}, "message": "configuration sent"}}]
-Sun Oct 18 21:15:34 2020:["s:update_file_content()", 1]
-Sun Oct 18 21:15:34 2020:["--->", 7, "rust-analyzer", {"method": "textDocument/didOpen", "params": {"textDocument": {"uri": "file:///Users/speed/src/helix/helix-lsp/src/lib.rs", "version": 1, "languageId": "rust", "text": "use std::collections::HashMap;\n\nuse jsonrpc_core as jsonrpc;\nuse lsp_types as lsp;\n\nuse serde::{Deserialize, Serialize};\nuse serde_json::Value;\n\nuse smol::channel::{Receiver, Sender};\nuse smol::io::{BufReader, BufWriter};\nuse smol::prelude::*;\nuse smol::process::{Child, ChildStderr, ChildStdin, ChildStdout, Command, Stdio};\nuse smol::Executor;\n\nuse futures_util::{select, FutureExt};\n\n/// A type representing all possible values sent from the server to the client.\n#[derive(Debug, PartialEq, Clone, Deserialize, Serialize)]\n#[serde(deny_unknown_fields)]\n#[serde(untagged)]\nenum Message {\n    /// A regular JSON-RPC request output (single response).\n    Output(jsonrpc::Output),\n    /// A notification.\n    Notification(jsonrpc::Notification),\n    /// A JSON-RPC request\n    Call(jsonrpc::Call),\n}\n\npub struct Client {\n    process: Child,\n    stderr: BufReader<ChildStderr>,\n    outgoing: Sender<Payload>,\n\n    pub request_counter: u64,\n\n    capabilities: Option<lsp::ServerCapabilities>,\n}\n\nimpl Client {\n    pub fn start(ex: &Executor, cmd: &str, args: &[String]) -> Self {\n        let mut process = Command::new(cmd)\n            .args(args)\n            .stdin(Stdio::piped())\n            .stdout(Stdio::piped())\n            .stderr(Stdio::piped())\n            .spawn()\n            .expect(\"Failed to start language server\");\n        // smol makes sure the process is reaped on drop, but using kill_on_drop(true) maybe?\n\n        // TODO: do we need bufreader/writer here? or do we use async wrappers on unblock?\n        let writer = BufWriter::new(process.stdin.take().expect(\"Failed to open stdin\"));\n        let reader = BufReader::new(process.stdout.take().expect(\"Failed to open stdout\"));\n        let stderr = BufReader::new(process.stderr.take().expect(\"Failed to open stderr\"));\n\n        let (incoming, outgoing) = Transport::start(ex, reader, writer);\n\n        Client {\n            process,\n            stderr,\n            outgoing,\n\n            request_counter: 0,\n\n            capabilities: None,\n        }\n    }\n\n    fn next_request_id(&mut self) -> jsonrpc::Id {\n        let id = jsonrpc::Id::Num(self.request_counter);\n        self.request_counter += 1;\n        id\n    }\n\n    fn to_params(value: Value) -> anyhow::Result<jsonrpc::Params> {\n        use jsonrpc::Params;\n\n        let params = match value {\n            Value::Null => Params::None,\n            Value::Bool(_) | Value::Number(_) | Value::String(_) => Params::Array(vec![value]),\n            Value::Array(vec) => Params::Array(vec),\n            Value::Object(map) => Params::Map(map),\n        };\n\n        Ok(params)\n    }\n\n    pub async fn request<R: lsp::request::Request>(\n        &mut self,\n        params: R::Params,\n    ) -> anyhow::Result<R::Result>\n    where\n        R::Params: serde::Serialize,\n        R::Result: core::fmt::Debug, // TODO: temporary\n    {\n        let params = serde_json::to_value(params)?;\n\n        let request = jsonrpc::MethodCall {\n            jsonrpc: Some(jsonrpc::Version::V2),\n            id: self.next_request_id(),\n            method: R::METHOD.to_string(),\n            params: Self::to_params(params)?,\n        };\n\n        let (tx, rx) = smol::channel::bounded::<anyhow::Result<Value>>(1);\n\n        self.outgoing\n            .send(Payload::Request {\n                chan: tx,\n                value: request,\n            })\n            .await?;\n\n        let response = rx.recv().await??;\n\n        let response = serde_json::from_value(response)?;\n\n        // TODO: we should pass request to a sender thread via a channel\n        // so it can't be interleaved\n\n        // TODO: responses can be out of order, we need to register a single shot response channel\n\n        Ok(response)\n    }\n\n    pub async fn notify<R: lsp::notification::Notification>(\n        &mut self,\n        params: R::Params,\n    ) -> anyhow::Result<()>\n    where\n        R::Params: serde::Serialize,\n    {\n        let params = serde_json::to_value(params)?;\n\n        let notification = jsonrpc::Notification {\n            jsonrpc: Some(jsonrpc::Version::V2),\n            method: R::METHOD.to_string(),\n            params: Self::to_params(params)?,\n        };\n\n        self.outgoing\n            .send(Payload::Notification(notification))\n            .await?;\n\n        Ok(())\n    }\n\n    // -------------------------------------------------------------------------------------------\n    // General messages\n    // -------------------------------------------------------------------------------------------\n\n    pub async fn initialize(&mut self) -> anyhow::Result<()> {\n        // TODO: delay any requests that are triggered prior to initialize\n\n        #[allow(deprecated)]\n        let params = lsp::InitializeParams {\n            process_id: Some(u64::from(std::process::id())),\n            root_path: None,\n            // root_uri: Some(lsp_types::Url::parse(\"file://localhost/\")?),\n            root_uri: None, // set to project root in the future\n            initialization_options: None,\n            capabilities: lsp::ClientCapabilities::default(),\n            trace: None,\n            workspace_folders: None,\n            client_info: None,\n        };\n\n        let response = self.request::<lsp::request::Initialize>(params).await?;\n        self.capabilities = Some(response.capabilities);\n\n        // next up, notify<initialized>\n        self.notify::<lsp::notification::Initialized>(lsp::InitializedParams {})\n            .await?;\n\n        Ok(())\n    }\n\n    pub async fn shutdown(&mut self) -> anyhow::Result<()> {\n        self.request::<lsp::request::Shutdown>(()).await\n    }\n\n    pub async fn exit(&mut self) -> anyhow::Result<()> {\n        self.notify::<lsp::notification::Exit>(()).await\n    }\n\n    // -------------------------------------------------------------------------------------------\n    // Text document\n    // -------------------------------------------------------------------------------------------\n\n    pub async fn text_document_did_open(\n        &mut self,\n        state: &helix_core::State,\n    ) -> anyhow::Result<()> {\n        self.notify::<lsp::notification::DidOpenTextDocument>(lsp::DidOpenTextDocumentParams {\n            text_document: lsp::TextDocumentItem {\n                uri: lsp::Url::from_file_path(\n                    std::fs::canonicalize(state.path.as_ref().unwrap()).unwrap(),\n                )\n                .unwrap(),\n                language_id: \"rust\".to_string(), // TODO: hardcoded for now\n                version: 0,\n                text: String::from(&state.doc),\n            },\n        })\n        .await\n    }\n\n    // TODO: trigger any time history.commit_revision happens\n    pub async fn text_document_did_change(\n        &mut self,\n        state: &helix_core::State,\n    ) -> anyhow::Result<()> {\n        self.notify::<lsp::notification::DidSaveTextDocument>(lsp::DidSaveTextDocumentParams {\n            text_document: lsp::TextDocumentIdentifier::new(\n                lsp::Url::from_file_path(state.path.as_ref().unwrap()).unwrap(),\n            ),\n            text: None, // TODO?\n        })\n        .await\n    }\n\n    pub async fn text_document_did_close(&mut self) -> anyhow::Result<()> {\n        unimplemented!()\n    }\n\n    // will_save / will_save_wait_until\n\n    pub async fn text_document_did_save(&mut self) -> anyhow::Result<()> {\n        unimplemented!()\n    }\n}\n\nenum Payload {\n    Request {\n        chan: Sender<anyhow::Result<Value>>,\n        value: jsonrpc::MethodCall,\n    },\n    Notification(jsonrpc::Notification),\n}\n\nstruct Transport {\n    incoming: Sender<Message>,\n    outgoing: Receiver<Payload>,\n\n    pending_requests: HashMap<jsonrpc::Id, Sender<anyhow::Result<Value>>>,\n    headers: HashMap<String, String>,\n\n    writer: BufWriter<ChildStdin>,\n    reader: BufReader<ChildStdout>,\n}\n\nimpl Transport {\n    pub fn start(\n        ex: &Executor,\n        reader: BufReader<ChildStdout>,\n        writer: BufWriter<ChildStdin>,\n    ) -> (Receiver<Message>, Sender<Payload>) {\n        let (incoming, rx) = smol::channel::unbounded();\n        let (tx, outgoing) = smol::channel::unbounded();\n\n        let transport = Self {\n            reader,\n            writer,\n            incoming,\n            outgoing,\n            pending_requests: Default::default(),\n            headers: Default::default(),\n        };\n\n        ex.spawn(transport.duplex()).detach();\n\n        (rx, tx)\n    }\n\n    async fn recv(\n        reader: &mut (impl AsyncBufRead + Unpin),\n        headers: &mut HashMap<String, String>,\n    ) -> Result<Message, std::io::Error> {\n        // read headers\n        loop {\n            let mut header = String::new();\n            // detect pipe closed if 0\n            reader.read_line(&mut header).await?;\n            let header = header.trim();\n\n            if header.is_empty() {\n                break;\n            }\n\n            let parts: Vec<&str> = header.split(\": \").collect();\n            if parts.len() != 2 {\n                // return Err(Error::new(ErrorKind::Other, \"Failed to parse header\"));\n                panic!()\n            }\n            headers.insert(parts[0].to_string(), parts[1].to_string());\n        }\n\n        // find content-length\n        let content_length = headers.get(\"Content-Length\").unwrap().parse().unwrap();\n\n        let mut content = vec![0; content_length];\n        reader.read_exact(&mut content).await?;\n        let msg = String::from_utf8(content).unwrap();\n\n        // read data\n\n        // try parsing as output (server response) or call (server request)\n        let output: serde_json::Result<Message> = serde_json::from_str(&msg);\n\n        Ok(output?)\n    }\n\n    pub async fn send_payload(&mut self, payload: Payload) -> anyhow::Result<()> {\n        match payload {\n            Payload::Request { chan, value } => {\n                self.pending_requests.insert(value.id.clone(), chan);\n\n                let json = serde_json::to_string(&value)?;\n                self.send(json).await\n            }\n            Payload::Notification(value) => {\n                let json = serde_json::to_string(&value)?;\n                self.send(json).await\n            }\n        }\n    }\n\n    pub async fn send(&mut self, request: String) -> anyhow::Result<()> {\n        println!(\"-> {}\", request);\n\n        // send the headers\n        self.writer\n            .write_all(format!(\"Content-Length: {}\\r\\n\\r\\n\", request.len()).as_bytes())\n            .await?;\n\n        // send the body\n        self.writer.write_all(request.as_bytes()).await?;\n\n        self.writer.flush().await?;\n\n        Ok(())\n    }\n\n    pub async fn recv_response(&mut self, output: jsonrpc::Output) -> anyhow::Result<()> {\n        match output {\n            jsonrpc::Output::Success(jsonrpc::Success { id, result, .. }) => {\n                println!(\"<- {}\", result);\n\n                let tx = self\n                    .pending_requests\n                    .remove(&id)\n                    .expect(\"pending_request with id not found!\");\n                tx.send(Ok(result)).await?;\n            }\n            jsonrpc::Output::Failure(_) => panic!(\"recv fail\"),\n            msg => unimplemented!(\"{:?}\", msg),\n        }\n        Ok(())\n    }\n\n    pub async fn duplex(mut self) {\n        loop {\n            select! {\n                // client -> server\n                msg = self.outgoing.next().fuse() => {\n                    if msg.is_none() {\n                        break;\n                    }\n                    let msg = msg.unwrap();\n\n                    self.send_payload(msg).await.unwrap();\n                }\n                // server <- client\n                msg = Self::recv(&mut self.reader, &mut self.headers).fuse() => {\n                    if msg.is_err() {\n                        break;\n                    }\n                    let msg = msg.unwrap();\n\n                    match msg {\n                        Message::Output(output) => self.recv_response(output).await.unwrap(),\n                        Message::Notification(_) => {\n                            // dispatch\n                        }\n                        Message::Call(_) => {\n                            // dispatch\n                        }\n                    };\n                }\n            }\n        }\n    }\n}\n"}}}]
-Sun Oct 18 21:15:34 2020:[{"response": {"data": {"__data__": "vim-lsp", "server_name": "rust-analyzer"}, "message": "server already started"}}]
-Sun Oct 18 21:15:34 2020:[{"response": {"data": {"__data__": "vim-lsp", "init_result": {"id": 1, "jsonrpc": "2.0", "result": {"capabilities": {"documentHighlightProvider": true, "hoverProvider": true, "typeDefinitionProvider": true, "workspaceSymbolProvider": true, "referencesProvider": true, "signatureHelpProvider": {"triggerCharacters": ["(", ","]}, "foldingRangeProvider": true, "callHierarchyProvider": true, "codeActionProvider": {"codeActionKinds": ["", "quickfix", "refactor", "refactor.extract", "refactor.inline", "refactor.rewrite"]}, "textDocumentSync": {"save": {}, "change": 2, "openClose": true}, "codeLensProvider": {"resolveProvider": true}, "implementationProvider": true, "documentOnTypeFormattingProvider": {"moreTriggerCharacter": [".", ">"], "firstTriggerCharacter": "="}, "definitionProvider": true, "selectionRangeProvider": true, "semanticTokensProvider": {"legend": {"tokenTypes": ["comment", "keyword", "string", "number", "regexp", "operator", "namespace", "type", "struct", "class", "interface", "enum", "typeParameter", "function", "member", "property", "macro", "variable", "parameter", "label", "attribute", "boolean", "builtinType", "enumMember", "escapeSequence", "formatSpecifier", "generic", "lifetime", "punctuation", "selfKeyword", "typeAlias", "union", "unresolvedReference"], "tokenModifiers": ["documentation", "declaration", "definition", "static", "abstract", "deprecated", "readonly", "constant", "controlFlow", "injected", "mutable", "unsafe", "attribute"]}, "documentProvider": true, "rangeProvider": true}, "documentFormattingProvider": true, "documentSymbolProvider": true, "experimental": {"parentModule": true, "onEnter": true, "runnables": {"kinds": ["cargo"]}, "ssr": true, "joinLines": true}, "renameProvider": {"prepareProvider": true}, "completionProvider": {"triggerCharacters": [":", "."]}}, "serverInfo": {"version": "???????", "name": "rust-analyzer"}}}, "server_name": "rust-analyzer"}, "message": "lsp server already initialized"}}]
-Sun Oct 18 21:15:34 2020:[{"response": {"data": {"__data__": "vim-lsp", "server_name": "rust-analyzer"}, "message": "configuration sent"}}]
-Sun Oct 18 21:15:34 2020:[{"response": {"data": {"path": "file:///Users/speed/src/helix/helix-lsp/src/lib.rs", "__data__": "vim-lsp", "server_name": "rust-analyzer"}, "message": "already opened"}}]
-Sun Oct 18 21:15:34 2020:[{"response": {"data": {"path": "file:///Users/speed/src/helix/helix-lsp/src/lib.rs", "__data__": "vim-lsp", "server_name": "rust-analyzer"}, "message": "not dirty"}}]
-Sun Oct 18 21:15:34 2020:["--->", 7, "rust-analyzer", {"method": "textDocument/foldingRange", "on_notification": "---funcref---", "bufnr": 1, "params": {"textDocument": {"uri": "file:///Users/speed/src/helix/helix-lsp/src/lib.rs"}}, "sync": 0}]
-Sun Oct 18 21:15:34 2020:[{"response": {"data": {"path": "file:///Users/speed/src/helix/helix-lsp/src/lib.rs", "__data__": "vim-lsp", "filetype": "rust", "server_name": "rust-analyzer"}, "message": "textDocument/open sent"}}]
-Sun Oct 18 21:15:34 2020:[{"response": {"data": {"path": "file:///Users/speed/src/helix/helix-lsp/src/lib.rs", "__data__": "vim-lsp", "server_name": "rust-analyzer"}, "message": "not dirty"}}]
-Sun Oct 18 21:15:35 2020:["<---", 7, {"id": 0, "jsonrpc": "2.0", "method": "client/registerCapability", "params": {"registrations": [{"id": "textDocument/didSave", "registerOptions": {"includeText": false, "documentSelector": [{"pattern": "**/*.rs"}, {"pattern": "**/Cargo.toml"}, {"pattern": "**/Cargo.lock"}]}, "method": "textDocument/didSave"}]}}]
-Sun Oct 18 21:15:35 2020:["--->", 7, "rust-analyzer", {"id": 0, "error": {"code": -32601, "message": "Method not found"}}]
-Sun Oct 18 21:15:35 2020:["<---", 7, "rust-analyzer", {"response": {"id": 2, "jsonrpc": "2.0", "result": [{"startLine": 2, "kind": "imports", "endLine": 3}, {"startLine": 5, "kind": "imports", "endLine": 6}, {"startLine": 8, "kind": "imports", "endLine": 12}, {"startLine": 20, "endLine": 27}, {"startLine": 29, "endLine": 37}, {"startLine": 39, "endLine": 230}, {"startLine": 40, "endLine": 66}, {"startLine": 57, "endLine": 65}, {"startLine": 68, "endLine": 72}, {"startLine": 74, "endLine": 85}, {"startLine": 77, "endLine": 81}, {"startLine": 87, "endLine": 89}, {"startLine": 94, "endLine": 123}, {"startLine": 97, "endLine": 101}, {"startLine": 107, "endLine": 110}, {"startLine": 107, "endLine": 109}, {"startLine": 117, "kind": "comment", "endLine": 118}, {"startLine": 125, "endLine": 127}, {"startLine": 131, "endLine": 145}, {"startLine": 134, "endLine": 137}, {"startLine": 147, "kind": "comment", "endLine": 149}, {"startLine": 151, "endLine": 175}, {"startLine": 155, "endLine": 164}, {"startLine": 177, "endLine": 179}, {"startLine": 181, "endLine": 183}, {"startLine": 185, "kind": "comment", "endLine": 187}, {"startLine": 189, "endLine": 191}, {"startLine": 192, "endLine": 205}, {"startLine": 193, "endLine": 203}, {"startLine": 193, "endLine": 202}, {"startLine": 194, "endLine": 201}, {"startLine": 195, "endLine": 197}, {"startLine": 208, "endLine": 210}, {"startLine": 211, "endLine": 219}, {"startLine": 212, "endLine": 217}, {"startLine": 212, "endLine": 216}, {"startLine": 213, "endLine": 214}, {"startLine": 221, "endLine": 223}, {"startLine": 227, "endLine": 229}, {"startLine": 232, "endLine": 238}, {"startLine": 233, "endLine": 235}, {"startLine": 240, "endLine": 249}, {"startLine": 251, "endLine": 392}, {"startLine": 252, "endLine": 255}, {"startLine": 256, "endLine": 272}, {"startLine": 260, "endLine": 266}, {"startLine": 274, "endLine": 276}, {"startLine": 277, "endLine": 310}, {"startLine": 279, "endLine": 295}, {"startLine": 285, "endLine": 287}, {"startLine": 290, "endLine": 293}, {"startLine": 312, "endLine": 325}, {"startLine": 313, "endLine": 324}, {"startLine": 314, "endLine": 319}, {"startLine": 320, "endLine": 323}, {"startLine": 327, "endLine": 341}, {"startLine": 343, "endLine": 358}, {"startLine": 344, "endLine": 356}, {"startLine": 345, "endLine": 353}, {"startLine": 360, "endLine": 391}, {"startLine": 361, "endLine": 390}, {"startLine": 362, "endLine": 389}, {"startLine": 364, "endLine": 371}, {"startLine": 365, "endLine": 367}, {"startLine": 373, "endLine": 388}, {"startLine": 374, "endLine": 376}, {"startLine": 379, "endLine": 386}, {"startLine": 381, "endLine": 383}, {"startLine": 384, "endLine": 386}]}, "request": {"id": 2, "jsonrpc": "2.0", "method": "textDocument/foldingRange", "params": {"textDocument": {"uri": "file:///Users/speed/src/helix/helix-lsp/src/lib.rs"}}}}]
-Sun Oct 18 21:15:36 2020:["<---", 7, "rust-analyzer", {"response": {"method": "textDocument/publishDiagnostics", "jsonrpc": "2.0", "params": {"diagnostics": [{"source": "rustc", "range": {"end": {"character": 15, "line": 355}, "start": {"character": 12, "line": 355}}, "code": "unreachable_patterns", "message": "unreachable pattern\n`#[warn(unreachable_patterns)]` on by default", "severity": 2}], "uri": "file:///Users/speed/src/helix/helix-lsp/src/lib.rs", "version": 1}}}]
-Sun Oct 18 21:15:36 2020:["<---", 7, "rust-analyzer", {"response": {"method": "textDocument/publishDiagnostics", "jsonrpc": "2.0", "params": {"diagnostics": [{"source": "rustc", "tags": [1], "range": {"end": {"character": 28, "line": 618}, "start": {"character": 24, "line": 618}}, "code": "unused_variables", "message": "unused variable: `view`\n`#[warn(unused_variables)]` on by default", "severity": 2}], "uri": "file:///Users/speed/src/helix/helix-view/src/commands.rs"}}}]
-Sun Oct 18 21:15:36 2020:["<---", 7, "rust-analyzer", {"response": {"method": "textDocument/publishDiagnostics", "jsonrpc": "2.0", "params": {"diagnostics": [{"source": "rustc", "range": {"end": {"character": 15, "line": 355}, "start": {"character": 12, "line": 355}}, "code": "unreachable_patterns", "message": "unreachable pattern\n`#[warn(unreachable_patterns)]` on by default", "severity": 2}, {"source": "rustc", "tags": [1], "range": {"end": {"character": 21, "line": 55}, "start": {"character": 13, "line": 55}}, "code": "unused_variables", "message": "unused variable: `incoming`\n`#[warn(unused_variables)]` on by default", "severity": 2}], "uri": "file:///Users/speed/src/helix/helix-lsp/src/lib.rs", "version": 1}}}]
-Sun Oct 18 21:15:36 2020:["<---", 7, "rust-analyzer", {"response": {"method": "textDocument/publishDiagnostics", "jsonrpc": "2.0", "params": {"diagnostics": [{"source": "rustc", "range": {"end": {"character": 15, "line": 355}, "start": {"character": 12, "line": 355}}, "code": "unreachable_patterns", "message": "unreachable pattern\n`#[warn(unreachable_patterns)]` on by default", "severity": 2}, {"source": "rustc", "tags": [1], "range": {"end": {"character": 21, "line": 55}, "start": {"character": 13, "line": 55}}, "code": "unused_variables", "message": "unused variable: `incoming`\n`#[warn(unused_variables)]` on by default", "severity": 2}, {"source": "rustc", "tags": [1], "range": {"end": {"character": 18, "line": 30}, "start": {"character": 4, "line": 30}}, "code": "dead_code", "message": "field is never read: `process`\n`#[warn(dead_code)]` on by default", "severity": 2}], "uri": "file:///Users/speed/src/helix/helix-lsp/src/lib.rs", "version": 1}}}]
-Sun Oct 18 21:15:36 2020:["<---", 7, "rust-analyzer", {"response": {"method": "textDocument/publishDiagnostics", "jsonrpc": "2.0", "params": {"diagnostics": [{"source": "rustc", "range": {"end": {"character": 15, "line": 355}, "start": {"character": 12, "line": 355}}, "code": "unreachable_patterns", "message": "unreachable pattern\n`#[warn(unreachable_patterns)]` on by default", "severity": 2}, {"source": "rustc", "tags": [1], "range": {"end": {"character": 21, "line": 55}, "start": {"character": 13, "line": 55}}, "code": "unused_variables", "message": "unused variable: `incoming`\n`#[warn(unused_variables)]` on by default", "severity": 2}, {"source": "rustc", "tags": [1], "range": {"end": {"character": 18, "line": 30}, "start": {"character": 4, "line": 30}}, "code": "dead_code", "message": "field is never read: `process`\n`#[warn(dead_code)]` on by default", "severity": 2}, {"source": "rustc", "tags": [1], "range": {"end": {"character": 34, "line": 31}, "start": {"character": 4, "line": 31}}, "code": "dead_code", "message": "field is never read: `stderr`", "severity": 2}], "uri": "file:///Users/speed/src/helix/helix-lsp/src/lib.rs", "version": 1}}}]
-Sun Oct 18 21:15:36 2020:["<---", 7, "rust-analyzer", {"response": {"method": "textDocument/publishDiagnostics", "jsonrpc": "2.0", "params": {"diagnostics": [{"source": "rustc", "range": {"end": {"character": 15, "line": 355}, "start": {"character": 12, "line": 355}}, "code": "unreachable_patterns", "message": "unreachable pattern\n`#[warn(unreachable_patterns)]` on by default", "severity": 2}, {"source": "rustc", "tags": [1], "range": {"end": {"character": 21, "line": 55}, "start": {"character": 13, "line": 55}}, "code": "unused_variables", "message": "unused variable: `incoming`\n`#[warn(unused_variables)]` on by default", "severity": 2}, {"source": "rustc", "tags": [1], "range": {"end": {"character": 18, "line": 30}, "start": {"character": 4, "line": 30}}, "code": "dead_code", "message": "field is never read: `process`\n`#[warn(dead_code)]` on by default", "severity": 2}, {"source": "rustc", "tags": [1], "range": {"end": {"character": 34, "line": 31}, "start": {"character": 4, "line": 31}}, "code": "dead_code", "message": "field is never read: `stderr`", "severity": 2}, {"source": "rustc", "tags": [1], "range": {"end": {"character": 29, "line": 241}, "start": {"character": 4, "line": 241}}, "code": "dead_code", "message": "field is never read: `incoming`", "severity": 2}], "uri": "file:///Users/speed/src/helix/helix-lsp/src/lib.rs", "version": 1}}}]
-Sun Oct 18 21:15:39 2020:["lsp#register_server", "server registered", "typescript-language-server"]
-Sun Oct 18 21:15:39 2020:["lsp#register_server", "server registered", "elixir-ls"]
-Sun Oct 18 21:15:39 2020:["lsp#register_server", "server registered", "vue-language-server"]
-Sun Oct 18 21:15:39 2020:["lsp#register_server", "server registered", "rust-analyzer"]
-Sun Oct 18 21:15:39 2020:["s:on_text_document_did_open()", 1, "vim", "/Users/speed/src/helix/helix-lsp", "file:///Users/speed/.vimrc"]
-Sun Oct 18 21:15:40 2020:["s:on_text_document_did_change()", 1]
-Sun Oct 18 21:15:40 2020:["s:send_didchange_queue() will be triggered"]
-Sun Oct 18 21:15:40 2020:["s:on_text_document_did_change()", 1]
-Sun Oct 18 21:15:41 2020:["s:on_text_document_did_save()", 1]
-Sun Oct 18 21:15:41 2020:["s:on_text_document_did_close()", 1]
-Sun Oct 18 21:15:55 2020:["<---", 7, "rust-analyzer", {"response": {"method": "textDocument/publishDiagnostics", "jsonrpc": "2.0", "params": {"diagnostics": [{"source": "rustc", "range": {"end": {"character": 15, "line": 355}, "start": {"character": 12, "line": 355}}, "code": "unreachable_patterns", "message": "unreachable pattern\n`#[warn(unreachable_patterns)]` on by default", "severity": 2}, {"source": "rustc", "tags": [1], "range": {"end": {"character": 21, "line": 55}, "start": {"character": 13, "line": 55}}, "code": "unused_variables", "message": "unused variable: `incoming`\n`#[warn(unused_variables)]` on by default", "severity": 2}, {"source": "rustc", "tags": [1], "range": {"end": {"character": 18, "line": 30}, "start": {"character": 4, "line": 30}}, "code": "dead_code", "message": "field is never read: `process`\n`#[warn(dead_code)]` on by default", "severity": 2}, {"source": "rustc", "tags": [1], "range": {"end": {"character": 34, "line": 31}, "start": {"character": 4, "line": 31}}, "code": "dead_code", "message": "field is never read: `stderr`", "severity": 2}, {"source": "rustc", "tags": [1], "range": {"end": {"character": 29, "line": 241}, "start": {"character": 4, "line": 241}}, "code": "dead_code", "message": "field is never read: `incoming`", "severity": 2}], "uri": "file:///Users/speed/src/helix/helix-lsp/src/lib.rs", "version": 1}}}]
-Sun Oct 18 21:15:57 2020:["s:on_text_document_did_close()", 1]
-Sun Oct 18 21:15:57 2020:["s:on_exit", 7, "rust-analyzer", "exited", 143]
diff --git a/helix-lsp/src/transport.rs b/helix-lsp/src/transport.rs
index b30a8a6e..4ab3d5ec 100644
--- a/helix-lsp/src/transport.rs
+++ b/helix-lsp/src/transport.rs
@@ -1,5 +1,7 @@
 use std::collections::HashMap;
 
+use log::debug;
+
 use crate::{Error, Message, Notification};
 
 type Result<T> = core::result::Result<T, Error>;
@@ -114,7 +116,7 @@ impl Transport {
     }
 
     pub async fn send(&mut self, request: String) -> anyhow::Result<()> {
-        // println!("-> {}", request);
+        debug!("-> {}", request);
 
         // send the headers
         self.writer
@@ -135,11 +137,11 @@ impl Transport {
             Message::Notification(jsonrpc::Notification { method, params, .. }) => {
                 let notification = Notification::parse(&method, params);
 
-                // println!("<- {} {:?}", method, notification);
+                debug!("<- {} {:?}", method, notification);
                 self.incoming.send(notification).await?;
             }
-            Message::Call(_call) => {
-                // println!("<- {:?}", call);
+            Message::Call(call) => {
+                debug!("<- {:?}", call);
                 // dispatch
             }
         };
@@ -149,7 +151,7 @@ impl Transport {
     pub async fn recv_response(&mut self, output: jsonrpc::Output) -> anyhow::Result<()> {
         match output {
             jsonrpc::Output::Success(jsonrpc::Success { id, result, .. }) => {
-                // println!("<- {}", result);
+                debug!("<- {}", result);
 
                 let tx = self
                     .pending_requests
diff --git a/helix-term/Cargo.toml b/helix-term/Cargo.toml
index db1edee9..c1560ee7 100644
--- a/helix-term/Cargo.toml
+++ b/helix-term/Cargo.toml
@@ -19,10 +19,15 @@ helix-lsp = { path = "../helix-lsp"}
 anyhow = "1"
 
 smol = "1"
-num_cpus = "1.13"
+num_cpus = "1"
 # tui = { version = "0.12", default-features = false, features = ["crossterm"] }
 tui = { git = "https://github.com/fdehau/tui-rs", default-features = false, features = ["crossterm"] }
 crossterm = { version = "0.18", features = ["event-stream"] }
 clap = { version = "3.0.0-beta.2 ", default-features = false, features = ["std", "cargo"] }
 
 futures-util = "0.3"
+
+# Logging
+fern = "0.6"
+chrono = "0.4"
+log = "0.4"
diff --git a/helix-term/src/main.rs b/helix-term/src/main.rs
index de3a0175..f91c1c8f 100644
--- a/helix-term/src/main.rs
+++ b/helix-term/src/main.rs
@@ -11,6 +11,39 @@ use anyhow::Error;
 
 static EX: smol::Executor = smol::Executor::new();
 
+fn setup_logging(verbosity: u64) -> Result<(), fern::InitError> {
+    let mut base_config = fern::Dispatch::new();
+
+    // Let's say we depend on something which whose "info" level messages are too
+    // verbose to include in end-user output. If we don't need them,
+    // let's not include them.
+    // .level_for("overly-verbose-target", log::LevelFilter::Warn)
+
+    base_config = match verbosity {
+        0 => base_config.level(log::LevelFilter::Warn),
+        1 => base_config.level(log::LevelFilter::Info),
+        2 => base_config.level(log::LevelFilter::Debug),
+        _3_or_more => base_config.level(log::LevelFilter::Trace),
+    };
+
+    // Separate file config so we can include year, month and day in file logs
+    let file_config = fern::Dispatch::new()
+        .format(|out, message, record| {
+            out.finish(format_args!(
+                "{} {} [{}] {}",
+                chrono::Local::now().format("%Y-%m-%dT%H:%M:%S%.3f"),
+                record.target(),
+                record.level(),
+                message
+            ))
+        })
+        .chain(fern::log_file("helix.log")?);
+
+    base_config.chain(file_config).apply()?;
+
+    Ok(())
+}
+
 fn main() -> Result<(), Error> {
     let args = clap::app_from_crate!()
         .arg(
@@ -20,8 +53,19 @@ fn main() -> Result<(), Error> {
                 .multiple(true)
                 .index(1),
         )
+        .arg(
+            Arg::new("verbose")
+                .about("Increases logging verbosity each use for up to 3 times")
+                .short('v')
+                .takes_value(false)
+                .multiple_occurrences(true),
+        )
         .get_matches();
 
+    let verbosity: u64 = args.occurrences_of("verbose");
+
+    setup_logging(verbosity).expect("failed to initialize logging.");
+
     for _ in 0..num_cpus::get() {
         std::thread::spawn(move || smol::block_on(EX.run(smol::future::pending::<()>())));
     }