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

logging macros and writeln!() crash if stderr is redirected to /dev/null #10626

Closed
dwrensha opened this issue Nov 24, 2013 · 4 comments · Fixed by #10635
Closed

logging macros and writeln!() crash if stderr is redirected to /dev/null #10626

dwrensha opened this issue Nov 24, 2013 · 4 comments · Fixed by #10635

Comments

@dwrensha
Copy link
Contributor

The following occurs for me on Mac OSX 10.9.

// child.rs
fn main() {
    for _ in range::<uint>(0, 1000) {
        error!("hello?");
    }
}
// parent.rs
fn main () {
    use std::io::process;

    let config = process::ProcessConfig {
        program : "./child",
        args : [],
        env : None,
        cwd : None,
        io : []
    };

    match process::Process::new(config) {
        Some(ref mut p) => println!("{}", p.wait()),
        None => println("failed to start child")
    }
}

When I run ./parent, I expect the output to be "exit code: 0". Instead, I see an error signal, and not always the same one:

$ ./parent
signal: 6
$ ./parent
signal: 4
$ ./parent
signal: 6
$ ./parent
signal: 6
$ ./parent
signal: 10
@dwrensha
Copy link
Contributor Author

I see the same behavior if instead I explicitly set the descriptors to Ignored:

...
        io : [process::Ignored, process::Ignored, process::Ignored]
...

@alexcrichton
Copy link
Member

What is the expected behavior? This appears to all be working as-intended to me. You have instructed the child to print something, but you have not provided a method of it to print anything, and it's aborting as a result.

It could be a bug that it's aborting incorrectly, but that seems separate from this issue.

@dwrensha
Copy link
Contributor Author

I expect the child to exit normally.

I discovered that I actually don't need the parent process in order to see the unexpected behavior.

$ ./child 2> /dev/null
Abort trap: 6

Here are some of gdb stack traces I see when the crash occurs:

program received signal EXC_BAD_ACCESS, Could not access memory.
Reason: KERN_INVALID_ADDRESS at address: 0x0000000000000080
[Switching to process 55750 thread 0x271f]
uv__stream_osx_select (arg=0x100d15bd0) at ../../../src/libuv/src/unix/stream.c:157
157   if (fd > s->int_fd)
(gdb) bt
#0  uv__stream_osx_select (arg=0x100d15bd0) at ../../../src/libuv/src/unix/stream.c:157
#1  0x0000000100699b49 in uv__thread_start (arg=<value temporarily unavailable, due to optimizations>) at ../../../src/libuv/src/uv-common.c:274
#2  0x00007fff8fdf9772 in _pthread_start ()
#3  0x00007fff8fde61a1 in thread_start ()
Program received signal SIGABRT, Aborted.
[Switching to process 55754 thread 0x1203]
0x00007fff85b97212 in __pthread_kill ()
(gdb) bt
#0  0x00007fff85b97212 in __pthread_kill ()
#1  0x00007fff8fdfab24 in pthread_kill ()
#2  0x00007fff8fe3ef61 in abort ()
#3  0x0000000100007835 in rt::util::abort::h78af1956eb5e49das::v0.9$x2dpre ()
#4  0x00000001006472b3 in rt::task::begin_unwind::hd550344a74825a7av::v0.9$x2dpre ()
#5  0x0000000100683915 in uvio::HomingIO::fire_homing_missile::h275a15cd89566c45a7::v0.9$x2dpre ()
#6  0x0000000100671181 in file::Drop$FileWatcher::drop::h243d5422d728745Mgap::v0.9$x2dpre ()
#7  0x00000001006710cd in file..FileWatcher::glue_drop::hb83953d6ca359e89ao ()
#8  0x000000010067106d in _$UP$file..FileWatcher::glue_free::hb4f5f58975dc6e74ak ()
#9  0x0000000100039ffb in logging::log::hd2877e3741c67e5aw::v0.9$x2dpre ()
#10 0x0000000100001d03 in main::anon::expr_fn::ap ()
#11 0x00000001000018c7 in main::hada226789343cd84ah::v0.0 ()
#12 0x00000001000d7755 in rt::task::__extensions__::build_start_wrapper::anon::anon::expr_fn::aw ()
#13 0x00000001000d6333 in rt::task::__extensions__::run::anon::expr_fn::a1 ()
#14 0x00000001007402e3 in rust_try (f=<value temporarily unavailable, due to optimizations>, fptr=<value temporarily unavailable, due to optimizations>, env=<value temporarily unavailable, due to optimizations>) at /Users/davidrenshaw/Code/rust/src/rt/rust_cxx_glue.cpp:20
#15 0x00000001000d6243 in rt::task::Unwinder::try::hdc872d3e23884703Sa0::v0.9$x2dpre ()
#16 0x00000001000d4e05 in rt::task::Task::run::he4b13dcb792462759TaY::v0.9$x2dpre ()
#17 0x00000001000d6eda in rt::task::__extensions__::build_start_wrapper::anon::expr_fn::ab ()

Also, the following program shows the same behavior.

// child.rs
fn main() {
    for _ in range::<uint>(0, 1000) {
        writeln!(&mut std::io::stderr() as &mut std::io::Writer, "hello?");
    }
}

@dwrensha
Copy link
Contributor Author

For comparison, the following program behaves as I think the other versions of "child.rs" ought to.

// child.rs
// exits normally
fn main() {
    let mut w = std::io::stderr();
    for _ in range::<uint>(0, 1000) {
        w.write("hello?\n".as_bytes());
    }
}

However, it reverts back to the bad behavior if I change it to:

// child.rs
// crashes
fn main() {
    for _ in range::<uint>(0, 1000) {
        std::io::stderr().write("hello?\n".as_bytes());
    }
}

bors added a commit that referenced this issue Nov 25, 2013
This is both useful for performance (otherwise logging is unbuffered), but also
useful for correctness. Because when a task is destroyed we can't block the task
waiting for the logger to close, loggers are opened with a 'CloseAsynchronously'
specification. This causes libuv do defer the call to close() until the next
turn of the event loop.

If you spin in a tight loop around printing, you never yield control back to the
libuv event loop, meaning that you simply enqueue a large number of close
requests but nothing is actually closed. This queue ends up never getting
closed, meaning that if you keep trying to create handles one will eventually
fail, which the runtime will attempt to print the failure, causing mass
destruction.

Caching will provide better performance as well as prevent creation of too many
handles.

Closes #10626
flip1995 pushed a commit to flip1995/rust that referenced this issue Sep 7, 2023
Clippy Book Chapter Updates Reborn: Trait Checking

This PR adds a new chapter to the book: "Trait Checking". No major changes from the source (just some typos, re-phrasing, the usual).

## Notes

- Does not require any other PR to be merged.
- To talk about the whole project, please use the tracking issue for the project rust-lang#10597 (It also contains a timeline, discussions and more information)

changelog: Add a new "Trait Checking" chapter to the book
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 a pull request may close this issue.

2 participants