feat: log permission access (#2518)

Replaces -D/--log-debug flag with --log-level=debug

--log-level=info displays permission access

4 files changed, 146 insertions, 83 deletions

diff --git a/cli/flags.rs b/cli/flags.rs
index 2ec1be021..3355c1e7b 100644
--- a/cli/flags.rs
+++ b/cli/flags.rs
@@ -1,6 +1,7 @@
 // Copyright 2018-2019 the Deno authors. All rights reserved. MIT license.
 use clap::{App, AppSettings, Arg, ArgMatches, SubCommand};
 use crate::deno_dir;
+use log::Level;
 
 // Creates vector of strings, Vec<String>
 macro_rules! svec {
@@ -9,7 +10,7 @@ macro_rules! svec {
 
 #[derive(Clone, Debug, PartialEq, Default)]
 pub struct DenoFlags {
-  pub log_debug: bool,
+  pub log_level: Option<Level>,
   pub version: bool,
   pub reload: bool,
   /// When the `--config`/`-c` flag is used to pass the name, this will be set
@@ -127,10 +128,12 @@ To get help on the another subcommands (run in this case):
 
   deno help run")
     .arg(
-      Arg::with_name("log-debug")
-        .short("D")
-        .long("log-debug")
-        .help("Log debug output")
+      Arg::with_name("log-level")
+        .short("L")
+        .long("log-level")
+        .help("Set log level")
+        .takes_value(true)
+        .possible_values(&["debug", "info"])
         .global(true),
     ).arg(
       Arg::with_name("reload")
@@ -409,8 +412,12 @@ fn resolve_paths(paths: Vec<String>) -> Vec<String> {
 pub fn parse_flags(matches: &ArgMatches) -> DenoFlags {
   let mut flags = DenoFlags::default();
 
-  if matches.is_present("log-debug") {
-    flags.log_debug = true;
+  if matches.is_present("log-level") {
+    flags.log_level = match matches.value_of("log-level").unwrap() {
+      "debug" => Some(Level::Debug),
+      "info" => Some(Level::Info),
+      _ => unreachable!(),
+    };
   }
   if matches.is_present("version") {
     flags.version = true;
@@ -743,11 +750,10 @@ mod tests {
   #[test]
   fn test_flags_from_vec_2() {
     let (flags, subcommand, argv) =
-      flags_from_vec(svec!["deno", "-r", "-D", "run", "script.ts"]);
+      flags_from_vec(svec!["deno", "-r", "run", "script.ts"]);
     assert_eq!(
       flags,
       DenoFlags {
-        log_debug: true,
         reload: true,
         ..DenoFlags::default()
       }
@@ -758,19 +764,12 @@ mod tests {
 
   #[test]
   fn test_flags_from_vec_3() {
-    let (flags, subcommand, argv) = flags_from_vec(svec![
-      "deno",
-      "run",
-      "-r",
-      "-D",
-      "--allow-write",
-      "script.ts"
-    ]);
+    let (flags, subcommand, argv) =
+      flags_from_vec(svec!["deno", "run", "-r", "--allow-write", "script.ts"]);
     assert_eq!(
       flags,
       DenoFlags {
         reload: true,
-        log_debug: true,
         allow_write: true,
         ..DenoFlags::default()
       }
@@ -782,11 +781,10 @@ mod tests {
   #[test]
   fn test_flags_from_vec_4() {
     let (flags, subcommand, argv) =
-      flags_from_vec(svec!["deno", "-Dr", "run", "--allow-write", "script.ts"]);
+      flags_from_vec(svec!["deno", "-r", "run", "--allow-write", "script.ts"]);
     assert_eq!(
       flags,
       DenoFlags {
-        log_debug: true,
         reload: true,
         allow_write: true,
         ..DenoFlags::default()
@@ -1179,7 +1177,6 @@ mod tests {
     let (flags, subcommand, argv) = flags_from_vec(svec![
       "deno",
       "-r",
-      "-D",
       "--allow-net",
       "run",
       "--allow-read",
@@ -1189,7 +1186,6 @@ mod tests {
       flags,
       DenoFlags {
         reload: true,
-        log_debug: true,
         allow_net: true,
         allow_read: true,
         ..DenoFlags::default()
@@ -1381,4 +1377,19 @@ mod tests {
       ]
     );
   }
+
+  #[test]
+  fn test_flags_from_vec_31() {
+    let (flags, subcommand, argv) =
+      flags_from_vec(svec!["deno", "--log-level=debug", "script.ts"]);
+    assert_eq!(
+      flags,
+      DenoFlags {
+        log_level: Some(Level::Debug),
+        ..DenoFlags::default()
+      }
+    );
+    assert_eq!(subcommand, DenoSubcommand::Run);
+    assert_eq!(argv, svec!["deno", "script.ts"])
+  }
 }
diff --git a/cli/main.rs b/cli/main.rs
index d56b07479..7965b4edf 100644
--- a/cli/main.rs
+++ b/cli/main.rs
@@ -56,7 +56,9 @@ use flags::DenoSubcommand;
 use futures::future;
 use futures::lazy;
 use futures::Future;
-use log::{LevelFilter, Metadata, Record};
+use log::Level;
+use log::Metadata;
+use log::Record;
 use std::env;
 
 static LOGGER: Logger = Logger;
@@ -333,11 +335,11 @@ fn main() {
     v8_set_flags(v8_flags.clone());
   }
 
-  log::set_max_level(if flags.log_debug {
-    LevelFilter::Debug
-  } else {
-    LevelFilter::Warn
-  });
+  let log_level = match flags.log_level {
+    Some(level) => level,
+    None => Level::Warn,
+  };
+  log::set_max_level(log_level.to_level_filter());
 
   match subcommand {
     DenoSubcommand::Bundle => bundle_command(flags, argv),
diff --git a/cli/ops.rs b/cli/ops.rs
index e4448c3b5..964ba61eb 100644
--- a/cli/ops.rs
+++ b/cli/ops.rs
@@ -42,6 +42,7 @@ use futures::Sink;
 use futures::Stream;
 use hyper;
 use hyper::rt::Future;
+use log;
 use rand::{thread_rng, Rng};
 use remove_dir_all::remove_dir_all;
 use std;
@@ -362,6 +363,11 @@ fn op_start(
     .clone()
     .map(|m| builder.create_string(&m));
 
+  let debug_flag = state
+    .flags
+    .log_level
+    .map_or(false, |l| l == log::Level::Debug);
+
   let inner = msg::StartRes::create(
     &mut builder,
     &msg::StartResArgs {
@@ -369,7 +375,7 @@ fn op_start(
       pid: std::process::id(),
       argv: Some(argv_off),
       main_module,
-      debug_flag: state.flags.log_debug,
+      debug_flag,
       version_flag: state.flags.version,
       v8_version: Some(v8_version_off),
       deno_version: Some(deno_version_off),
diff --git a/cli/permissions.rs b/cli/permissions.rs
index 222016532..2647d4236 100644
--- a/cli/permissions.rs
+++ b/cli/permissions.rs
@@ -6,6 +6,7 @@ use crate::flags::DenoFlags;
 use ansi_term::Style;
 use crate::deno_error::permission_denied;
 use crate::deno_error::DenoResult;
+use log;
 use std::collections::HashSet;
 use std::fmt;
 use std::io;
@@ -13,6 +14,8 @@ use std::path::PathBuf;
 use std::sync::atomic::{AtomicBool, AtomicUsize, Ordering};
 use std::sync::Arc;
 
+const PERMISSION_EMOJI: &str = "⚠️";
+
 /// Tri-state value for storing permission state
 pub enum PermissionAccessorState {
   Allow = 0,
@@ -158,40 +161,50 @@ impl DenoPermissions {
   }
 
   pub fn check_run(&self) -> DenoResult<()> {
+    let msg = "access to run a subprocess";
+
     match self.allow_run.get_state() {
-      PermissionAccessorState::Allow => Ok(()),
-      PermissionAccessorState::Ask => {
-        match self.try_permissions_prompt("access to run a subprocess") {
-          Err(e) => Err(e),
-          Ok(v) => {
-            self.allow_run.update_with_prompt_result(&v);
-            v.check()?;
-            Ok(())
-          }
-        }
+      PermissionAccessorState::Allow => {
+        self.log_perm_access(msg);
+        Ok(())
       }
+      PermissionAccessorState::Ask => match self.try_permissions_prompt(msg) {
+        Err(e) => Err(e),
+        Ok(v) => {
+          self.allow_run.update_with_prompt_result(&v);
+          v.check()?;
+          self.log_perm_access(msg);
+          Ok(())
+        }
+      },
       PermissionAccessorState::Deny => Err(permission_denied()),
     }
   }
 
   pub fn check_read(&self, filename: &str) -> DenoResult<()> {
+    let msg = &format!("read access to \"{}\"", filename);
     match self.allow_read.get_state() {
-      PermissionAccessorState::Allow => Ok(()),
+      PermissionAccessorState::Allow => {
+        self.log_perm_access(msg);
+        Ok(())
+      }
       state => {
         if check_path_white_list(filename, &self.read_whitelist) {
+          self.log_perm_access(msg);
           Ok(())
         } else {
           match state {
-            PermissionAccessorState::Ask => match self.try_permissions_prompt(
-              &format!("read access to \"{}\"", filename),
-            ) {
-              Err(e) => Err(e),
-              Ok(v) => {
-                self.allow_read.update_with_prompt_result(&v);
-                v.check()?;
-                Ok(())
+            PermissionAccessorState::Ask => {
+              match self.try_permissions_prompt(msg) {
+                Err(e) => Err(e),
+                Ok(v) => {
+                  self.allow_read.update_with_prompt_result(&v);
+                  v.check()?;
+                  self.log_perm_access(msg);
+                  Ok(())
+                }
               }
-            },
+            }
             PermissionAccessorState::Deny => Err(permission_denied()),
             _ => unreachable!(),
           }
@@ -201,23 +214,29 @@ impl DenoPermissions {
   }
 
   pub fn check_write(&self, filename: &str) -> DenoResult<()> {
+    let msg = &format!("write access to \"{}\"", filename);
     match self.allow_write.get_state() {
-      PermissionAccessorState::Allow => Ok(()),
+      PermissionAccessorState::Allow => {
+        self.log_perm_access(msg);
+        Ok(())
+      }
       state => {
         if check_path_white_list(filename, &self.write_whitelist) {
+          self.log_perm_access(msg);
           Ok(())
         } else {
           match state {
-            PermissionAccessorState::Ask => match self.try_permissions_prompt(
-              &format!("write access to \"{}\"", filename),
-            ) {
-              Err(e) => Err(e),
-              Ok(v) => {
-                self.allow_write.update_with_prompt_result(&v);
-                v.check()?;
-                Ok(())
+            PermissionAccessorState::Ask => {
+              match self.try_permissions_prompt(msg) {
+                Err(e) => Err(e),
+                Ok(v) => {
+                  self.allow_write.update_with_prompt_result(&v);
+                  v.check()?;
+                  self.log_perm_access(msg);
+                  Ok(())
+                }
               }
-            },
+            }
             PermissionAccessorState::Deny => Err(permission_denied()),
             _ => unreachable!(),
           }
@@ -227,8 +246,12 @@ impl DenoPermissions {
   }
 
   pub fn check_net(&self, host_and_port: &str) -> DenoResult<()> {
+    let msg = &format!("network access to \"{}\"", host_and_port);
     match self.allow_net.get_state() {
-      PermissionAccessorState::Allow => Ok(()),
+      PermissionAccessorState::Allow => {
+        self.log_perm_access(msg);
+        Ok(())
+      }
       state => {
         let parts = host_and_port.split(':').collect::<Vec<&str>>();
         if match parts.len() {
@@ -244,17 +267,22 @@ impl DenoPermissions {
           1 => self.net_whitelist.contains(parts[0]),
           _ => panic!("Failed to parse origin string: {}", host_and_port),
         } {
+          self.log_perm_access(msg);
           Ok(())
         } else {
-          self.check_net_inner(state, host_and_port)
+          self.check_net_inner(state, msg)
         }
       }
     }
   }
 
   pub fn check_net_url(&self, url: url::Url) -> DenoResult<()> {
+    let msg = &format!("network access to \"{}\"", url);
     match self.allow_net.get_state() {
-      PermissionAccessorState::Allow => Ok(()),
+      PermissionAccessorState::Allow => {
+        self.log_perm_access(msg);
+        Ok(())
+      }
       state => {
         let host = url.host().unwrap();
         let whitelist_result = {
@@ -270,9 +298,10 @@ impl DenoPermissions {
           }
         };
         if whitelist_result {
+          self.log_perm_access(msg);
           Ok(())
         } else {
-          self.check_net_inner(state, &url.to_string())
+          self.check_net_inner(state, msg)
         }
       }
     }
@@ -284,34 +313,38 @@ impl DenoPermissions {
     prompt_str: &str,
   ) -> DenoResult<()> {
     match state {
-      PermissionAccessorState::Ask => match self.try_permissions_prompt(
-        &format!("network access to \"{}\"", prompt_str),
-      ) {
-        Err(e) => Err(e),
-        Ok(v) => {
-          self.allow_net.update_with_prompt_result(&v);
-          v.check()?;
-          Ok(())
+      PermissionAccessorState::Ask => {
+        match self.try_permissions_prompt(prompt_str) {
+          Err(e) => Err(e),
+          Ok(v) => {
+            self.allow_net.update_with_prompt_result(&v);
+            v.check()?;
+            self.log_perm_access(prompt_str);
+            Ok(())
+          }
         }
-      },
+      }
       PermissionAccessorState::Deny => Err(permission_denied()),
       _ => unreachable!(),
     }
   }
 
   pub fn check_env(&self) -> DenoResult<()> {
+    let msg = "access to environment variables";
     match self.allow_env.get_state() {
-      PermissionAccessorState::Allow => Ok(()),
-      PermissionAccessorState::Ask => {
-        match self.try_permissions_prompt("access to environment variables") {
-          Err(e) => Err(e),
-          Ok(v) => {
-            self.allow_env.update_with_prompt_result(&v);
-            v.check()?;
-            Ok(())
-          }
-        }
+      PermissionAccessorState::Allow => {
+        self.log_perm_access(msg);
+        Ok(())
       }
+      PermissionAccessorState::Ask => match self.try_permissions_prompt(msg) {
+        Err(e) => Err(e),
+        Ok(v) => {
+          self.allow_env.update_with_prompt_result(&v);
+          v.check()?;
+          self.log_perm_access(msg);
+          Ok(())
+        }
+      },
       PermissionAccessorState::Deny => Err(permission_denied()),
     }
   }
@@ -328,6 +361,17 @@ impl DenoPermissions {
     permission_prompt(message)
   }
 
+  fn log_perm_access(&self, message: &str) {
+    if log_enabled!(log::Level::Info) {
+      eprintln!(
+        "{}",
+        Style::new()
+          .bold()
+          .paint(format!("{}️  Granted {}", PERMISSION_EMOJI, message))
+      );
+    }
+  }
+
   pub fn allows_run(&self) -> bool {
     self.allow_run.is_allow()
   }
@@ -414,7 +458,7 @@ impl fmt::Display for PromptResult {
 }
 
 fn permission_prompt(message: &str) -> DenoResult<PromptResult> {
-  let msg = format!("⚠️  Deno requests {}. Grant? [a/y/n/d (a = allow always, y = allow once, n = deny once, d = deny always)] ", message);
+  let msg = format!("️{}  Deno requests {}. Grant? [a/y/n/d (a = allow always, y = allow once, n = deny once, d = deny always)] ", PERMISSION_EMOJI, message);
   // print to stderr so that if deno is > to a file this is still displayed.
   eprint!("{}", Style::new().bold().paint(msg));
   loop {