feat: file logging #54

hnidoaht-101 · 2022-08-25T06:20:31Z

File logging

This PR is served for #39.

Implementation (Optional)

Following TODO placeholder left in the source code.

I have

run cargo fmt;
run cargo clippy;
run cargo testand all tests pass;
linked to the originating issue (if applicable).

MatteoNardi

Hi @hnidoaht-101, thanks for the PR and welcome to the project!

Apart from the minor issues I've highlighted below, this patch disables the main pulsar logging infrastructure, which uses env_logger.

There are some higher level design decisions I'd like to discuss with @banditopazzo before merging it (BTW, he's currently on holiday, he'll be back early next week):

How to integrate with general pulsar logging
Possible paths forward include:

Creating a multiplexing logger
Installing only the log4rs logger
Avoid installing log4rs as the logger. Write logs directly, maybe reusing log4rs code.
Check if the tracing ecosystem offers a better solution.

Reusing pulsar.ini vs external log4rs config
Reusing the pulsar.ini would give better consistency, pulsar CLI integration and eventual hot reloading. On the other hand, the external file gives greater flexibility and more features.

Logging of non-threat events
What should a user do if he wants to log also non-threat events? Maybe a work-around would be marking all/some events as threat from the rule-engine.

Logging of application log
What should a user do if he wants to log to file also application logs? I'd reuse systemd, but we may need a way to do it if that's not acceptable. It's probably an uncommon use-case and I would probably handle it in a different module/way.

MatteoNardi · 2022-08-25T07:40:35Z

modules/logger/src/lib.rs

+
+use std::path::PathBuf;
+
+use log::info;


For consistency with the rest of the project, remove the use log::info line and use log::info!() in the code below.

MatteoNardi · 2022-08-25T07:48:06Z

modules/logger/src/lib.rs

