println! sometimes panics in drop methods

Opened by sorear at 2020-07-03 13:43:40

If you try to println!-debug a drop method in a type which is being used in TLS, you can have problems because the TLS variable which holds the local stdout might already have been destroyed, turning your innocent print into a panic with "cannot access a TLS value during or after it is destroyed". This seems unnecessarily user-hostile.

(I solved the bug in my code, but I'm kinda curious what the recommended way to trace a drop method is. rt::util::dumb_print?)

The issue here is that we initialise TLS variables lazily (AFAIR), but they still get dropped in order (of initialisation). If you happen to initialise your droppable type before whatever println! stores in the TLS, you will encounter this error.

A simple solution would be to somehow ensure that types which depend on TLS in their Drop get initialised latest… Sadly we do not have any means to figure out such dependencies.
Simonas Kazlauskas at 2015-10-31 15:56:53
Sounds bad! I think we just need to add a check to see if TLS is already destroyed: https://github.com/rust-lang/rust/pull/29491
Alex Crichton at 2015-10-31 16:43:34
@nagisa I am afraid that we do not have any kind of guarantee about the order in which TLS variables are destroyed.

@alexcrichton We might also want to sanitise std to ensure that this issue does not affect other code. This has already been done for stderr and thread_info and it is now being done to stdout. AFAICT thread_local! is also used in src/libstd/rand/mod.rs; I guess it is not very likely to call it directly from a Drop implementation, but it could still happen if some (complex) data structures were using while dropping.
Andrea Canciani at 2015-11-01 23:11:50
That's a good point about an audit! We probably don't need to worry much about rand as it's not an exported interface of the standard library, however, but probably good to fixup nonetheless!
Alex Crichton at 2015-11-02 16:17:19
If I improve the test case by adding: FOO.with(|_| {}); as the first line in main(), I get:
```
thread 'main' panicked at 'cannot access stdout during shutdown', src/libcore/option.rs:874:4
note: Run with `RUST_BACKTRACE=1` for a backtrace.
fatal runtime error: failed to initiate panic, error 5
```
(rustc 1.23.0)

It's the same if I add another FOO2 : Foo TLS and access it from main in the same way.

My question is, shouldn't stdout handling in TLS be symmetrical with regard to the main thread compared to threads created during runtime? @alexcrichton
Dan Aloni at 2018-02-02 19:06:30

There is another case when applications panic while using drop/TLS/println:

struct Foo {}

impl Drop for Foo {
    fn drop(&mut self) {
        println!("drop begin");
    }
}


thread_local! {
    static FOO: Foo = Foo{};
}


fn main() {
    println!("main begin");
    FOO.with(|_| {});
}

This code output is:

main begin
thread '<unnamed>' panicked at 'cannot access stdout during shutdown', libcore\option.rs:916:5

My point of view is it also must be fixed in Rust language.

rustc 1.26.0-nightly (adf2135ad 2018-03-17)

mw at 2018-03-18 19:09:58

Seems like this is happening again?
Pietro Albini at 2018-03-20 22:47:37
My question is, shouldn't stdout handling in TLS be symmetrical with regard to the main thread compared to threads created during runtime?

We don't control the TLS implementation unfortunately.
Steven Fackler at 2018-03-21 09:30:39
Bug is critical as rust is panic. I think the I-ICE label must be added. But I have no privilegies for this. Can someone add I-ICE, A-thread-locals and A-destructors please?
mw at 2018-03-25 19:05:37
Thanks. It seems this issue is related to another old one.
mw at 2018-03-25 20:45:55
Assigning P-medium, would be great to fix but not super-high-priority
Alex Crichton at 2018-04-19 22:57:35
@alexcrichton I think it is quite high priority. I want to use private TLS-variables in a library. How can I gracefuly drop this variables? I don't know another method than using a Drop trait.

Due to this bug I see no way to create libraries with TLS-variables that needs a destructor. Tell me please if you know a method.
mw at 2018-04-22 16:27:08
Why do you need to print in the destructor of your type?
Steven Fackler at 2018-04-22 16:29:28
Due to debugging and logging needs.
mw at 2018-04-22 16:31:56
I think a fact that drop trait is not working is not a println! issue. Without println! TLS-drop don't work as expected too.

Windows7x64
mw at 2018-04-22 16:37:18

Let's see an example without println! TLS-drop function try to use c++ external function lib_fun() that simply writes to stdout. Expected that this app must write

from C++: 77
from C++: 23

But it write only:

from C++: 77

main.rs:

use std::os::raw::c_int;

#[link(name = "Project1", kind="static")]
extern {
    pub fn lib_fun(i: c_int) -> c_int;
}

struct Foo {}

impl Drop for Foo {
    fn drop(&mut self) {
        unsafe {
            lib_fun(23);
        }
    }
}

thread_local! {
    static FOO: Foo = Foo {};
}

fn main() {
    FOO.with(|_| {
        unsafe { lib_fun(77); }
    });
}

Project1.cpp:

#include <stdio.h>

extern "C" {
	int lib_fun(int t) {
		printf("from C++: %d\r\n", t);
		fflush(stdout);
		return t;
	}
}

mw at 2018-04-22 16:52:14

Some platforms do not run TLS destructors on the main thread. We have no control over that behavior.
Steven Fackler at 2018-04-22 17:07:54
In my C++ project on this platform I freely used TLS variables destructors in main thread without errors. I assume Rust must doing this well too.
mw at 2018-04-22 17:26:05
@DustinByfuglien that is #28129, not this issue.
Steven Fackler at 2018-04-22 19:10:48
Yes it seems that issue can be related with this, as I marked before https://github.com/rust-lang/rust/issues/29488#issuecomment-376002009
mw at 2018-04-22 19:17:54
No, they are totally separate issues. This issue is "something bad happens when TLS destructors run", and the other issue is "TLS destructors don't run on the main thread". The only thing that's similar between them is that they both involve TLS.
Steven Fackler at 2018-04-22 19:20:04
Both issues are platform-depending. I will not wonder if this issues may have a one internal cause. But even if this issues have different causes than there is prefferable for me to see that both are solved in near future. Without they are fixed I don'tknow how to write Rust apps with TLS on my platform.
mw at 2018-04-22 19:32:40
Why do you need to print in the destructor of your type?

I have a peculiar use case here in that the test framework (cargo test) will only capture the output from the primary test thread, so we're gathering the logs from the other threads and then emit them (via the println!s) in a Drop of a RAII variable living inside the test, in order to ensure that the logs are printed even if the test panics.

BTW, adding catch_unwind around the println! statement seems to work as a workaround.
Artem at 2019-06-30 04:51:13
BTW, adding catch_unwind around the println! statement seems to work as a workaround.

I tried this:
```
std::panic::catch_unwind(|| {
    println!("Something");
});
```
That doesn't work for me. I need to remove all println! in drop implementations if I want to remove these panics in my tests.
Jari Pennanen at 2020-07-03 13:43:25