Segmentation Fault when checking for update

[Spaceface16518]

🐛 Bug description

Nothing actually bad happens, but when I try to run wasm-pack --help, the help message is printed, followed by Segmentation fault (core dumped).

$ wasm-pack help
wasm-pack 0.9.1
Ashley Williams <ashley666ashley@gmail.com>
📦 ✨  pack and publish your wasm!

USAGE:
    wasm-pack [FLAGS] [OPTIONS] <SUBCOMMAND>

FLAGS:
    -h, --help       Prints help information
    -q, --quiet      No output printed to stdout
    -V, --version    Prints version information
    -v, --verbose    Log verbosity is based off the number of v used

OPTIONS:
        --log-level <log_level>    The maximum level of messages that should be logged by wasm-pack. [possible values:
                                   info, warn, error] [default: info]

SUBCOMMANDS:
    build      🏗️  build your npm package!
    help       Prints this message or the help of the given subcommand(s)
    login      👤  Add an npm registry user account! (aliases: adduser, add-user)
    new        🐑 create a new project with a template
    pack       🍱  create a tar of your npm package but don't publish!
    publish    🎆  pack up your npm package and publish!
    test       👩‍🔬  test your wasm!
Segmentation fault (core dumped)

🤔 Expected Behavior

Help message should print, and program should exit.

👟 Steps to reproduce

I'm going to try to reproduce it by building it from source and running with valgrind. I will update this section once I have that information.

I'm not doing anything special besides running wasm-pack help or wasm-pack --help. The segfault is not deterministic, but it seems like it happens more often than not (might be confirmation bias though). I will try to get stats on this.

UPDATE: posted below

🌍 Your environment

Include the relevant details of your environment.
wasm-pack version: wasm-pack 0.9.1
rustc version: rustc 1.51.0 (2fd73fabe 2021-03-23)

[Spaceface16518]

Steps to Reproduce

$ git clone https://github.com/Spaceface16518/wasm-pack.git
Cloning into 'wasm-pack'...
remote: Enumerating objects: 5449, done.
remote: Counting objects: 100% (13/13), done.
remote: Compressing objects: 100% (12/12), done.
remote: Total 5449 (delta 3), reused 4 (delta 1), pack-reused 5436
Receiving objects: 100% (5449/5449), 3.39 MiB | 1.71 MiB/s, done.
Resolving deltas: 100% (3358/3358), done.
$ cd wasm-pack
$ cargo run --release --quiet -- help
<output elided>
Segmentation fault (core dumped)

There is a chance that the segfault won't be triggered on the first run. Use a loop to called it repeatedly. You can also silence stdout to wait for the segfault.

<previous steps elided>
$ cd wasm-pack
$ (exit 0) && while [ $? -eq 0 ]; do cargo run --release --quiet -- help > /dev/null; done
Segmentation fault (core dumped)

[Spaceface16518]

Confirmed to not just be a quirk of my computer?

$ docker run -v $PWD:/app/ -t rust bash -c "while [ \$? -eq 0 ]; do cargo run --release --quiet --manifest-path /app/Cargo.toml -- help > /dev/null; done"
bash: line 1:  1977 Segmentation fault      (core dumped) cargo run --release --manifest-path /app/Cargo.toml -- help > /dev/null

[Spaceface16518]

I could not make valgrind pick up the segfault so I used the core dump + gdb post-mortem strategy and came up with this backtrace.

#29 0x0000556385f15124 in wasm_pack::manifest::Crate::check_wasm_pack_latest_version () at /<REDACTED>/wasm-pack/src/manifest/mod.rs:245
#30 0x0000556385f14fbd in wasm_pack::manifest::Crate::return_latest_wasm_pack_version () at /<REDACTED>/wasm-pack/src/manifest/mod.rs:228
#31 0x0000556385f141f7 in wasm_pack::manifest::Crate::return_api_call_result (current_time=...) at /<REDACTED>/wasm-pack/src/manifest/mod.rs:178
#32 0x0000556385f14081 in wasm_pack::manifest::Crate::return_wasm_pack_latest_version () at /<REDACTED>/wasm-pack/src/manifest/mod.rs:171
#33 0x0000556385edf30c in wasm_pack::build::check_wasm_pack_versions () at /<REDACTED>/wasm-pack/src/build/mod.rs:65
#34 0x0000556385e75d0f in wasm_pack::background_check_for_updates::{{closure}} () at /<REDACTED>/wasm-pack/src/main.rs:30

This is only one thread, the full thread backtrace is much longer.

[Spaceface16518]

That narrows it down the the call to curl from src/manifest/mod.rs, which means this is likely a C issue, not a rust issue.

wasm-pack/src/manifest/mod.rs

Lines 242 to 261 in d46d1c6

	fn check_wasm_pack_latest_version() -> Result<Crate, Error> {
	let url = "https://crates.io/api/v1/crates/wasm-pack";
	let mut easy = easy::Easy2::new(Collector(Vec::new()));
	easy.useragent(&format!(
	"wasm-pack/{} ({})",
	WASM_PACK_VERSION.unwrap_or_else(|| "unknown"),
	WASM_PACK_REPO_URL
	))?;
	easy.url(url)?;
	easy.get(true)?;
	easy.perform()?;
	let status_code = easy.response_code()?;
	if 200 <= status_code && status_code < 300 {
	let contents = easy.get_ref();
	let result = String::from_utf8_lossy(&contents.0);

[Spaceface16518]

This could be related to curl/curl#6898 since the segfault happens after the help message is printed (and presumably after the request happens) as curl is being cleaned up.

[bagder]

Is this really doing SFTP over an HTTPS proxy with curl? If not, then it's not that issue.

[Spaceface16518]

Yeah when I actually read the issue in detail it seems less likely to be to same problem. It was just the first issue that mentioned a segmentation fault and it had been posted recently, so I linked it—an imprudent decision, obviously 😅.

[Spaceface16518]

The last entry in the backtrace leads to the construction of an Easy2.

wasm-pack/src/manifest/mod.rs

Line 245 in d46d1c6

let mut easy = easy::Easy2::new(Collector(Vec::new()));

I made another backtrace to investigate further (gave up on redaction lol. No use anyway.)

#0  0x00007fba60d8cb1e in pthread_rwlock_unlock () from /usr/lib/libpthread.so.0
#1  0x00007fba612124fa in CRYPTO_THREAD_unlock () from /usr/lib/libcrypto.so.1.1
#2  0x00007fba611a606c in OPENSSL_init_crypto () from /usr/lib/libcrypto.so.1.1
#3  0x00007fba6133b242 in OPENSSL_init_ssl () from /usr/lib/libssl.so.1.1
#4  0x00007fba60ff8731 in ?? () from /usr/lib/libcurl.so.4
#5  0x00007fba60fab735 in ?? () from /usr/lib/libcurl.so.4
#6  0x000056449408bb37 in curl::init::{{closure}} ()
    at /home/amrit/.cargo/registry/src/github.com-1ecc6299db9ec823/curl-0.4.25/src/lib.rs:88
#7  0x000056449408f6dc in std::sync::once::{{impl}}::call_once::{{closure}}<closure-0> ()
    at /home/amrit/.rustup/toolchains/stable-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/std/src/sync/once.rs:261
#8  0x000056449457ed92 in std::sync::once::Once::call_inner ()
    at /rustc/2fd73fabe469357a12c2c974c140f67e7cdd76d0//library/std/src/sync/once.rs:418
#9  0x000056449408f65f in std::sync::once::Once::call_once<closure-0> (
    self=0x564494a02e60 <curl::init::INIT>, f=...)
    at /home/amrit/.rustup/toolchains/stable-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/std/src/sync/once.rs:261
#10 0x000056449408bb11 in curl::init ()
    at /home/amrit/.cargo/registry/src/github.com-1ecc6299db9ec823/curl-0.4.25/src/lib.rs:85
#11 0x0000564493a4e185 in curl::easy::handler::Easy2<wasm_pack::manifest::Collector>::new<wasm_pack::manifest::Collector> (handler=...)
    at /home/amrit/.cargo/registry/src/github.com-1ecc6299db9ec823/curl-0.4.25/src/easy/handler.rs:608

After that, it continued down the same path from my other comment.

Continuing up the backtrace lead me into the rust-curl library, then curl_global_init in curl-sys and finally at the global_init function in libcurl in lib/easy.c. I figured this because of some characteristics of the backtrace. While I couldn't load the symbols for libcurl, the functions seem to be in the same general location (at least compared to the other locations). This reflects the relationship of the functions in easy.c—right next to each other and one wrapping the other.

static CURLcode global_init(long flags, bool memoryfuncs)
{
  // body elided
}


// doc comment elided
CURLcode curl_global_init(long flags)
{
  return global_init(flags, TRUE);
}

Reading the body of global_init and going further up the trace is the challenge for tomorrow. I still don't think it's on the Rust side, since there are null checks in the appropriate locations.

I'm wary of linking issues after the last time, but I found curl/curl#3990 which mentioned the non-thread-safe nature of curl_global_init.
This doesn't mean anything on its own, even if curl_global_init is called in a thread specifically for the purpose of calling that function, but it could be a point for further research. However, as the backtrace suggests, the segfault is likely happening further down the chain.

[Spaceface16518]

Going further up the trace leads us to OPENSSL_init_ssl(). A similar function exists in libcurl, by the name of Curl_init_ssl(), which is called by global_init. The missing link is in the documentation. Basically, Curl_init_ssl() calls the function Curl_ssl->init() on the global Curl_ssl instance, which must be provided by a certain backend. Looking at the trace, that seems to be openssl. This can be found in curl's lib/vtls/openssl.c:4477.

const struct Curl_ssl Curl_ssl_openssl = {
   { CURLSSLBACKEND_OPENSSL, "openssl" },

The function we were looking for, OPENSSL_init_ssl() is called in this file too, so it must originate from one of the headers at the top of this file. Wild guess, it's probably openssl/ssl.h.

Cloning openssl, I found that ssl.h is a generated file, but is basically a combination of a bunch of files. OPENSSL_init_ssl is defined in ssl/ssl_init.c at line 103. This function calls the next one in the trace, OPENSSL_init_crypto, at line 127. Searching for this function finally lead me to crypto/init.c:466, where OPENSSL_init_crypto() does a whole mess of multithreaded stuff. It doesn't contain any direct calls to pthread_rwlock_unlock(), but it has a lot of macros/functions like CRYPTO_THREAD_unlock which could contain that call, so that's probably where I'll go digging. I'm basically going to try and find an invariant that the code needs to not segfault, and then go back up the chain trying to find where this invariant might have been violated.

[Spaceface16518]

On a separate note, I see absolutely no reason for this tool to use curl at all. Considering this is the only use of curl in the codebase (excluding tests), I find it much simpler to use a pure-rust library for lower overhead and more safety. For example, using ureq

fn check_wasm_pack_latest_version() -> Result<Crate, Error> {
    let url = "https://crates.io/api/v1/crates/wasm-pack";

    let agent = ureq::builder()
        .user_agent(&format!(
            "wasm-pack/{} ({})",
            WASM_PACK_VERSION.unwrap_or("unknown"),
            WASM_PACK_REPO_URL
        ))
        .build();

    let res = agent.get(url).call().map_err(|err| match err {
        Status(status_code, _response) => format_err!(
            "Received a bad HTTP status code ({}) when checking for newer wasm-pack version at: {}",
            status_code,
            url
        ),
        Transport(transport) => transport.into(),
    })?;
    Ok(res.into_json()?)
}

The resulting code, although not as pretty as I could have made it, is simpler and more idiomatic (especially the error handling). If I were to not try to adhere to the previous behavior, the whole mess at the end could be removed, and it starts looking way more like rust code.

fn check_wasm_pack_latest_version() -> Result<Crate, Error> {
    let url = "https://crates.io/api/v1/crates/wasm-pack";

    let agent = ureq::builder()
        .user_agent(&format!(
            "wasm-pack/{} ({})",
            WASM_PACK_VERSION.unwrap_or("unknown"),
            WASM_PACK_REPO_URL
        ))
        .build();

    Ok(agent.get(url).call()?.into_json()?)
}

Most importantly this code does not exhibit the segfault caused by the libcurl version.

$ (exit 0) && while [ $? = 0]; do cargo run --quiet -- help > /dev/null; done
<loops forever>

I've made these changes in Spaceface16518@4b7411c, if you want me to open a PR.

[sassman]

I recently encountered this very same issue on the docker image rust:1.56.1-buster
For me installing libssl-dev and skipping wasm-pack default features solved the problem:

apt-get install libssl-dev
cargo install wasm-pack --no-default-features