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

Relax atomic orderings #520

Closed
wants to merge 4 commits into from
Closed

Relax atomic orderings #520

wants to merge 4 commits into from

Conversation

Cassy343
Copy link

Currently this crate uses SeqCst orderings for all atomic operations related to logger initialization. At most these orderings would need to be AcqRel since they only involve a single atomic. This PR relaxes all orderings as much as possible without introducing visibility issues.

I also changed the initialization of the filter to be LevelFilter::Off as usize for clarity.

@Cassy343
Copy link
Author

Closes #509

In talking with some other developers some concern was presented over whether or not a write to LOGGER could be re-ordered before a relaxed atomic load despite that write being conditional. This commit defensively changes the ordering to Acquire to ensure this does not happen, but if it is guaranteed that such a reordering could not occur with Relaxed then that commit can be reverted.

@Thomasdezeeuw
Copy link
Collaborator

I'm not sure that this new ordering is valid, but does it really matter? The logger is set at most once, usually during startup, personally I don't think the performance concerns at that stage outweigh getting this wrong...

@Cassy343
Copy link
Author

Cassy343 commented Jun 13, 2022

The initialization of the logger wasn't really of concern here, the SeqCst load in the logger function was. I did a couple benches and didn't see a significant change in performance.

A couple remarks on that: this doesn't change a whole lot. Using SeqCst everywhere is analogous to using a RwLock for a single thread instead of a RefCell. Will it have a noticeable impact on performance? Probably not, but it's wholly unnecessary. Again, since this is a single atomic variable, you could change every SeqCst ordering to AcqRel/Acquire/Release and it would be exactly equivalent. SeqCst only causes logically different behavior when it synchronizes with atomic operations on different memory locations or SeqCst fences.

If the primary concern here is correctness over performance, then I'd personally suggest not using a home-brew Once. For instance the unbounded spinning in set_logger_inner is almost certainly the wrong choice. OnceCell and other crates provide #![no_std] battle-tested implementations of this pattern with minimal but sufficient orderings, as well as better unsafe hygiene that doesn't involve static mut.

If you want to close this that's fine. My two cents is that in its current state the once implementation here is non-optimal (and this PR doesn't fix the aforementioned unbounded spin loop), and that if you want correctness then a better solution would be to rely on a 3rd party once crate with more thorough auditing than to simply make all orderings SeqCst.

EDIT: I forgot to mention, if the correctness of this implementation was of primary concern, then I could add loom tests which would give pretty substantial reassurance that the orderings are correct.

@Thomasdezeeuw
Copy link
Collaborator

@Cassy343 I'm familiar with atomic ordering, that wasn't my point. My point was that the ordering is tricky to get right (even if you following docs precisely) and that I don't think it's worth it for the setup phase of a program.

So, I propose to reduce this pr to just change the atomic ordering of the logger function as that's really the only one where performance matters.

Regarding the ordering logger I think we can lower it all the way to Relaxed, iff we properly document it. I imagine (but have no data to backup this statement) that most multi-threaded applications will setup logging before starting threads. Given that, changing logger to Relaxed shouldn't be an issue. One exception might be testing, where the creation of the test threads isn't handled by the developer (assuming the default testing harness). But again make a reasonable assuming that all tests that need logging will attempt to set it up, thus calling something that loads using SeqCst again, I don't think this will be an issue.

@Cassy343
Copy link
Author

That ordering should not be reduced to relaxed. Even if we properly document it, if one thread initializes the logger and another concurrently tries to access the logger, then that's undefined behavior which is not allowed to occur in safe code, so that function would need to be marked as unsafe.

I'd also wager that a non-trivial number of users are initializing the logger after spinning up threads due to libraries such as tokio and rocket providing macros that wrap your main and spin up a thread pool before executing your code. An acquire load is the minimally sufficient ordering to make that function safe provided that, after LOGGER is written to, STATE is set to INITIALIZED with release ordering or stronger.

@Thomasdezeeuw
Copy link
Collaborator

That ordering should not be reduced to relaxed. Even if we properly document it, if one thread initializes the logger and another concurrently tries to access the logger, then that's undefined behavior which is not allowed to occur in safe code, so that function would need to be marked as unsafe.

How do you think this is possible?

I'd also wager that a non-trivial number of users are initializing the logger after spinning up threads due to libraries such as tokio and rocket providing macros that wrap your main and spin up a thread pool before executing your code. An acquire load is the minimally sufficient ordering to make that function safe provided that, after LOGGER is written to, STATE is set to INITIALIZED with release ordering or stronger.

I disagree. I think if you put a atomic::fence(SeqCst) at the bottom of set_logger and use STATE.load(Relaxed) == INITIALIZED it not possible for a thread to read state == INITIALIZED with the logger not set.

@chorman0773
Copy link

I disagree. I think if you put a atomic::fence(SeqCst) at the bottom of set_logger and use STATE.load(Relaxed) == INITIALIZED it not possible for a thread to read state == INITIALIZED with the logger not set.

That is not what fence(SeqCst) does. With all accesses being Relaxed, there is no acquire operation for the release part of the fence to attach to. If there was, fence(Acquire) would be sufficient, but there isn't so there isn't a correct option.
I agree with @Cassy343's PR, and assesment that going to relaxed introduces undefined behaviour in various cases of safe use of the function.

@Cassy343
Copy link
Author

To add on to @chorman0773's point, here is a (correctly failing) loom test demonstrating that Relaxed ordering causes UB:

