Already Borrowed Error Inside stdio.rs

help
1

This is the stack trace. Rustc is 1.75.0

thread 'NAME' panicked at library/std/src/io/stdio.rs:747:20:
already borrowed: BorrowMutError
stack backtrace:
   0: rust_begin_unwind
             at /rustc/82e1608dfa6e0b5569232559e3d385fea5a93112/library/std/src/panicking.rs:645:5
   1: core::panicking::panic_fmt
             at /rustc/82e1608dfa6e0b5569232559e3d385fea5a93112/library/core/src/panicking.rs:72:14
   2: core::cell::panic_already_borrowed
             at /rustc/82e1608dfa6e0b5569232559e3d385fea5a93112/library/core/src/cell.rs:762:5
   3: core::cell::RefCell<T>::borrow_mut
             at /rustc/82e1608dfa6e0b5569232559e3d385fea5a93112/library/core/src/cell.rs:1052:25
   4: <std::io::stdio::StdoutLock as std::io::Write>::write_all
             at /rustc/82e1608dfa6e0b5569232559e3d385fea5a93112/library/std/src/io/stdio.rs:747:20
   5: <std::io::Write::write_fmt::Adapter<T> as core::fmt::Write>::write_str
             at /rustc/82e1608dfa6e0b5569232559e3d385fea5a93112/library/std/src/io/mod.rs:1751:23
   6: <alloc::string::String as core::fmt::Display>::fmt
             at /rustc/82e1608dfa6e0b5569232559e3d385fea5a93112/library/alloc/src/string.rs:2350:9
   7: core::fmt::rt::Argument::fmt
             at /rustc/82e1608dfa6e0b5569232559e3d385fea5a93112/library/core/src/fmt/rt.rs:142:9
   8: core::fmt::write
             at /rustc/82e1608dfa6e0b5569232559e3d385fea5a93112/library/core/src/fmt/mod.rs:1120:17
   9: std::io::Write::write_fmt
             at /rustc/82e1608dfa6e0b5569232559e3d385fea5a93112/library/std/src/io/mod.rs:1762:15
  10: <&std::io::stdio::Stdout as std::io::Write>::write_fmt
             at /rustc/82e1608dfa6e0b5569232559e3d385fea5a93112/library/std/src/io/stdio.rs:727:9
  11: <std::io::stdio::Stdout as std::io::Write>::write_fmt
             at /rustc/82e1608dfa6e0b5569232559e3d385fea5a93112/library/std/src/io/stdio.rs:701:9
  12: std::io::stdio::print_to
             at /rustc/82e1608dfa6e0b5569232559e3d385fea5a93112/library/std/src/io/stdio.rs:1020:21
  13: std::io::stdio::_print
             at /rustc/82e1608dfa6e0b5569232559e3d385fea5a93112/library/std/src/io/stdio.rs:1097:5
  14: X::logging::LogData::new

The match inside new pointed to by is:

        match serde_json::to_string(&ld){
            Ok(l) => {
                ***println!("{l}");***
            },
            Err(e) =>{
                eprintln!("{e}");
            }
        }

This code has not changed in more than six months. Any thoughts if I need to change anything?

2

Here's that line.

fn write_all(&mut self, buf: &[u8]) -> io::Result<()> {
    self.inner.borrow_mut().write_all(buf)
}

And that self is this.

pub struct StdoutLock<'a> {
    inner: ReentrantMutexGuard<'a, RefCell<LineWriter<StdoutRaw>>>,
}

I'm guessing you are sending a StdoutLock handle across threads, which panics because it borrows the RefCell twice. It's also undefined behavior because it causes a data race in the RefCell.

Rust Playground

If you try running that many times, you'll see how inconsistent it is even when trying to cause it, which explains why it took so long to show up. And different OSes probably handle this differently.

If that's not it, then it means something went wrong with ReentrantMutexGuard. All the RefCell borrows in the stdio module are limited to their functions, so there's no way to borrow twice on the same thread.

1 Like
3

Hello! I use RefCell very specifically and just in one place during initialization. This happened way after their use. The threads are in place.

I make no explicit use of StdoutLock. The threads are spawned during initialization and are tied to a specific RefCell, there are several RC. These threads are to log some information in a struct that currently dumps to console.

Would putting the logging struct in a different thread solve this?

thanks!

4

What do you mean with "in place"?

What do you mean with "tied"?

Are you sharing them between threads?

If it solved this then it would be for the wrong reason. This is probably either a bug in the stdlib (which needs to be fixed there) or UB in your code.

It would also help seeing more of the code and the backtrace. Is this code being called in some particular situation (e.g. panic handler/thread-local destructor)? And which platform/OS is this?

1 Like
5

The error is indicating that it is specifically the RefCell inside StdoutLock that is panicking. It has nothing to do with any RefCells you create, nor can you gain access to the one inside StdoutLock yourself. You also don't need to explicitly use StdoutLock, most likely something you use is storing StdoutLock internally. Check for instances of unsafe in your code, and possibly in your dependencies, and in particular, look for unsafe impl Send.

This is not really an issue with threads. That's what causes the panic, but the actual bug is that someone has removed the !Send property of StdoutLock.

4 Likes
6

This sounds more like it.

There are certainly several instances of unsafe and send.

I will look into this scenario. Would placing the logging before any of these happen and modifying the logging struct to avoid calling stdio directly solve the problem?

7

There's no way for me to know what code changes will solve the problem. Just stop making StdoutLock implement Send. Then you can be sure that the code won't compile until the bug is gone.

8

That was my thinking.

Thanks!

9

Since the io is done in just the small logging struct, this is the only place that needs to be !Send. I placed a PhantomData + Cell there to make sure the struct is not send.

I increased the size of the tests, and things seem to be working. I will extend the testing to make sure problem is fixed.

10

Problem is, if it holds an StdoutLock, it would already not be Send, unless there's unsafe impl Send somewhere. And if it is, the problem is likely to return.

3 Likes
11

Correct. It will be removed. There is no way around other than moving the logging away from the current code path.

thanks

12

As a final note: the situation also seems to cause deadlocks more often the panics.

I removed all the print macros from the logging. Basically running muted. Running 25 million requests tests. So far smooth sailing,

Thanks!

13

FOR REFERENCE:

The real solution, as mentioned in the thread, was to move the calls to stdio before the send, sync, refcell, and unsafe code was even called.

14

This topic was automatically closed 90 days after the last reply. We invite you to open a new topic if you have further questions or comments.