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.

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

syslog Logger's messages get dropped by daemon(3) #58

Open
asomers opened this issue Nov 19, 2024 · 12 comments
Open

syslog Logger's messages get dropped by daemon(3) #58

asomers opened this issue Nov 19, 2024 · 12 comments

Comments

@asomers
Copy link

asomers commented Nov 19, 2024

daemon(3) is a handy helper to create a daemon process. It closes stdin, stdout, and stderr, forks the process, exits the parent, and leaves the child running. Unfortunately, using daemon(3) with sloggers's syslog module results in messages being lost.

Internally, daemon(3) calls exit(3) in the parent process. That would explain why the parent process doesn't actually send the messages. But the Logger object lives on in the child process. Why doesn't the child ever send the messages?

Reproducer:

use sloggers::Build;

fn main() {
    let logger = sloggers::syslog::SyslogBuilder::new()
        .log_ndelay()   // This line doesn't make a difference
        .build().unwrap();

    // Try to send a log message.  But it never gets received by syslogd :(
    slog::warn!(logger, "syslog-daemon example log entry");

    // Enabling this sleep will allow the log message to be sent.
    //std::thread::sleep(std::time::Duration::from_secs(1));

    // Dropping the logger here, in the parent, will result in the log message being sent.
    //drop(logger);

    // Disabling this daemon will allow the log message to be sent.
    nix::unistd::daemon(false, false).unwrap();

    // Dropping the logger here, in the child, does _not_ allow the log message to be sent.
    drop(logger);
}
@sile
Copy link
Owner

sile commented Nov 19, 2024

That behavior sounds strange.
At the moment, I have no idea about the cause, but I'll take some time to look into this issue either this weekend or the next.

As for the question, is this issue specific to SyslogBuilder, or can it be reproduced with a non-syslog logger such as FileLoggerBuilder?

@asomers
Copy link
Author

asomers commented Nov 19, 2024

That behavior sounds strange. At the moment, I have no idea about the cause, but I'll take some time to look into this issue either this weekend or the next.

As for the question, is this issue specific to SyslogBuilder, or can it be reproduced with a non-syslog logger such as FileLoggerBuilder?

I can't reproduce it with TerminalLoggerBuilder. I haven't tried FileLoggerBuilder.

@sile
Copy link
Owner

sile commented Nov 19, 2024

I see. Thank you.

@sile
Copy link
Owner

sile commented Dec 1, 2024

I've been occupied for a while, but I believe I can investigate this issue this week.
(However, I'm not sure if I can resolve it, as I'm not familiar with syslog and wasn't the one who implemented the syslog logger.)

@sile
Copy link
Owner

sile commented Dec 4, 2024

I was unable to build the code above on my macOS machine:

error[E0425]: cannot find function `daemon` in module `nix::unistd`
   --> src/main.rs:19:18
    |
19  |     nix::unistd::daemon(false, false).unwrap();
    |                  ^^^^^^ not found in `nix::unistd`
    |
note: found an item that was configured out
   --> /Users/tohta/.cargo/registry/src/index.crates.io-6f17d22bba15001f/nix-0.29.0/src/unistd.rs:994:8
    |
994 | pub fn daemon(nochdir: bool, noclose: bool) -> Result<()> {
    |        ^^^^^^
note: the item is gated here
   --> /Users/tohta/.cargo/registry/src/index.crates.io-6f17d22bba15001f/nix-0.29.0/src/unistd.rs:988:1
    |
988 | / #[cfg(any(
989 | |         linux_android,
990 | |         freebsdlike,
991 | |         solarish,
992 | |         netbsdlike
993 | | ))]

At the moment, I don't have a Linux machine, so it seems difficult to investigate the problem in detail.

By the way, the comment in syslog.rs states, "POSIX doesn't support opening more than one connection to syslogd at a time": https://github.com/sile/sloggers/blob/master/src/syslog.rs#L8-L11
Therefore, this restriction might be causing the issue (just a thought, although I'm not sure).

@sile
Copy link
Owner

sile commented Dec 4, 2024

Another possibility is that the implicitSyslogDrain::drop() call on the parent might cause some issues, although I'm not certain about this idea either.

@asomers
Copy link
Author

asomers commented Dec 12, 2024

This example should work on OSX, but you'll have to use a patched version of Nix.

[patch.crates-io]
nix = { git = "https://github.com/asomers/nix.git", branch="apple-daemon"}

@sile
Copy link
Owner

sile commented Dec 13, 2024

Thank you. I'll try the patch this weekend.

@sile
Copy link
Owner

sile commented Dec 14, 2024

Hmm, I encountered the following error after enabling the patch:

$ cargo check --manifest-path /Users/tohta/dev/rust/sloggers/Cargo.toml
    Updating git repository `https://github.com/asomers/nix.git`
error: failed to load source for dependency `nix`

Caused by:
  Unable to update https://github.com/asomers/nix.git?branch=apple-daemon

Caused by:
  failed to find branch `apple-daemon`

Caused by:
  cannot locate remote-tracking branch 'origin/apple-daemon'; class=Reference (4); code=NotFound (-3)

It seems no such branch on the nix repository:
image

@asomers
Copy link
Author

asomers commented Dec 14, 2024

Oops, I must've forgotten to push it. Sorry. Please try again.

@sile
Copy link
Owner

sile commented Dec 14, 2024

Thank you. I was able to build the patched version.

Upon investigation, it turned out that this behavior is not unique to SyslogBuilder and can also be reproduced with FileBuilder.
Furthermore, it can be replicated even when using the slog crate directly, without the slogger crate, as follows:

// This example code is based on the slog's official example:
// - https://docs.rs/slog/latest/slog/#logging-to-a-file
 use slog::Drain;
 use std::fs::OpenOptions;

 fn main() { 
     let log_path = "/tmp/issue58.log";
     let file = OpenOptions::new()
         .create(true)
         .write(true)
         .truncate(true)
         .open(log_path)
         .unwrap();

     let decorator = slog_term::PlainDecorator::new(file);
     let drain = slog_term::FullFormat::new(decorator).build().fuse();
     let drain = slog_async::Async::new(drain).build().fuse();

     let logger = slog::Logger::root(drain, slog::o!());

     slog::info!(logger, "hello");

     // Without this line, the "hello" message will not be logged to the file (though there is some stochastic behavior involved)
     std::thread::sleep(std::time::Duration::from_millis(500));

     nix::unistd::daemon(false, false).unwrap();
 
     // This message will disappear if the daemon() function above is called.
     slog::info!(logger, "world");
     std::thread::sleep(std::time::Duration::from_millis(500));
 }

It appears that slog::Logger does not support daemon().
Since slogger is simply a wrapper library for slog, it seems difficult to resolve this issue at the sloggers layer.

@asomers
Copy link
Author

asomers commented Dec 14, 2024

Hey, great work! I'll take this issue up in the slog repo. Thanks for your help.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants