Giter Site home page Giter Site logo

Fern and forks about fern HOT 10 OPEN

daboross avatar daboross commented on July 17, 2024
Fern and forks

from fern.

Comments (10)

amoffat avatar amoffat commented on July 17, 2024 1

It is looking very likely that a RwLock/Mutex-based version of a changeable logger is not going to have defined behavior while forking. From the pthread_rwlock_unlock man pages:

Results are undefined if the read-write lock rwlock is not held by the calling thread.

I don't know why it matters if the child is a copy of the parent, but there must be some bits of state in the lock that have a thread id in it, causing it to misbehave in a fork.

So as it stands, I think that it's not possible to use the threading primitives to make a fork-friendly logger work. Opening back up to suggestions.

from fern.

amoffat avatar amoffat commented on July 17, 2024 1

The userspace locking or atomics sounds feasible. I ended up going in a different direction with my forking/logging model though (still using fern though, love it! Great work), so this issue has less relevance to me now. Thank you for your feedback, and feel free to close the issue if it's not something you want to work towards. It is a pretty rare case I imagine.

from fern.

daboross avatar daboross commented on July 17, 2024

I don't think fern provides any utilities at the moment which allow changing loggers after setting an initial logger. This could be a reasonable feature, though!

In the meantime, if you need this a stopgap implementation like this should function:

use std::sync::RwLock;

use once_cell::sync::OnceCell;

static LOG_INSTANCE: OnceCell<RwLock<Option<Box<dyn log::Log>>>> = OnceCell::new();

struct UseChangeableLog;


impl log::Log for UseChangeableLog {
    fn enabled(&self, metadata: &log::Metadata) -> bool {
        with_log(|o| {
            o.map(|l| l.enabled(metadata)).unwrap_or(false)
        })
    }
    fn log(&self, record: &log::Record) {
        with_log(|o| {
            if let Some(l) = o {
                l.log(record);
            }
        })
    }
    fn flush(&self) {
        with_log(|o| {
            if let Some(l) = o {
                l.flush();
            }
        })
    }
}

fn with_log<O>(f: impl FnOnce(Option<&dyn log::Log>) -> O) -> O {
    let opt_lock = LOG_INSTANCE.get();
    match opt_lock {
        None => f(None),
        Some(lock) => {
            let guard = lock.read().unwrap();
            f(guard.as_ref().map(|b| &**b))
        }
    }
}

fn set_log_reusable(max: log::LevelFilter, log: Box<dyn log::Log>) {
    let mutex = LOG_INSTANCE.get_or_init(Default::default);
    {
        // ignore panics; we're completely overwriting the value
        let mut mutable = mutex.write().unwrap_or_else(|e| e.into_inner());
        *mutable = Some(log);
    }
    // this will fail after the first call. that's OK since we're storing the
    // log elsewhere - so ignore the result
    let _ = log::set_logger(&UseChangeableLog);
    // this call on the other hand IS callable multiple times
    log::set_max_level(max);
}

log's global logger can only be set once, so to provide one that can be changed we need to implement our own concurrency. To use with fern, instead of doing fern::Dispatch::apply, you can do Dispatch::into_log and call the new function:

fn configure_logger(...) {
    let dispatch = fern::Dispatch::new().x().y().z()...;
    let (max_level, boxed_logger) = dispatch.into_log();
    set_log(max_level, boxed_logger);
}

from fern.

amoffat avatar amoffat commented on July 17, 2024

@daboross thanks for the quick reply! Nice shim, worked perfectly as a drop-in replacement.

I'm having a little trouble getting it to work with forking though. The crux of the issue seems to be that if a thread in the parent process performs log while the child process is forking, that thread will hold the log mutex while the child process's memory space is copied from the parent. This means that--to the child--the log mutex is held forever, because the thread that acquired the mutex no longer exists in the child's memory space to release it. The result is that the child deadlocks when trying to set up its logger.

Threads and processes, fun :)

from fern.

daboross avatar daboross commented on July 17, 2024

Ah, that makes sense! Forking is tricky.

Do you think it'd be reasonable to grab a mutable lock before forking, and only release it once the operation is complete? That way you could guarantee that the mutex is in a consistent unlocked state after the fork completes.

Could be done with a utility function like

fn with_mutable_logger_lock<O>(f: FnOnce() -> O) -> O {
    let mutex = LOG_INSTANCE.get_or_init(Default::default);
    let mut mutable = mutex.write().unwrap_or_else(|e| e.into_inner());
    let result = f();
    // explicit drop not 100% necessary, but helps clarity
    drop(mutable);
    result
}

I was considering suggesting using an UnsafeCell and the guarantee that there are no threads running after a fork, but I don't think it'd be safe to drop the old logger, since there would be no guarantee it was in a consistent state when the fork happened.

from fern.

amoffat avatar amoffat commented on July 17, 2024