fn main() {
    use loom::{sync::atomic::{AtomicUsize, Ordering, fence}, cell::UnsafeCell, thread};
    use std::sync::Arc;

    loom::model(|| {
        let number = Arc::new(UnsafeCell::new(0i32));
        let state = Arc::new(AtomicUsize::new(0));

        thread::spawn({
            let number = Arc::clone(&number);
            let state = Arc::clone(&state);

            move || {
                if state.load(Ordering::Relaxed) == 2 {
                    number.with(|ptr| assert_eq!(unsafe { *ptr }, 1));
                }
            }
        });

        thread::spawn(move || {
            match state.compare_exchange(0, 1, Ordering::SeqCst, Ordering::SeqCst) {
                Ok(0) => {
                    number.with_mut(|ptr| unsafe { *ptr = 1 });
                    state.store(2, Ordering::SeqCst);
                },
                _ => unreachable!()
            }

            fence(Ordering::SeqCst);
        });
    });
}

@Thomasdezeeuw
Copy link
Collaborator

@Cassy343 I don't use Loom, but that's not exactly what I had in my. I was thinking the following.

fn main() {
    use loom::{sync::atomic::{AtomicUsize, Ordering, fence}, cell::UnsafeCell, thread};
    use std::sync::Arc;

    loom::model(|| {
        let number = Arc::new(UnsafeCell::new(0i32));
        let state = Arc::new(AtomicUsize::new(0));

        thread::spawn({
            let number = Arc::clone(&number);
            let state = Arc::clone(&state);

            move || {
                if state.load(Ordering::Relaxed) == 2 {
                    number.with(|ptr| assert_eq!(unsafe { *ptr }, 1));
                }
            }
        });

        thread::spawn(move || {
            match state.compare_exchange(0, 1, Ordering::SeqCst, Ordering::SeqCst) {
                Ok(0) => {
                    number.with_mut(|ptr| unsafe { *ptr = 1 });
                    fence(Ordering::SeqCst);  // Sync the write above.
                    state.store(2, Ordering::SeqCst);
                },
                _ => unreachable!()
            }
        });
    });
}

@Thomasdezeeuw
Copy link
Collaborator

But I think you guys are right and we still need something this proposed fence can sync with on the reading side (the log calls).

@relufi
Copy link

relufi commented Aug 4, 2022

I'm not sure that this new ordering is valid, but does it really matter? The logger is set at most once, usually during startup, personally I don't think the performance concerns at that stage outweigh getting this wrong...

The impact is not limited to the startup phase, incurring unnecessary overhead every time the log!() is used, and SeqCst is a very expensive operation on some platforms.

pub fn logger() -> &'static dyn Log {
    if STATE.load(Ordering::SeqCst) != INITIALIZED {

@KodrAus
Copy link
Contributor

KodrAus commented Aug 31, 2022

Thanks for the PR @Cassy343! I think one of your earlier points about not using a home-grown once cell for this is pretty valid, and once OnceLock stabilizes we should move to it. In the meantime, synchronizing on the global logger is almost the only thing this library actually does, so it seems fair that we should try do a good job of it. Maybe we could move this synchronization code into its own sub-module and add a loom test for it?

@NobodyXu
Copy link

OnceLock is stablised in 1.70 and the msrv for this crate is 1.60, so it looks like this would take another debian release to happen.

@NobodyXu
Copy link

@KodrAus Maybe it's a good idea to use once_cell as a dep?

@KodrAus
Copy link
Contributor

KodrAus commented Jun 11, 2023

@NobodyXu Ah we don’t actually tie our MSRV to what’s in Debian. We just lined them up this time because there happened to be a release coming up, but I don’t expect us to stay tied to 1.60 for the next few years.

We avoid adding any required dependencies to log so I think can’t pull in once_cell. Once some time has passed we’ll move to 1.70 and be able to use OnceLock.

@NobodyXu
Copy link

@NobodyXu Ah we don’t actually tie our MSRV to what’s in Debian. We just lined them up this time because there happened to be a release coming up, but I don’t expect us to stay tied to 1.60 for the next few years.

Wouldn't that break users who compile their programs on debian stable or make it harder for debian to package rust programs that depends on log?

We avoid adding any required dependencies to log so I think can’t pull in once_cell. Once some time has passed we’ll move to 1.70 and be able to use OnceLock.

If you don't want to tie log msrv bump to debian release, then I suppose it will be safe to do it in 6-9 months of time?

EFanZh pushed a commit to EFanZh/log that referenced this pull request Jul 23, 2023
…lang#520)

to convert all tracing spans and events to log.

Signed-off-by: Jiahao XU <[email protected]>
@Thomasdezeeuw
Copy link
Collaborator

We avoid adding any required dependencies to log so I think can’t pull in once_cell. Once some time has passed we’ll move to 1.70 and be able to use OnceLock.

Problem is the OnceLock isn't available without std lib, otherwise we could have used std::sync::Once.

@Thomasdezeeuw
Copy link
Collaborator

In #610 we switched to using Acquire for the logger function (i.e. one called for every log message).

We could still accept the changes here to relax the orderings in the setup functions (set_logger etc.). rust-lang/rust#122729 I think set a pretty clear presented recently.

@KodrAus
Copy link
Contributor

KodrAus commented Jun 25, 2024

Well, that's what I get for trying to use GitHub's UI to merge branches.

@KodrAus
Copy link
Contributor

KodrAus commented Jun 25, 2024

I've re-opened this as #632 so will close this PR. The discussion is all linked so we can find our way back to it in the future if needed.

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

Successfully merging this pull request may close these issues.

6 participants