Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

cli: don't colorize file log output, collect internal logs for broadcast #177420

Merged
merged 2 commits into from Mar 17, 2023
Merged

cli: don't colorize file log output, collect internal logs for broadcast #177420

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
a3112cc
cli: don't colorize file log output, collect internal logs for broadcast
connor4312 Mar 16, 2023
3a7cf26
Merge branch 'main' into connor4312/issue177345
connor4312 Mar 17, 2023
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Jump to
Jump to file
Failed to load files.
Diff view
Diff view
106 changes: 39 additions & 67 deletions cli/src/bin/code/main.rs
View file
Open in desktop
Expand Up @@ -10,7 +10,7 @@ use clap::Parser;
use cli::{
commands::{args, internal_wsl, tunnels, update, version, CommandContext},
constants::get_default_user_agent,
desktop, log as own_log,
desktop, log,
state::LauncherPaths,
util::{
errors::{wrap, AnyError},
Expand All @@ -22,8 +22,6 @@ use legacy_args::try_parse_legacy;
use opentelemetry::sdk::trace::TracerProvider as SdkTracerProvider;
use opentelemetry::trace::TracerProvider;

use log::{Level, Metadata, Record};

#[tokio::main]
async fn main() -> Result<(), std::convert::Infallible> {
let raw_args = std::env::args_os().collect::<Vec<_>>();
Expand All @@ -38,72 +36,84 @@ async fn main() -> Result<(), std::convert::Infallible> {
});

let core = parsed.core();
let context = CommandContext {
let context_paths = LauncherPaths::new(&core.global_options.cli_data_dir).unwrap();
let context_args = core.clone();

// gets a command context without installing the global logger
let context_no_logger = || CommandContext {
http: reqwest::ClientBuilder::new()
.user_agent(get_default_user_agent())
.build()
.unwrap(),
paths: LauncherPaths::new(&core.global_options.cli_data_dir).unwrap(),
log: make_logger(core),
args: core.clone(),
paths: context_paths,
log: make_logger(&context_args),
args: context_args,
};

log::set_logger(Box::leak(Box::new(RustyLogger(context.log.clone()))))
.map(|()| log::set_max_level(log::LevelFilter::Debug))
.expect("expected to make logger");
// gets a command context with the global logger installer. Usually what most commands want.
macro_rules! context {
() => {{
let context = context_no_logger();
log::install_global_logger(context.log.clone());
context
}};
}

let result = match parsed {
args::AnyCli::Standalone(args::StandaloneCli {
subcommand: Some(cmd),
..
}) => match cmd {
args::StandaloneCommands::Update(args) => update::update(context, args).await,
args::StandaloneCommands::Update(args) => update::update(context!(), args).await,
args::StandaloneCommands::Wsl(args) => match args.command {
args::WslCommands::Serve => internal_wsl::serve(context).await,
args::WslCommands::Serve => internal_wsl::serve(context!()).await,
},
},
args::AnyCli::Standalone(args::StandaloneCli { core: c, .. })
| args::AnyCli::Integrated(args::IntegratedCli { core: c, .. }) => match c.subcommand {
None => {
let context = context!();
let ca = context.args.get_base_code_args();
start_code(context, ca).await
}

Some(args::Commands::Extension(extension_args)) => {
let context = context!();
let mut ca = context.args.get_base_code_args();
extension_args.add_code_args(&mut ca);
start_code(context, ca).await
}

Some(args::Commands::Status) => {
let context = context!();
let mut ca = context.args.get_base_code_args();
ca.push("--status".to_string());
start_code(context, ca).await
}

Some(args::Commands::Version(version_args)) => match version_args.subcommand {
args::VersionSubcommand::Use(use_version_args) => {
version::switch_to(context, use_version_args).await
version::switch_to(context!(), use_version_args).await
}
args::VersionSubcommand::Show => version::show(context).await,
args::VersionSubcommand::Show => version::show(context!()).await,
},

Some(args::Commands::Tunnel(tunnel_args)) => match tunnel_args.subcommand {
Some(args::TunnelSubcommand::Prune) => tunnels::prune(context).await,
Some(args::TunnelSubcommand::Unregister) => tunnels::unregister(context).await,
Some(args::TunnelSubcommand::Kill) => tunnels::kill(context).await,
Some(args::TunnelSubcommand::Restart) => tunnels::restart(context).await,
Some(args::TunnelSubcommand::Status) => tunnels::status(context).await,
Some(args::TunnelSubcommand::Prune) => tunnels::prune(context!()).await,
Some(args::TunnelSubcommand::Unregister) => tunnels::unregister(context!()).await,
Some(args::TunnelSubcommand::Kill) => tunnels::kill(context!()).await,
Some(args::TunnelSubcommand::Restart) => tunnels::restart(context!()).await,
Some(args::TunnelSubcommand::Status) => tunnels::status(context!()).await,
Some(args::TunnelSubcommand::Rename(rename_args)) => {
tunnels::rename(context, rename_args).await
tunnels::rename(context!(), rename_args).await
}
Some(args::TunnelSubcommand::User(user_command)) => {
tunnels::user(context, user_command).await
tunnels::user(context!(), user_command).await
}
Some(args::TunnelSubcommand::Service(service_args)) => {
tunnels::service(context, service_args).await
tunnels::service(context_no_logger(), service_args).await
}
None => tunnels::serve(context, tunnel_args.serve_args).await,
None => tunnels::serve(context_no_logger(), tunnel_args.serve_args).await,
},
},
};
Expand All @@ -114,18 +124,17 @@ async fn main() -> Result<(), std::convert::Infallible> {
}
}

fn make_logger(core: &args::CliCore) -> own_log::Logger {
fn make_logger(core: &args::CliCore) -> log::Logger {
let log_level = if core.global_options.verbose {
own_log::Level::Trace
log::Level::Trace
} else {
core.global_options.log.unwrap_or(own_log::Level::Info)
core.global_options.log.unwrap_or(log::Level::Info)
};

let tracer = SdkTracerProvider::builder().build().tracer("codecli");
let mut log = own_log::Logger::new(tracer, log_level);
let mut log = log::Logger::new(tracer, log_level);
if let Some(f) = &core.global_options.log_to_file {
log =
log.tee(own_log::FileLogSink::new(log_level, f).expect("expected to make file logger"))
log = log.tee(log::FileLogSink::new(log_level, f).expect("expected to make file logger"))
}

log
Expand All @@ -135,7 +144,7 @@ fn print_and_exit<E>(err: E) -> !
where
E: std::fmt::Display,
{
own_log::emit(own_log::Level::Error, "", &format!("{}", err));
log::emit(log::Level::Error, "", &format!("{}", err));
std::process::exit(1);
}

Expand Down Expand Up @@ -167,40 +176,3 @@ async fn start_code(context: CommandContext, args: Vec<String>) -> Result<i32, A

Ok(code)
}

/// Logger that uses the common rust "log" crate and directs back to one of
/// our managed loggers.
struct RustyLogger(own_log::Logger);

impl log::Log for RustyLogger {
fn enabled(&self, metadata: &Metadata) -> bool {
metadata.level() <= Level::Debug
}

fn log(&self, record: &Record) {
if !self.enabled(record.metadata()) {
return;
}

// exclude noisy log modules:
let src = match record.module_path() {
Some("russh::cipher") => return,
Some("russh::negotiation") => return,
Some(s) => s,
None => "<unknown>",
};

self.0.emit(
match record.level() {
log::Level::Debug => own_log::Level::Debug,
log::Level::Error => own_log::Level::Error,
log::Level::Info => own_log::Level::Info,
log::Level::Trace => own_log::Level::Trace,
log::Level::Warn => own_log::Level::Warn,
},
&format!("[{}] {}", src, record.args()),
);
}

fn flush(&self) {}
}
10 changes: 6 additions & 4 deletions cli/src/commands/tunnels.rs
View file
Open in desktop
Expand Up @@ -22,7 +22,7 @@ use crate::{
auth::Auth,
constants::APPLICATION_NAME,
json_rpc::{new_json_rpc, start_json_rpc},
log::{self, Logger},
log,
singleton::connect_as_client,
state::LauncherPaths,
tunnels::{
Expand Down Expand Up @@ -330,10 +330,14 @@ fn get_connection_token(tunnel: &ActiveTunnel) -> String {

async fn serve_with_csa(
paths: LauncherPaths,
mut log: Logger,
mut log: log::Logger,
gateway_args: TunnelServeArgs,
mut csa: CodeServerArgs,
) -> Result<i32, AnyError> {
let log_broadcast = BroadcastLogSink::new();
log = log.tee(log_broadcast.clone());
log::install_global_logger(log.clone()); // re-install so that library logs are captured

let shutdown = match gateway_args
.parent_process_id
.and_then(|p| Pid::from_str(&p).ok())
Expand Down Expand Up @@ -377,8 +381,6 @@ async fn serve_with_csa(

debug!(log, "starting as new singleton");

let log_broadcast = BroadcastLogSink::new();
log = log.tee(log_broadcast.clone());
let mut server =
make_singleton_server(log_broadcast.clone(), log.clone(), server, shutdown.clone());
let platform = spanf!(log, log.span("prereq"), PreReqChecker::new().verify())?;
Expand Down
67 changes: 57 additions & 10 deletions cli/src/log.rs
View file
Open in desktop
Expand Up @@ -178,7 +178,7 @@ impl LogSink for FileLogSink {
return;
}

let line = format(level, prefix, message);
let line = format(level, prefix, message, false);

// ignore any errors, not much we can do if logging fails...
self.file.lock().unwrap().write_all(line.as_bytes()).ok();
Expand Down Expand Up @@ -295,31 +295,78 @@ impl<'a> crate::util::io::ReportCopyProgress for DownloadLogger<'a> {
}
}

pub fn format(level: Level, prefix: &str, message: &str) -> String {
fn format(level: Level, prefix: &str, message: &str, use_colors: bool) -> String {
let current = Local::now();
let timestamp = current.format("%Y-%m-%d %H:%M:%S").to_string();

let name = level.name().unwrap();

if let Some(c) = level.color_code() {
format!(
"\x1b[2m[{}]\x1b[0m {}{}\x1b[0m {}{}\n",
timestamp, c, name, prefix, message
)
} else {
format!("[{}] {} {}{}\n", timestamp, name, prefix, message)
if use_colors {
if let Some(c) = level.color_code() {
return format!(
"\x1b[2m[{}]\x1b[0m {}{}\x1b[0m {}{}\n",
timestamp, c, name, prefix, message
);
}
}

format!("[{}] {} {}{}\n", timestamp, name, prefix, message)
}

pub fn emit(level: Level, prefix: &str, message: &str) {
let line = format(level, prefix, message);
let line = format(level, prefix, message, true);
if level == Level::Trace {
print!("\x1b[2m{}\x1b[0m", line);
} else {
print!("{}", line);
}
}

/// Installs the logger instance as the global logger for the 'log' service.
/// Replaces any existing registered logger. Note that the logger will be leaked/
pub fn install_global_logger(log: Logger) {
log::set_logger(Box::leak(Box::new(RustyLogger(log))))
.map(|()| log::set_max_level(log::LevelFilter::Debug))
.expect("expected to make logger");
}

/// Logger that uses the common rust "log" crate and directs back to one of
/// our managed loggers.
struct RustyLogger(Logger);

impl log::Log for RustyLogger {
fn enabled(&self, metadata: &log::Metadata) -> bool {
metadata.level() <= log::Level::Debug
}

fn log(&self, record: &log::Record) {
if !self.enabled(record.metadata()) {
return;
}

// exclude noisy log modules:
let src = match record.module_path() {
Some("russh::cipher") => return,
Some("russh::negotiation") => return,
Some(s) => s,
None => "<unknown>",
};

self.0.emit(
match record.level() {
log::Level::Debug => Level::Debug,
log::Level::Error => Level::Error,
log::Level::Info => Level::Info,
log::Level::Trace => Level::Trace,
log::Level::Warn => Level::Warn,
},
&format!("[{}] {}", src, record.args()),
);
}

fn flush(&self) {}
}

#[macro_export]
macro_rules! error {
($logger:expr, $str:expr) => {
Expand Down