Acquire the lock, fork with f(), parent and child both release the lock, separately. It looks like it should work in theory. Still seeing a deadlock though when the child tries to acquire mutex.write(). Check this out:

use nix::unistd::{fork, ForkResult};
use once_cell::sync::OnceCell;
use std::error::Error;
use std::sync::Mutex;
use std::thread::{sleep, spawn};
use std::time::Duration;

static LOCK: OnceCell<Mutex<()>> = OnceCell::new();

fn with_lock<T>(f: impl FnOnce() -> T) -> T {
    let mutex = LOCK.get_or_init(Default::default);
    let guard = mutex.lock();
    let res = f();
    drop(guard);
    res
}

fn main() -> Result<(), Box<dyn Error>> {
    let bg_thread = spawn(|| loop {
        let mutex = LOCK.get_or_init(Default::default);
        let guard = mutex.lock();
        //println!("acquire in bg");
        sleep(Duration::from_millis(50));
        drop(guard);
        //println!("release in bg");
    });

    // give bg_thread a chance to start before forking
    sleep(Duration::from_millis(100));

    let res = with_lock(fork)?;
    match res {
        ForkResult::Child => {
            let mutex = LOCK.get().unwrap();
            let held = mutex.try_lock().is_err();
            println!("CHILD mutex held: {}", held);
        }
        ForkResult::Parent { child } => {
            let mutex = LOCK.get().unwrap();
            let held = mutex.try_lock().is_err();
            println!("PARENT mutex held: {}", held);
        }
    }
    Ok(())
}

There's a background thread bg_thread which acquires the global lock for 50ms and then releases, in a loop. Then we fork a child process with the same pattern as above...acquiring the lock, forking, releasing the lock. But for some reason it consistently deadlocks for me. I think we are missing something. Strangely, if you uncomment the printlns in bg_thread, it won't deadlock.

from fern.

amoffat avatar amoffat commented on July 17, 2024

Hmm it seems like the bg_thread loop is spinning too fast. Putting a sleep underneath the drop allows things to work as expected. Wtf though...how can the main thread, which is waiting on a lock, never wake up? The above code may be a red-herring though. I am trying to reproduce the deadlocking behavior that I'm still seeing in my main app.

from fern.

amoffat avatar amoffat commented on July 17, 2024

I'm going to close this. I think the theory is right, I just have some app-specific weirdness going on. Thanks for your help @daboross

from fern.

amoffat avatar amoffat commented on July 17, 2024

Seems that it may be an issue with RwLock + fork. My snippet above was using a Mutex, and so it wasn't seeing the same results. https://stackoverflow.com/questions/61976745/why-does-rust-rwlock-behave-unexpectedly-with-fork

from fern.

daboross avatar daboross commented on July 17, 2024

Troubling. I guess fork can lead to even more UB than I thought!

If the problem is the with the platform RwLock APIs, what about using a userspace lock implementation? The main one I know of is parking_lot. Even though there were some quality concerns raised in a review of it by rustc maintainers, and it doesn't hold up to std's quality standards, I think it's still seen as a pretty good lock implementation.

I guess I might imagine an alternative which does stuff using lower-level APIs, but I don't know exactly what it'd look like. Maybe we could add an additional AtomicBool "lock enabled" that the logger spins on waiting for true, and we only set to false while forking? Then we could lock the mutex once to ensure no one holds it, and no one grabs it during the fork. I can't think of a foolproof ordering of operations, though, so maybe this isn't viable.

from fern.

Related Issues (20)

Recommend Projects

  • React photo React

    A declarative, efficient, and flexible JavaScript library for building user interfaces.

  • Vue.js photo Vue.js

    🖖 Vue.js is a progressive, incrementally-adoptable JavaScript framework for building UI on the web.

  • Typescript photo Typescript

    TypeScript is a superset of JavaScript that compiles to clean JavaScript output.

  • TensorFlow photo TensorFlow

    An Open Source Machine Learning Framework for Everyone

  • Django photo Django

    The Web framework for perfectionists with deadlines.

  • D3 photo D3

    Bring data to life with SVG, Canvas and HTML. 📊📈🎉

Recommend Topics

  • javascript

    JavaScript (JS) is a lightweight interpreted programming language with first-class functions.

  • web

    Some thing interesting about web. New door for the world.

  • server

    A server is a program made to process requests and deliver data to clients.

  • Machine learning

    Machine learning is a way of modeling and interpreting data that allows a piece of software to respond intelligently.

  • Game

    Some thing interesting about game, make everyone happy.

Recommend Org

  • Facebook photo Facebook

    We are working to build community through open source technology. NB: members must have two-factor auth.

  • Microsoft photo Microsoft

    Open source projects and samples from Microsoft.

  • Google photo Google

    Google ❤️ Open Source for everyone.

  • D3 photo D3

    Data-Driven Documents codes.