Apply code review suggestions. Rename decorating_pipe to logging_pipe. Add plugin_id to plugin log. Move logger init from file to in-code initialization and change logging file to zellij directory. Change format of timestamp.

This commit is contained in:
Paweł Palenica 2021-07-13 23:22:11 -07:00
parent a38c176646
commit b15cfba6e1
14 changed files with 143 additions and 123 deletions

1
.gitignore vendored
View file

@ -5,4 +5,3 @@
.DS_Store
/assets/man/zellij.1
**/target
zellij.log

82
Cargo.lock generated
View file

@ -46,9 +46,9 @@ dependencies = [
[[package]]
name = "anyhow"
version = "1.0.41"
version = "1.0.42"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "15af2628f6890fe2609a3b91bef4c83450512802e59489f9c1cb1fa5df064a61"
checksum = "595d3cfa7a60d4555cb5067b99f07142a08ea778de5cf993f7b75c7d8fabc486"
[[package]]
name = "arc-swap"
@ -105,12 +105,11 @@ dependencies = [
[[package]]
name = "async-io"
version = "1.4.1"
version = "1.6.0"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "4bbfd5cf2794b1e908ea8457e6c45f8f8f1f6ec5f74617bf4662623f47503c3b"
checksum = "a811e6a479f2439f0c04038796b5cfb3d2ad56c230e0f2d3f7b04d68cfee607b"
dependencies = [
"concurrent-queue",
"fastrand",
"futures-lite",
"libc",
"log",
@ -211,12 +210,12 @@ checksum = "065374052e7df7ee4047b1160cca5e1467a12351a40b3da123c870ba0b8eda2a"
[[package]]
name = "atty"
version = "0.2.11"
version = "0.2.14"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "9a7d5b8723950951411ee34d271d99dddcc2035a16ab25310ea2c8cfd4369652"
checksum = "d9b39be18770d11421cdb1b9947a45dd3f37e93092cbf377614828a319d5fee8"
dependencies = [
"hermit-abi",
"libc",
"termion",
"winapi",
]
@ -308,9 +307,9 @@ checksum = "df8670b8c7b9dae1793364eafadf7239c40d669904660c5960d74cfd80b46a53"
[[package]]
name = "cc"
version = "1.0.68"
version = "1.0.69"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "4a72c244c1ff497a746a7e1fb3d14bd08420ecda70c8f25c7112f2781652d787"
checksum = "e70cc2f62c6ce1868963827bd677764c62d07c3d9a3e1fb1177ee1a9ab199eb2"
[[package]]
name = "cfg-if"
@ -589,9 +588,9 @@ dependencies = [
[[package]]
name = "darling"
version = "0.12.4"
version = "0.13.0"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "5f2c43f534ea4b0b049015d00269734195e6d3f0f6635cb692251aca6f9f8b3c"
checksum = "757c0ded2af11d8e739c4daea1ac623dd1624b06c844cf3f5a39f1bdbd99bb12"
dependencies = [
"darling_core",
"darling_macro",
@ -599,9 +598,9 @@ dependencies = [
[[package]]
name = "darling_core"
version = "0.12.4"
version = "0.13.0"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "8e91455b86830a1c21799d94524df0845183fa55bafd9aa137b01c7d1065fa36"
checksum = "2c34d8efb62d0c2d7f60ece80f75e5c63c1588ba68032740494b0b9a996466e3"
dependencies = [
"fnv",
"ident_case",
@ -613,9 +612,9 @@ dependencies = [
[[package]]
name = "darling_macro"
version = "0.12.4"
version = "0.13.0"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "29b5acf0dea37a7f66f7b25d2c5e93fd46f8f6968b1a5d7a3e02e97768afc95a"
checksum = "ade7bff147130fe5e6d39f089c6bd49ec0250f35d70b2eebf72afdfc919f15cc"
dependencies = [
"darling_core",
"quote",
@ -674,18 +673,18 @@ checksum = "a357d28ed41a50f9c765dbfe56cbc04a64e53e5fc58ba79fbc34c10ef3df831f"
[[package]]
name = "enumset"
version = "1.0.6"
version = "1.0.7"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "fbd795df6708a599abf1ee10eacc72efd052b7a5f70fdf0715e4d5151a6db9c3"
checksum = "7e76129da36102af021b8e5000dab2c1c30dbef85c1e482beeff8da5dde0e0b0"
dependencies = [
"enumset_derive",
]
[[package]]
name = "enumset_derive"
version = "0.5.4"
version = "0.5.5"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "e19c52f9ec503c8a68dc04daf71a04b07e690c32ab1a8b68e33897f255269d47"
checksum = "6451128aa6655d880755345d085494cf7561a6bee7c8dc821e5d77e6d267ecd4"
dependencies = [
"darling",
"proc-macro2",
@ -980,9 +979,9 @@ dependencies = [
[[package]]
name = "instant"
version = "0.1.9"
version = "0.1.10"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "61124eeebbd69b8190558df225adf7e4caafce0d743919e5d6b19652314ec5ec"
checksum = "bee0328b1209d157ef001c94dd85b4f8f64139adb0eac2659f4b08382b2f474d"
dependencies = [
"cfg-if 1.0.0",
]
@ -1070,9 +1069,9 @@ checksum = "3576a87f2ba00f6f106fdfcd16db1d698d648a26ad8e0573cad8537c3c362d2a"
[[package]]
name = "libc"
version = "0.2.97"
version = "0.2.98"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "12b8adadd720df158f4d70dfe7ccc6adb0472d7c55ca83445f6a5ab3e36f8fb6"
checksum = "320cfe77175da3a483efed4bc0adc1968ca050b098ce4f2f1c13a56626128790"
[[package]]
name = "libloading"
@ -1354,9 +1353,9 @@ dependencies = [
[[package]]
name = "ordered-float"
version = "2.5.1"
version = "2.7.0"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "f100fcfb41e5385e0991f74981732049f9b896821542a219420491046baafdc2"
checksum = "039f02eb0f69271f26abe3202189275d7aa2258b903cb0281b5de710a2570ff3"
dependencies = [
"num-traits",
]
@ -1925,9 +1924,9 @@ checksum = "73473c0e59e6d5812c5dfe2a064a6444949f089e20eec9a2e5506596494e4623"
[[package]]
name = "structopt"
version = "0.3.21"
version = "0.3.22"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "5277acd7ee46e63e5168a80734c9f6ee81b1367a7d8772a2d765df2a3705d28c"
checksum = "69b041cdcb67226aca307e6e7be44c8806423d83e018bd662360a93dabce4d71"
dependencies = [
"clap",
"lazy_static",
@ -1936,9 +1935,9 @@ dependencies = [
[[package]]
name = "structopt-derive"
version = "0.4.14"
version = "0.4.15"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "5ba9cdfda491b814720b6b06e0cac513d922fc407582032e8706e9f137976f90"
checksum = "7813934aecf5f51a54775e00068c237de98489463968231a51746bbbc03f9c10"
dependencies = [
"heck",
"proc-macro-error",
@ -2050,18 +2049,18 @@ dependencies = [
[[package]]
name = "thiserror"
version = "1.0.25"
version = "1.0.26"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "fa6f76457f59514c7eeb4e59d891395fab0b2fd1d40723ae737d64153392e9c6"
checksum = "93119e4feac1cbe6c798c34d3a53ea0026b0b1de6a120deef895137c0529bfe2"
dependencies = [
"thiserror-impl",
]
[[package]]
name = "thiserror-impl"
version = "1.0.25"
version = "1.0.26"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "8a36768c0fbf1bb15eca10defa29526bda730a2376c2ab4393ccfa16fb1a318d"
checksum = "060d69a0afe7796bf42e9e2ff91f5ee691fb15c53d38b4b62a9a53eb23164745"
dependencies = [
"proc-macro2",
"quote",
@ -2081,11 +2080,12 @@ dependencies = [
[[package]]
name = "time"
version = "0.1.43"
version = "0.1.44"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "ca8a50ef2360fbd1eeb0ecd46795a87a19024eb4b53c5dc916ca1fd95fe62438"
checksum = "6db9e6914ab8b1ae1c260a4ae7a49b6c5611b40328a735b21862567685e73255"
dependencies = [
"libc",
"wasi",
"winapi",
]
@ -2163,9 +2163,9 @@ dependencies = [
[[package]]
name = "unicode-segmentation"
version = "1.7.1"
version = "1.8.0"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "bb0d2e7be6ae3a5fa87eed5fb451aff96f2573d2694942e40543ae0bbe19c796"
checksum = "8895849a949e7845e06bd6dc1aa51731a103c42707010a5b591c0038fb73385b"
[[package]]
name = "unicode-width"
@ -2272,9 +2272,9 @@ checksum = "9d5b2c62b4012a3e1eca5a7e077d13b3bf498c4073e33ccd58626607748ceeca"
[[package]]
name = "wasi"
version = "0.10.2+wasi-snapshot-preview1"
version = "0.10.0+wasi-snapshot-preview1"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "fd6fbd9a79829dd1ad0cc20627bf1ed606756a7f77edff7b66b7064f9cb327c6"
checksum = "1a143597ca7c7793eff794def352d41792a93c481eb1042423ff7ff72ba2c31f"
[[package]]
name = "wasm-bindgen"
@ -2639,6 +2639,7 @@ name = "zellij-client"
version = "0.15.0"
dependencies = [
"insta",
"log",
"mio",
"termbg",
"zellij-utils",
@ -2652,6 +2653,7 @@ dependencies = [
"async-trait",
"base64",
"cassowary",
"chrono",
"daemonize",
"insta",
"log",

View file

@ -133,7 +133,6 @@ fn color_elements(palette: Palette) -> ColoredElements {
impl ZellijPlugin for State {
fn load(&mut self) {
dbg!("hello from load");
set_selectable(false);
set_invisible_borders(true);
set_fixed_height(2);

View file

@ -9,15 +9,11 @@ register_plugin!(State);
impl ZellijPlugin for State {
fn load(&mut self) {
dbg!("hello from load");
dbg!("hello from load2?");
refresh_directory(self);
subscribe(&[EventType::KeyPress]);
}
fn update(&mut self, event: Event) {
dbg!("hello from update");
if let Event::KeyPress(key) = event {
match key {
Key::Up | Key::Char('k') => {

View file

@ -21,7 +21,7 @@ use zellij_utils::{
pub fn main() {
configure_logger();
info!("Hello Zellij!");
info!("Starting Zellij!");
let opts = CliArgs::from_args();
if let Some(Command::Sessions(Sessions::ListSessions)) = opts.command {

View file

@ -12,6 +12,7 @@ license = "MIT"
mio = "0.7.11"
termbg = "0.2.3"
zellij-utils = { path = "../zellij-utils/", version = "0.15.0" }
log = "0.4.14"
[dev-dependencies]
insta = "1.6.0"

View file

@ -3,6 +3,7 @@ pub mod os_input_output;
mod command_is_executing;
mod input_handler;
use log::info;
use std::env::current_exe;
use std::io::{self, Write};
use std::path::Path;
@ -291,6 +292,7 @@ pub fn start_client(
);
os_input.disable_mouse();
info!("{}", exit_msg);
os_input.unset_raw_mode(0);
let mut stdout = os_input.get_stdout_writer();
let _ = stdout.write(goodbye_message.as_bytes()).unwrap();

View file

@ -21,6 +21,7 @@ cassowary = "0.3.0"
zellij-utils = { path = "../zellij-utils/", version = "0.15.0" }
log = "0.4.14"
typetag = "0.1.7"
chrono = "0.4.19"
[dev-dependencies]
insta = "1.6.0"

View file

@ -2,7 +2,7 @@ pub mod os_input_output;
pub mod panes;
pub mod tab;
mod decorating_pipe;
mod logging_pipe;
mod pty;
mod route;
mod screen;

View file

@ -3,32 +3,51 @@ use std::{
io::{Read, Seek, Write},
};
use log::{error, info};
use log::{debug, error, info};
use wasmer_wasi::{WasiFile, WasiFsError};
use zellij_utils::serde;
use chrono::prelude::*;
use serde::{Deserialize, Serialize};
// 16kB log buffer
const ZELLIJ_MAX_PIPE_BUFFER_SIZE: usize = 16_384;
#[derive(Debug, Serialize, Deserialize)]
#[serde(crate = "self::serde")]
pub struct DecoratingPipe {
pub struct LoggingPipe {
buffer: VecDeque<u8>,
plugin_name: String,
plugin_id: u32,
}
impl DecoratingPipe {
pub fn new(plugin_name: &str) -> DecoratingPipe {
info!("Creating decorating pipe for plugin: {}!", plugin_name);
DecoratingPipe {
impl LoggingPipe {
pub fn new(plugin_name: &str, plugin_id: u32) -> LoggingPipe {
info!(
"|{:<25.25}| {} [{:<10.15}] Creating decorating pipe for plugin: {}!",
plugin_name,
Local::now().format("%Y-%m-%d %H:%M:%S.%3f"),
format!("id: {}", plugin_id),
plugin_name
);
LoggingPipe {
buffer: VecDeque::new(),
plugin_name: String::from(plugin_name),
plugin_id,
}
}
fn log_message(&self, message: &str) {
debug!(
"|{:<25.25}| {} [{:<10.15}] {}",
self.plugin_name,
Local::now().format("%Y-%m-%d %H:%M:%S.%3f"),
format!("id: {}", self.plugin_id),
message
);
}
}
impl Read for DecoratingPipe {
impl Read for LoggingPipe {
fn read(&mut self, buf: &mut [u8]) -> std::io::Result<usize> {
let amt = std::cmp::min(buf.len(), self.buffer.len());
for (i, byte) in self.buffer.drain(..amt).enumerate() {
@ -38,11 +57,9 @@ impl Read for DecoratingPipe {
}
}
impl Write for DecoratingPipe {
impl Write for LoggingPipe {
fn write(&mut self, buf: &[u8]) -> std::io::Result<usize> {
self.buffer.extend(buf);
if self.buffer.len() > ZELLIJ_MAX_PIPE_BUFFER_SIZE {
if self.buffer.len() + buf.len() > ZELLIJ_MAX_PIPE_BUFFER_SIZE {
let error_msg =
"Exceeded log buffer size. Make sure that your plugin calls flush on stderr on \
valid UTF-8 symbol boundary. Aditionally, make sure that your log message contains \
@ -55,6 +72,8 @@ impl Write for DecoratingPipe {
));
}
self.buffer.extend(buf);
Ok(buf.len())
}
@ -73,11 +92,11 @@ impl Write for DecoratingPipe {
if split_converted_buffer.peek().is_none() {
// Log last chunk iff the last char is endline. Otherwise do not do it.
if converted_buffer.chars().last().unwrap() == '\n' && !msg.is_empty() {
info!("|{:<25}| {}", self.plugin_name, msg);
self.log_message(msg);
consumed_bytes += msg.len() + 1;
}
} else {
info!("|{:<25}| {}", self.plugin_name, msg);
self.log_message(msg);
consumed_bytes += msg.len() + 1;
}
}
@ -91,7 +110,7 @@ impl Write for DecoratingPipe {
}
}
impl Seek for DecoratingPipe {
impl Seek for LoggingPipe {
fn seek(&mut self, _pos: std::io::SeekFrom) -> std::io::Result<u64> {
Err(std::io::Error::new(
std::io::ErrorKind::Other,
@ -101,7 +120,7 @@ impl Seek for DecoratingPipe {
}
#[typetag::serde]
impl WasiFile for DecoratingPipe {
impl WasiFile for LoggingPipe {
fn last_accessed(&self) -> u64 {
0
}
@ -128,13 +147,13 @@ impl WasiFile for DecoratingPipe {
// Unit tests
#[cfg(test)]
mod decorating_pipe_test {
mod logging_pipe_test {
use super::*;
#[test]
fn write_without_endl_does_not_consume_buffer_after_flush() {
let mut pipe = DecoratingPipe::new("TestPipe");
let mut pipe = LoggingPipe::new("TestPipe", 0);
let test_buffer = "Testing write".as_bytes();
@ -146,7 +165,7 @@ mod decorating_pipe_test {
#[test]
fn write_with_single_endl_at_the_end_consumes_whole_buffer_after_flush() {
let mut pipe = DecoratingPipe::new("TestPipe");
let mut pipe = LoggingPipe::new("TestPipe", 0);
let test_buffer = "Testing write \n".as_bytes();
@ -158,7 +177,7 @@ mod decorating_pipe_test {
#[test]
fn write_with_endl_in_the_middle_consumes_buffer_up_to_endl_after_flush() {
let mut pipe = DecoratingPipe::new("TestPipe");
let mut pipe = LoggingPipe::new("TestPipe", 0);
let test_buffer = "Testing write \n".as_bytes();
let test_buffer2 = "And the rest".as_bytes();
@ -182,7 +201,7 @@ mod decorating_pipe_test {
#[test]
fn write_with_many_endl_consumes_whole_buffer_after_flush() {
let mut pipe = DecoratingPipe::new("TestPipe");
let mut pipe = LoggingPipe::new("TestPipe", 0);
let test_buffer = "Testing write \n".as_bytes();
@ -205,7 +224,7 @@ mod decorating_pipe_test {
#[test]
fn write_with_incorrect_byte_boundary_does_not_crash() {
let mut pipe = DecoratingPipe::new("TestPipe");
let mut pipe = LoggingPipe::new("TestPipe", 0);
let test_buffer = "😱".as_bytes();

View file

@ -17,7 +17,7 @@ use wasmer_wasi::{Pipe, WasiEnv, WasiState};
use zellij_tile::data::{Event, EventType, PluginIds};
use crate::{
decorating_pipe::DecoratingPipe,
logging_pipe::LoggingPipe,
panes::PaneId,
pty::PtyInstruction,
screen::ScreenInstruction,
@ -57,7 +57,7 @@ pub(crate) struct PluginEnv {
// Thread main --------------------------------------------------------------------------------------------------------
pub(crate) fn wasm_thread_main(bus: Bus<PluginInstruction>, store: Store, data_dir: PathBuf) {
info!("Wasm create thread :))");
info!("Wasm main thread starts");
let mut plugin_id = 0;
let mut plugin_map = HashMap::new();
loop {
@ -76,8 +76,10 @@ pub(crate) fn wasm_thread_main(bus: Bus<PluginInstruction>, store: Store, data_d
let output = Pipe::new();
let input = Pipe::new();
let stderr =
DecoratingPipe::new(path.as_path().file_name().unwrap().to_str().unwrap());
let stderr = LoggingPipe::new(
path.as_path().file_name().unwrap().to_str().unwrap(),
plugin_id,
);
let mut wasi_env = WasiState::new("Zellij")
.env("CLICOLOR_FORCE", "1")
.preopen(|p| {

View file

@ -19,7 +19,6 @@ macro_rules! register_plugin {
}
fn main() {
dbg!("hello from plugin main :)");
STATE.with(|state| {
state.borrow_mut().load();
});

View file

@ -1,46 +0,0 @@
# Scan this file for changes every 30 seconds
refresh_rate: 30 seconds
appenders:
# An appender named "stderr" that writes to stderr
stderr:
kind: console
target: stderr
# default zellij appender, should be used across most of the codebase.
logFile:
kind: file
path: "zellij.log"
append: false
encoder:
# {n} means platform dependent newline
# module is padded to *at least* 25 bytes and thread is padded to be between 10 and 15 bytes.
pattern: "|{module:<25}| {date} {highlight({level})} [{thread:<10.15}] [{file}:{line}]: {message} {n}"
# plugin appender. To be used in decorating_pipe to forward stderr output from plugins.
logPlugin:
kind: file
path: "zellij.log"
encoder:
# {n} means platform dependent newline
pattern: "{message} {n}"
# Set the default logging level to "info" and log it to zellij.log file
root:
level: info
appenders:
- logFile
loggers:
# decrease verbosity for this module because it has a lot of useless info logs
wasmer_compiler_cranelift:
level: warn
appenders:
- logFile
# For decorating_pipe, we use custom format as we use logging macros to forward stderr output from plugins
zellij_server::decorating_pipe:
level: trace
appenders:
- logPlugin
additive: false

View file

@ -7,13 +7,59 @@ use std::{
path::{Path, PathBuf},
};
use log::info;
use log::{info, LevelFilter};
use log4rs::append::file::FileAppender;
use log4rs::config::{Appender, Config, Logger, Root};
use log4rs::encode::pattern::PatternEncoder;
use crate::consts::{ZELLIJ_TMP_LOG_DIR, ZELLIJ_TMP_LOG_FILE};
use crate::shared::set_permissions;
pub fn configure_logger() {
log4rs::init_file("zellij-utils/assets/config/log4rs.yml", Default::default()).unwrap();
// {n} means platform dependent newline
// module is padded to exactly 25 bytes and thread is padded to be between 10 and 15 bytes.
let file_pattern = "{highlight({level:<6})} |{module:<25.25}| {date(%Y-%m-%d %H:%M:%S.%3f)} [{thread:<10.15}] [{file}:{line}]: {message} {n}";
// default zellij appender, should be used across most of the codebase.
let log_file = FileAppender::builder()
.encoder(Box::new(PatternEncoder::new(file_pattern)))
.append(true)
.build(ZELLIJ_TMP_LOG_DIR.join("zellij.log"))
.unwrap();
// plugin appender. To be used in loggin_pipe to forward stderr output from plugins. We do some formatting
// in logging_pipe to print plugin name as 'module' and plugin_id instead of thread.
let log_plugin = FileAppender::builder()
.encoder(Box::new(PatternEncoder::new(
"{highlight({level:<6})} {message} {n}",
)))
.append(true)
.build(ZELLIJ_TMP_LOG_DIR.join("zellij.log"))
.unwrap();
// Set the default logging level to "info" and log it to zellij.log file
// Decrease verbosity for `wasmer_compiler_cranelift` module because it has a lot of useless info logs
// For `zellij_server::logging_pipe`, we use custom format as we use logging macros to forward stderr output from plugins
let config = Config::builder()
.appender(Appender::builder().build("logFile", Box::new(log_file)))
.appender(Appender::builder().build("logPlugin", Box::new(log_plugin)))
.logger(
Logger::builder()
.appender("logFile")
.build("wasmer_compiler_cranelift", LevelFilter::Warn),
)
.logger(
Logger::builder()
.appender("logPlugin")
.additive(false)
.build("zellij_server::logging_pipe", LevelFilter::Trace),
)
.build(Root::builder().appender("logFile").build(LevelFilter::Info))
.unwrap();
let _ = log4rs::init_config(config).unwrap();
info!("Zellij logger initialized");
}