@@ -47,27 +54,41 @@ impl TryFrom<&ModuleConfig> for Config {
    fn try_from(config: &ModuleConfig) -> Result<Self, Self::Error> {
        Ok(Self {
            console: config.required("console").unwrap_or(true),
-            // file: config.required("file")?,
+            file: config.required("file").unwrap_or(false),


This should be: config.with_default("file", false)?
See pulsar-core/src/pdk/config.rs
That utility method has the added benefit of returning a config error if the user value is invalid (eg. [logger] file=invalid_value). By propagating it with ? we'll cause the logger module to fail and show the error to the user.

MatteoNardi · 2022-08-25T07:54:50Z

modules/logger/src/lib.rs

+                include_str!("../log4rs_conf.yml"),
+            ) {
+                Ok(it) => it,
+                Err(err) => println!("{}", err),


Warning should be logged with log::warn!(), not println!. The pre-existing println! line below is an exception (since this module goal is to output logs about events, we decided it made sense to write them to stdout directly)

An even better solution would be to propagate the error with ?, causing the module to fail.

MatteoNardi · 2022-08-25T07:55:48Z

modules/logger/src/logging.rs

+    println!(
+        "Initializing logging according to {:?}",
+        log_conf_file.to_str().unwrap_or("[??]")
+    );


log::info!

uhmm, at this point, I can use println! only because we start initializing logger here, log::info! has no effects.

MatteoNardi · 2022-08-25T08:27:49Z

modules/logger/src/logging.rs

+
+    if !log_conf_file.exists() {
+        if let Some(d) = log_conf_file.parent() {
+            fs::create_dir_all(d).map_err(|e| LoggerError::CreateParentDir(e.to_string()))?


Don't convert errors to strings, we may lose useful information when things go wrong.
A better solution is to keep the original error and wrap it:

pub enum LoggerError { #[error("Could not create log file's parent directory: {0}")] CreateParentDir(PathBuf, #[source] std::io::Error), ... if let Some(d) = log_conf_file.parent() { fs::create_dir_all(d).map_err(|e| LoggerError::CreateParentDir(d.to_path_buf(), e))? };

The same applies to the errors below.

To make things less verbose, we usually choose anyhow for error management in modules since it allows to just .with_context(|| format!("Could not create log file's parent directory: {d}"))?
In the core modules (pulsar-core, bpf-common, etc.) instead, we prefer to use thiserror.

Since you've already took care of using thiserror for this, I would keep it. If next time you feel lazy, go with anyhow.

MatteoNardi · 2022-08-25T08:36:00Z

pulsar/src/pulsard/mod.rs


 mod config;
 mod daemon;
 mod module_manager;
+mod shutdown_signal;


Please, split this change in a different PR.
Also, I'm not so sure about the need for this since right now we're Linux-only.
@banditopazzo what do you think?

yeah, sorry I didnt notice carefully, this one should belong to another PR. This is minor change I think, the point is I want to handle shutdown signal properly, before that we just handle 2 signal kinds.

hnidoaht-101 · 2022-08-25T13:13:56Z

hi @MatteoNardi thank for your detailed reviews 💯 I'll update minor issues first.
Based on your comment, I'd love to ask which possible path did you want to integrate with general pulsar logging? 😸
I should ask you guys before implementing this one 🥲

hnidoaht-101 · 2022-08-25T13:18:08Z

Ah, nice catch!

Reusing pulsar.ini vs external log4rs config
Reusing the pulsar.ini would give better consistency, pulsar CLI integration and eventual hot reloading. On the other hand, the external file gives greater flexibility and more features.

Actually I really wanted to reuse pulsar.ini for logging instead of external log4rs config. Err, you remind me about python logger ini file.... hmm, maybe we can use it with custom logger. Lemme think.

MatteoNardi · 2022-08-25T13:50:53Z

For now stick to to the minor issues and let's wait for Bandito's opinion before going forward.

I think we wanted to give tracing a try, the first solution which comes to mind would be replacing env_logger with tracing-subscriber and overriding it in the pulsar logger module by tracing-appender using with_default. But I don't want to waste your time on a solution we're not sure about, so let's wait some days.

hnidoaht-101 · 2022-08-26T05:00:59Z

replacing env_logger with tracing-subscriber and overriding it in the pulsar logger module by tracing-appender using with_default.

@MatteoNardi tracing crate is very useful, i didn't recognize it has tracing-appender, I've read its code. Yah we may give it a try 😄 Lemme know once you guys made final decision for this feature, I'd love to rework it.

banditopazzo · 2022-09-01T13:33:05Z

Hi,

I think it's better to implement a simple handwritten file logger which doesn't use the log subsystem.

This module is called logger but in reality is the "threat event logger". it's goal is to log only threat events and not all the application logs.

Application and the event logging and separate things, we don't want to mix them.

We have planned to take a look at tracing for the application wide logging, if we decide to switch to tracing we will rethink a new solution.

hnidoaht-101 · 2022-09-01T13:58:50Z

Hi,

I think it's better to implement a simple handwritten file logger which doesn't use the log subsystem.

This module is called logger but in reality is the "threat event logger". it's goal is to log only threat events and not all the application logs.

Application and the event logging and separate things, we don't want to mix them.

We have planned to take a look at tracing for the application wide logging, if we decide to switch to tracing we will rethink a new solution.

Got it. I will rework this PR & submit for review again.

banditopazzo · 2022-10-06T17:20:42Z

@hnidoaht-101 did you copy the code from https://github.com/polyverse/file-rotation/blob/main/src/asynchronous.rs ?

it's an unmaintained crate.

why did you change variables and function names?

I didn't have time to check in detail the code and in particular if the unsafe implementations of Send and Sync are legit, but I have doubts

at this state the code needs an accurate review, if you can't explain the code with better comments, a detailed review will be re scheduled for future

thaodt · 2022-10-07T05:27:35Z

@hnidoaht-101 did you copy the code from https://github.com/polyverse/file-rotation/blob/main/src/asynchronous.rs ?

it's an unmaintained crate.

why did you change variables and function names?

I didn't have time to check in detail the code and in particular if the unsafe implementations of Send and Sync are legit, but I have doubts

at this state the code needs an accurate review, if you can't explain the code with better comments, a detailed review will be re scheduled for future

Yeah sure, will add comment details for code. unsafe impl of Send and Sync are safe to use.
Refs:

P/s: im in holidays, be back next week to update, thank for ur review.

MatteoNardi · 2022-10-07T08:03:10Z

unsafe impl of Send and Sync are safe to use.

[nitpiking mode on] If PendingRename or PendingCreate contained a !Send future, it would be a bug. Since you're provinding those callbacks and they're Send, it's not a problem (except that we're not letting the compiler make sure of that). A solution is to add the requirement for the dyn object to be Send:

pub enum RotationState {                                                      
    PendingRename(Pin<Box<dyn Future<Output = io::Result<()>> + Send>>),      
    PendingCreate(Pin<Box<dyn Future<Output = io::Result<fs::File>> + Send>>),
    PendingFlush,                                                             
    Done,                                                                     
}

thaodt · 2022-10-07T10:24:47Z

unsafe impl of Send and Sync are safe to use.

[nitpiking mode on] If PendingRename or PendingCreate contained a !Send future, it would be a bug. Since you're provinding those callbacks and they're Send, it's not a problem (except that we're not letting the compiler make sure of that). A solution is to add the requirement for the dyn object to be Send:

pub enum RotationState {                                                      
    PendingRename(Pin<Box<dyn Future<Output = io::Result<()>> + Send>>),      
    PendingCreate(Pin<Box<dyn Future<Output = io::Result<fs::File>> + Send>>),
    PendingFlush,                                                             
    Done,                                                                     
}

Neat! Thanks @MatteoNardi. 👍
Regarding to async file rotation, Im gonna rewrite a bit, its not copying and adjust it based on our needs. Currently its following rule rename file of logrotate in linux, for e.g. file.log, file.0.log, file.1.log, etc .... If we want to rotate by date time and rename by datetime, the code need to be handled more for this case

hnidoaht-101 · 2022-10-23T05:23:13Z

As discussed with @banditopazzo, I'm going to close this PR first to rethink a simpler solution instead of using unmaintained version with my own update.

giovannialberto requested a review from MatteoNardi August 25, 2022 08:06

MatteoNardi suggested changes Aug 25, 2022

View reviewed changes

hnidoaht-101 requested a review from MatteoNardi August 25, 2022 14:10

hnidoaht-101 closed this Sep 2, 2022

hnidoaht-101 reopened this Sep 2, 2022

hnidoaht-101 marked this pull request as draft September 2, 2022 04:51

hnidoaht-101 added 2 commits September 7, 2022 18:17

feat: file logger basic cfg

f1651cf

fix: borrowing issue in writing file

1d21039

hnidoaht-101 closed this Oct 23, 2022

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

feat: file logging #54

feat: file logging #54

hnidoaht-101 commented Aug 25, 2022

MatteoNardi left a comment

MatteoNardi Aug 25, 2022

MatteoNardi Aug 25, 2022

MatteoNardi Aug 25, 2022

MatteoNardi Aug 25, 2022

hnidoaht-101 Aug 25, 2022

MatteoNardi Aug 25, 2022

MatteoNardi Aug 25, 2022

hnidoaht-101 Aug 25, 2022

hnidoaht-101 commented Aug 25, 2022

hnidoaht-101 commented Aug 25, 2022 •

edited

Loading

MatteoNardi commented Aug 25, 2022

hnidoaht-101 commented Aug 26, 2022

banditopazzo commented Sep 1, 2022

hnidoaht-101 commented Sep 1, 2022

banditopazzo commented Oct 6, 2022 •

edited

Loading

thaodt commented Oct 7, 2022

MatteoNardi commented Oct 7, 2022

thaodt commented Oct 7, 2022

hnidoaht-101 commented Oct 23, 2022

feat: file logging #54

feat: file logging #54

Conversation

hnidoaht-101 commented Aug 25, 2022

File logging

Implementation (Optional)

I have

MatteoNardi left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

hnidoaht-101 commented Aug 25, 2022

hnidoaht-101 commented Aug 25, 2022 • edited Loading

MatteoNardi commented Aug 25, 2022

hnidoaht-101 commented Aug 26, 2022

banditopazzo commented Sep 1, 2022

hnidoaht-101 commented Sep 1, 2022

banditopazzo commented Oct 6, 2022 • edited Loading

thaodt commented Oct 7, 2022

MatteoNardi commented Oct 7, 2022

thaodt commented Oct 7, 2022

hnidoaht-101 commented Oct 23, 2022

hnidoaht-101 commented Aug 25, 2022 •

edited

Loading

banditopazzo commented Oct 6, 2022 •

edited

Loading