Sig 11

[05nelsonm]

Compiling JNI bindings atop libtor-sys and I keep getting intermittent Tor 0.4.6.9 died: Caught signal 11 crashes. Not entirely sure if this is attributed to something with libtor-sys, or JVM side, but I feel like I'm losing my mind trying to debug this.

JVM Test simply starts Tor, then cycles a restart a couple times at 5s intervals. It sometimes fails immediately, sometimes makes it through start and then 1 restart cycle.

Any suggestions would be greatly appreciated.

lib.rs (work in progress, lol)

#![allow(non_snake_case)]

extern crate tor_sys;

use jni::JNIEnv;
use jni::objects::{JClass, JList, JString, JObject};
use std::ffi::CString;

#[no_mangle]
pub extern "system" fn Java_io_matthewnelson_kmp_tor_KmpTorLoaderJvm_runLines(
    env: JNIEnv,
    _class: JClass,
    // lines are a list of of strings to be run, already configured from kotlin side:
    // ex: [ "--ControlPortWriteToFile", "/path/to/file" ]
    lines: JObject // JList
) {
    let mut verify: Vec<String> = vec![
        String::from("tor"), String::from("--verify-config")
    ];

    let mut run: Vec<String> = vec![
        String::from("tor")
    ];

    let lines: JList = env.get_list(lines).expect("some exception").into();
    for i in 0..lines.size().unwrap() {
        let line = JString::from(lines.get(i.into()).unwrap().unwrap());
        verify.push(env.get_string(line.clone()).unwrap().into());
        run.push(env.get_string(line.clone()).unwrap().into());
    }

    let verify: Vec<_> = verify.into_iter().map(|s| CString::new(s).unwrap()).collect();
    let verify_ptr: Vec<_> = verify.iter().map(|s| s.as_ptr()).collect();

    let run: Vec<_> = run.into_iter().map(|s| CString::new(s).unwrap()).collect();
    let run_ptr: Vec<_> = run.iter().map(|s| s.as_ptr()).collect();

    unsafe {
        println!("==== RUST: acquiring config");
        let config = tor_sys::tor_main_configuration_new();

        println!("==== RUST: setting lines to verify");

        // set lines to be verified
        if tor_sys::tor_main_configuration_set_command_line(
            config,
            verify.len() as i32,
            verify_ptr.as_ptr()
        ) != 0 {
            println!("torMainConfigurationSetCommandLine returned non-0")
            // should throw err && release config
        }

        // run lines to verify
        println!("==== RUST: verifying lines");
        if tor_sys::tor_run_main(config) != 0 {
            println!("==== RUST: torRunMain returned non-0")
            // should throw err && release config
        }

        // set lines to be run
        println!("==== RUST: setting lines to run");
        if tor_sys::tor_main_configuration_set_command_line(
            config,
            run.len() as i32,
            run_ptr.as_ptr()
        ) != 0 {
            println!("==== RUST: torMainConfigurationSetCommandLine returned non-0")
            // should throw err && release config
        }

        println!("===== RUST: Starting Tor with args: {:#?}", run);

        // run lines
        // This is runBlocking on the current Thread (which is handled kotlin side)
        println!("==== RUST: running lines");
        if tor_sys::tor_run_main(config) != 0 {
            println!("==== RUST: torRunMain returned non-0")
            // should throw err && release config
        }

        // release config from mem
        println!("==== RUST: freeing config");
        tor_sys::tor_main_configuration_free(config);
    }
}

Cargo.toml

[package]
name = "kmp-tor-binary-build"
version = "0.1.0"

[dependencies]
jni = "0.19.0"
libtor-sys = { version = "46.9.0+0.4.6.9", features = ["vendored-openssl"] }

[lib]
name = "kmptor"
crate_type = [ "cdylib" ]
test = false
bench = false

Kotlin Multiplatform JVM Native Loader

actual class KmpTorLoaderJvm @JvmOverloads constructor(
    provider: TorConfigProviderJvm,
    loadLib: Boolean = false,
): KmpTorLoader(provider) {

    init {
        if (loadLib) {
            System.loadLibrary("kmptor")
        }
    }

    private external fun runLines(lines: List<String>)

    @Throws(TorManagerException::class, CancellationException::class)
    protected override suspend fun startTor(configLines: List<String>) {
        runLines(configLines)
    }
}

Jvm test output 1 (linuxx64, failure on first restart called)

io.matthewnelson.kmp.tor.KmpTorLoaderJvmUnitTest[jvm] STANDARD_OUT
    Lifecycle(class=RealTorManager@856837143, event=onCreate)
    State(torState=Tor: Starting, networkState=Network: Disabled)
    Action.Start
==== RUST: acquiring config
==== RUST: setting lines to verify
==== JAVA: ReentrantLock acquired
==== RUST: verifying lines
Jan 15 14:30:52.900 [notice] Tor 0.4.6.9 running on Linux with Libevent 2.1.12-stable, OpenSSL 1.1.1m, Zlib 1.2.11, Liblzma N/A, Libzstd N/A and Glibc 2.34 as libc.
Jan 15 14:30:52.900 [notice] Tor can't help you if you use it wrong! Learn how to be safe at https://www.torproject.org/download/download#warning
Jan 15 14:30:52.900 [notice] Read configuration file "/tmp/junit2447373153840319148/torservice/torrc-defaults".
Jan 15 14:30:52.900 [notice] Read configuration file "/tmp/junit2447373153840319148/torservice/torrc".
Jan 15 14:30:52.902 [warn] Fixing permissions on directory /tmp/junit2447373153840319148/cache
==== RUST: setting lines to run
==== RUST: Starting Tor with args: [
    "tor",
    "--RunAsDaemon",
    "0",
    "-f",
    "/tmp/junit2447373153840319148/torservice/torrc",
    "--defaults-torrc",
    "/tmp/junit2447373153840319148/torservice/torrc-defaults",
    "--ignore-missing-torrc",
    "--ControlPort",
    "9155",
    "--SocksPort",
    "auto",
    "--HTTPTunnelPort",
    "auto",
    "--DormantClientTimeout",
    "10 minutes",
    "--DormantCanceledByStartup",
    "0",
    "--DisableNetwork",
    "1",
    "--SyslogIdentityTag",
    "TorManager",
    "--CacheDirectory",
    "/tmp/junit2447373153840319148/cache",
    "--DataDirectory",
    "/tmp/junit2447373153840319148/torservice/data",
    "--ControlPortWriteToFile",
    "/tmp/junit2447373153840319148/torservice/control.txt",
    "--CookieAuthentication",
    "1",
    "--CookieAuthFile",
    "/tmp/junit2447373153840319148/torservice/control_auth_cookie",
    "--GeoIPFile",
    "/tmp/junit2447373153840319148/torservice/geoip",
    "--GeoIPv6File",
    "/tmp/junit2447373153840319148/torservice/geoip6",
]
==== RUST: running lines
Jan 15 14:30:52.905 [notice] Tor 0.4.6.9 running on Linux with Libevent 2.1.12-stable, OpenSSL 1.1.1m, Zlib 1.2.11, Liblzma N/A, Libzstd N/A and Glibc 2.34 as libc.
Jan 15 14:30:52.905 [notice] Tor can't help you if you use it wrong! Learn how to be safe at https://www.torproject.org/download/download#warning
Jan 15 14:30:52.905 [notice] Read configuration file "/tmp/junit2447373153840319148/torservice/torrc-defaults".
Jan 15 14:30:52.905 [notice] Read configuration file "/tmp/junit2447373153840319148/torservice/torrc".
Jan 15 14:30:52.907 [notice] Opening Control listener on 127.0.0.1:9155
Jan 15 14:30:52.907 [notice] Opened Control listener connection (ready) on 127.0.0.1:9155
Jan 15 14:30:52.907 [notice] DisableNetwork is set. Tor will not make or accept non-control network connections. Shutting down all existing connections.
Jan 15 14:30:52.000 [notice] Parsing GEOIP IPv4 file /tmp/junit2447373153840319148/torservice/geoip.
Jan 15 14:30:53.000 [notice] Parsing GEOIP IPv6 file /tmp/junit2447373153840319148/torservice/geoip6.
Jan 15 14:30:53.000 [notice] Bootstrapped 0% (starting): Starting
Jan 15 14:30:53.000 [notice] Starting with guard context "default"
Jan 15 14:30:53.000 [notice] Delaying directory fetches: DisableNetwork is set.
Jan 15 14:30:53.000 [notice] New control connection opened from 127.0.0.1.
    Lifecycle(class=RealTorController@1226354880, event=onCreate)
    >> TAKEOWNERSHIP

    << 250 OK
    >> SETEVENTS ERR NOTICE WARN

    << 250 OK
    >> SETCONF DisableNetwork=0

Jan 15 14:30:53.000 [notice] Opening Socks listener on 127.0.0.1:0
Jan 15 14:30:53.000 [notice] Socks listener listening on port 40851.
Jan 15 14:30:53.000 [notice] Opened Socks listener connection (ready) on 127.0.0.1:40851
Jan 15 14:30:53.000 [notice] Opening HTTP tunnel listener on 127.0.0.1:0
Jan 15 14:30:53.000 [notice] HTTP tunnel listener listening on port 39647.
Jan 15 14:30:53.000 [notice] Opened HTTP tunnel listener connection (ready) on 127.0.0.1:39647
Jan 15 14:30:53.000 [notice] Bootstrapped 5% (conn): Connecting to a relay
    << 250 OK
    << 650 NOTICE Opening Socks listener on 127.0.0.1:0
    event=Notice, output=Opening Socks listener on 127.0.0.1:0
    << 650 NOTICE Socks listener listening on port 40851.
    event=Notice, output=Socks listener listening on port 40851.
    << 650 NOTICE Opened Socks listener connection (ready) on 127.0.0.1:40851
    event=Notice, output=Opened Socks listener connection (ready) on 127.0.0.1:40851
    << 650 NOTICE Opening HTTP tunnel listener on 127.0.0.1:0
    event=Notice, output=Opening HTTP tunnel listener on 127.0.0.1:0
    << 650 NOTICE HTTP tunnel listener listening on port 39647.
    event=Notice, output=HTTP tunnel listener listening on port 39647.
    << 650 NOTICE Opened HTTP tunnel listener connection (ready) on 127.0.0.1:39647
    event=Notice, output=Opened HTTP tunnel listener connection (ready) on 127.0.0.1:39647
    << 650 NOTICE Bootstrapped 5% (conn): Connecting to a relay
    State(torState=Tor: On, networkState=Network: Disabled)
    event=Notice, output=Bootstrapped 5% (conn): Connecting to a relay
    State(torState=Tor: On, networkState=Network: Enabled)

io.matthewnelson.kmp.tor.KmpTorLoaderJvmUnitTest[jvm] > testExample[jvm] STARTED
Jan 15 14:30:53.000 [notice] Bootstrapped 10% (conn_done): Connected to a relay

io.matthewnelson.kmp.tor.KmpTorLoaderJvmUnitTest[jvm] > testExample[jvm] STANDARD_OUT
    << 650 NOTICE Bootstrapped 10% (conn_done): Connected to a relay
    State(torState=Tor: On, networkState=Network: Enabled)
    event=Notice, output=Bootstrapped 10% (conn_done): Connected to a relay
Jan 15 14:30:54.000 [notice] Bootstrapped 14% (handshake): Handshaking with a relay
    << 650 NOTICE Bootstrapped 14% (handshake): Handshaking with a relay
    State(torState=Tor: On, networkState=Network: Enabled)
    event=Notice, output=Bootstrapped 14% (handshake): Handshaking with a relay
Jan 15 14:30:54.000 [notice] Bootstrapped 15% (handshake_done): Handshake with a relay done
Jan 15 14:30:54.000 [notice] Bootstrapped 20% (onehop_create): Establishing an encrypted directory connection
    << 650 NOTICE Bootstrapped 15% (handshake_done): Handshake with a relay done
    State(torState=Tor: On, networkState=Network: Enabled)
    event=Notice, output=Bootstrapped 15% (handshake_done): Handshake with a relay done
    << 650 NOTICE Bootstrapped 20% (onehop_create): Establishing an encrypted directory connection
    State(torState=Tor: On, networkState=Network: Enabled)
    event=Notice, output=Bootstrapped 20% (onehop_create): Establishing an encrypted directory connection
Jan 15 14:30:54.000 [notice] Bootstrapped 25% (requesting_status): Asking for networkstatus consensus
    << 650 NOTICE Bootstrapped 25% (requesting_status): Asking for networkstatus consensus
    State(torState=Tor: On, networkState=Network: Enabled)
    event=Notice, output=Bootstrapped 25% (requesting_status): Asking for networkstatus consensus
Jan 15 14:30:54.000 [notice] Bootstrapped 30% (loading_status): Loading networkstatus consensus
    << 650 NOTICE Bootstrapped 30% (loading_status): Loading networkstatus consensus
    State(torState=Tor: On, networkState=Network: Enabled)
    event=Notice, output=Bootstrapped 30% (loading_status): Loading networkstatus consensus
Jan 15 14:30:55.000 [notice] I learned some more directory information, but not enough to build a circuit: We have no usable consensus.
    << 650 NOTICE I learned some more directory information, but not enough to build a circuit: We have no usable consensus.
    event=Notice, output=I learned some more directory information, but not enough to build a circuit: We have no usable consensus.
Jan 15 14:30:56.000 [notice] Bootstrapped 40% (loading_keys): Loading authority key certs
    << 650 NOTICE Bootstrapped 40% (loading_keys): Loading authority key certs
    State(torState=Tor: On, networkState=Network: Enabled)
    event=Notice, output=Bootstrapped 40% (loading_keys): Loading authority key certs
Jan 15 14:30:56.000 [notice] The current consensus has no exit nodes. Tor can only build internal paths, such as paths to onion services.
Jan 15 14:30:56.000 [notice] Bootstrapped 45% (requesting_descriptors): Asking for relay descriptors
Jan 15 14:30:56.000 [notice] I learned some more directory information, but not enough to build a circuit: We need more microdescriptors: we have 0/6845, and can only build 0% of likely paths. (We have 0% of guards bw, 0% of midpoint bw, and 0% of end bw (no exits in consensus, using mid) = 0% of path bw.)
    << 650 NOTICE The current consensus has no exit nodes. Tor can only build internal paths, such as paths to onion services.
    event=Notice, output=The current consensus has no exit nodes. Tor can only build internal paths, such as paths to onion services.
    << 650 NOTICE Bootstrapped 45% (requesting_descriptors): Asking for relay descriptors
    State(torState=Tor: On, networkState=Network: Enabled)
    event=Notice, output=Bootstrapped 45% (requesting_descriptors): Asking for relay descriptors
    << 650 NOTICE I learned some more directory information, but not enough to build a circuit: We need more microdescriptors: we have 0/6845, and can only build 0% of likely paths. (We have 0% of guards bw, 0% of midpoint bw, and 0% of end bw (no exits in consensus, using mid) = 0% of path bw.)
    event=Notice, output=I learned some more directory information, but not enough to build a circuit: We need more microdescriptors: we have 0/6845, and can only build 0% of likely paths. (We have 0% of guards bw, 0% of midpoint bw, and 0% of end bw (no exits in consensus, using mid) = 0% of path bw.)
Jan 15 14:30:57.000 [notice] Bootstrapped 50% (loading_descriptors): Loading relay descriptors
    << 650 NOTICE Bootstrapped 50% (loading_descriptors): Loading relay descriptors
    State(torState=Tor: On, networkState=Network: Enabled)
    event=Notice, output=Bootstrapped 50% (loading_descriptors): Loading relay descriptors
==== JAVA - TEST: RESTART 1
Jan 15 14:30:58.000 [notice] The current consensus contains exit nodes. Tor can build exit and internal paths.
    State(torState=Tor: Stopping, networkState=Network: Enabled)
    AddressInfo(dns=null, http=null, socks=null, trans=null)
    Action.Restart
    >> SETCONF DisableNetwork=1

Jan 15 14:30:58.000 [notice] Closing no-longer-configured HTTP tunnel listener on 127.0.0.1:39647
Jan 15 14:30:58.000 [notice] Closing no-longer-configured Socks listener on 127.0.0.1:40851
Jan 15 14:30:58.000 [notice] DisableNetwork is set. Tor will not make or accept non-control network connections. Shutting down all existing connections.
    << 650 NOTICE The current consensus contains exit nodes. Tor can build exit and internal paths.
    event=Notice, output=The current consensus contains exit nodes. Tor can build exit and internal paths.
    << 250 OK
    << 650 NOTICE Closing no-longer-configured HTTP tunnel listener on 127.0.0.1:39647
    event=Notice, output=Closing no-longer-configured HTTP tunnel listener on 127.0.0.1:39647
    << 650 NOTICE Closing no-longer-configured Socks listener on 127.0.0.1:40851
    event=Notice, output=Closing no-longer-configured Socks listener on 127.0.0.1:40851
    << 650 NOTICE DisableNetwork is set. Tor will not make or accept non-control network connections. Shutting down all existing connections.
    State(torState=Tor: Stopping, networkState=Network: Disabled)
    event=Notice, output=DisableNetwork is set. Tor will not make or accept non-control network connections. Shutting down all existing connections.
Jan 15 14:30:58.000 [notice] Interrupt: exiting cleanly.
    >> SIGNAL SHUTDOWN

    << 250 OK

============================================================ T= 1642275058
Tor 0.4.6.9 died: Caught signal 11
/home/administrator/AndroidStudioProjects/personal/components/kmp-tor/library/binaries/kmp-tor-binary-build/target/debug/libkmptor.so(+0x11bad1)[0x7f00e4248ad1]
[0x7f00f4ee2f54]
[0x7f00f4ee2f54]

Jvm test output 2 (linuxx64, failure mid run after successful restart)

io.matthewnelson.kmp.tor.KmpTorLoaderJvmUnitTest[jvm] STANDARD_OUT
    Lifecycle(class=RealTorManager@1744007757, event=onCreate)
    State(torState=Tor: Starting, networkState=Network: Disabled)
    Action.Start
==== RUST: acquiring config
==== JAVA: ReentrantLock acquired
==== RUST: setting lines to verify
==== RUST: verifying lines
Jan 15 14:45:49.478 [notice] Tor 0.4.6.9 running on Linux with Libevent 2.1.12-stable, OpenSSL 1.1.1m, Zlib 1.2.11, Liblzma N/A, Libzstd N/A and Glibc 2.34 as libc.
Jan 15 14:45:49.478 [notice] Tor can't help you if you use it wrong! Learn how to be safe at https://www.torproject.org/download/download#warning
Jan 15 14:45:49.478 [notice] Read configuration file "/tmp/junit5222000579364414621/torservice/torrc-defaults".
Jan 15 14:45:49.478 [notice] Read configuration file "/tmp/junit5222000579364414621/torservice/torrc".
Jan 15 14:45:49.479 [warn] Fixing permissions on directory /tmp/junit5222000579364414621/cache
==== RUST: setting lines to run
==== RUST: Starting Tor with args: [
    "tor",
    "--RunAsDaemon",
    "0",
    "-f",
    "/tmp/junit5222000579364414621/torservice/torrc",
    "--defaults-torrc",
    "/tmp/junit5222000579364414621/torservice/torrc-defaults",
    "--ignore-missing-torrc",
    "--ControlPort",
    "9155",
    "--SocksPort",
    "auto",
    "--HTTPTunnelPort",
    "auto",
    "--DormantClientTimeout",
    "10 minutes",
    "--DormantCanceledByStartup",
    "0",
    "--DisableNetwork",
    "1",
    "--SyslogIdentityTag",
    "TorManager",
    "--CacheDirectory",
    "/tmp/junit5222000579364414621/cache",
    "--DataDirectory",
    "/tmp/junit5222000579364414621/torservice/data",
    "--ControlPortWriteToFile",
    "/tmp/junit5222000579364414621/torservice/control.txt",
    "--CookieAuthentication",
    "1",
    "--CookieAuthFile",
    "/tmp/junit5222000579364414621/torservice/control_auth_cookie",
    "--GeoIPFile",
    "/tmp/junit5222000579364414621/torservice/geoip",
    "--GeoIPv6File",
    "/tmp/junit5222000579364414621/torservice/geoip6",
]
==== RUST: running lines
Jan 15 14:45:49.483 [notice] Tor 0.4.6.9 running on Linux with Libevent 2.1.12-stable, OpenSSL 1.1.1m, Zlib 1.2.11, Liblzma N/A, Libzstd N/A and Glibc 2.34 as libc.
Jan 15 14:45:49.483 [notice] Tor can't help you if you use it wrong! Learn how to be safe at https://www.torproject.org/download/download#warning
Jan 15 14:45:49.483 [notice] Read configuration file "/tmp/junit5222000579364414621/torservice/torrc-defaults".
Jan 15 14:45:49.483 [notice] Read configuration file "/tmp/junit5222000579364414621/torservice/torrc".
Jan 15 14:45:49.484 [notice] Opening Control listener on 127.0.0.1:9155
Jan 15 14:45:49.484 [notice] Opened Control listener connection (ready) on 127.0.0.1:9155
Jan 15 14:45:49.484 [notice] DisableNetwork is set. Tor will not make or accept non-control network connections. Shutting down all existing connections.
Jan 15 14:45:49.000 [notice] Parsing GEOIP IPv4 file /tmp/junit5222000579364414621/torservice/geoip.
Jan 15 14:45:49.000 [notice] Parsing GEOIP IPv6 file /tmp/junit5222000579364414621/torservice/geoip6.
Jan 15 14:45:49.000 [notice] Bootstrapped 0% (starting): Starting
Jan 15 14:45:49.000 [notice] Starting with guard context "default"
Jan 15 14:45:49.000 [notice] Delaying directory fetches: DisableNetwork is set.
Jan 15 14:45:49.000 [notice] New control connection opened from 127.0.0.1.
    Lifecycle(class=RealTorController@1511809161, event=onCreate)
    >> TAKEOWNERSHIP

    << 250 OK
    >> SETEVENTS ERR NOTICE WARN

    << 250 OK
    >> SETCONF DisableNetwork=0

Jan 15 14:45:49.000 [notice] Opening Socks listener on 127.0.0.1:0
Jan 15 14:45:49.000 [notice] Socks listener listening on port 35255.
Jan 15 14:45:49.000 [notice] Opened Socks listener connection (ready) on 127.0.0.1:35255
Jan 15 14:45:49.000 [notice] Opening HTTP tunnel listener on 127.0.0.1:0
Jan 15 14:45:49.000 [notice] HTTP tunnel listener listening on port 38231.
Jan 15 14:45:49.000 [notice] Opened HTTP tunnel listener connection (ready) on 127.0.0.1:38231
Jan 15 14:45:49.000 [notice] Bootstrapped 5% (conn): Connecting to a relay
    << 250 OK
    << 650 NOTICE Opening Socks listener on 127.0.0.1:0
    event=Notice, output=Opening Socks listener on 127.0.0.1:0
    << 650 NOTICE Socks listener listening on port 35255.
    event=Notice, output=Socks listener listening on port 35255.
    << 650 NOTICE Opened Socks listener connection (ready) on 127.0.0.1:35255
    event=Notice, output=Opened Socks listener connection (ready) on 127.0.0.1:35255
    << 650 NOTICE Opening HTTP tunnel listener on 127.0.0.1:0
    event=Notice, output=Opening HTTP tunnel listener on 127.0.0.1:0
    << 650 NOTICE HTTP tunnel listener listening on port 38231.
    event=Notice, output=HTTP tunnel listener listening on port 38231.
    << 650 NOTICE Opened HTTP tunnel listener connection (ready) on 127.0.0.1:38231
    event=Notice, output=Opened HTTP tunnel listener connection (ready) on 127.0.0.1:38231
    << 650 NOTICE Bootstrapped 5% (conn): Connecting to a relay
    State(torState=Tor: On, networkState=Network: Disabled)
    event=Notice, output=Bootstrapped 5% (conn): Connecting to a relay
    State(torState=Tor: On, networkState=Network: Enabled)

io.matthewnelson.kmp.tor.KmpTorLoaderJvmUnitTest[jvm] > testExample[jvm] STARTED
Jan 15 14:45:50.000 [notice] Bootstrapped 10% (conn_done): Connected to a relay

io.matthewnelson.kmp.tor.KmpTorLoaderJvmUnitTest[jvm] > testExample[jvm] STANDARD_OUT
    << 650 NOTICE Bootstrapped 10% (conn_done): Connected to a relay
    State(torState=Tor: On, networkState=Network: Enabled)
    event=Notice, output=Bootstrapped 10% (conn_done): Connected to a relay
Jan 15 14:45:50.000 [notice] Bootstrapped 14% (handshake): Handshaking with a relay
    << 650 NOTICE Bootstrapped 14% (handshake): Handshaking with a relay
    State(torState=Tor: On, networkState=Network: Enabled)
    event=Notice, output=Bootstrapped 14% (handshake): Handshaking with a relay
Jan 15 14:45:50.000 [notice] Bootstrapped 15% (handshake_done): Handshake with a relay done
Jan 15 14:45:50.000 [notice] Bootstrapped 20% (onehop_create): Establishing an encrypted directory connection
    << 650 NOTICE Bootstrapped 15% (handshake_done): Handshake with a relay done
    State(torState=Tor: On, networkState=Network: Enabled)
    event=Notice, output=Bootstrapped 15% (handshake_done): Handshake with a relay done
    << 650 NOTICE Bootstrapped 20% (onehop_create): Establishing an encrypted directory connection
    State(torState=Tor: On, networkState=Network: Enabled)
    event=Notice, output=Bootstrapped 20% (onehop_create): Establishing an encrypted directory connection
Jan 15 14:45:50.000 [notice] Bootstrapped 25% (requesting_status): Asking for networkstatus consensus
    << 650 NOTICE Bootstrapped 25% (requesting_status): Asking for networkstatus consensus
    State(torState=Tor: On, networkState=Network: Enabled)
    event=Notice, output=Bootstrapped 25% (requesting_status): Asking for networkstatus consensus
Jan 15 14:45:51.000 [notice] Bootstrapped 30% (loading_status): Loading networkstatus consensus
    << 650 NOTICE Bootstrapped 30% (loading_status): Loading networkstatus consensus
    State(torState=Tor: On, networkState=Network: Enabled)
    event=Notice, output=Bootstrapped 30% (loading_status): Loading networkstatus consensus
Jan 15 14:45:52.000 [notice] I learned some more directory information, but not enough to build a circuit: We have no usable consensus.
    << 650 NOTICE I learned some more directory information, but not enough to build a circuit: We have no usable consensus.
    event=Notice, output=I learned some more directory information, but not enough to build a circuit: We have no usable consensus.
Jan 15 14:45:52.000 [notice] Bootstrapped 40% (loading_keys): Loading authority key certs
    << 650 NOTICE Bootstrapped 40% (loading_keys): Loading authority key certs
    State(torState=Tor: On, networkState=Network: Enabled)
    event=Notice, output=Bootstrapped 40% (loading_keys): Loading authority key certs
Jan 15 14:45:52.000 [notice] The current consensus has no exit nodes. Tor can only build internal paths, such as paths to onion services.
Jan 15 14:45:52.000 [notice] Bootstrapped 45% (requesting_descriptors): Asking for relay descriptors
Jan 15 14:45:52.000 [notice] I learned some more directory information, but not enough to build a circuit: We need more microdescriptors: we have 0/6845, and can only build 0% of likely paths. (We have 0% of guards bw, 0% of midpoint bw, and 0% of end bw (no exits in consensus, using mid) = 0% of path bw.)
    << 650 NOTICE The current consensus has no exit nodes. Tor can only build internal paths, such as paths to onion services.
    event=Notice, output=The current consensus has no exit nodes. Tor can only build internal paths, such as paths to onion services.
    << 650 NOTICE Bootstrapped 45% (requesting_descriptors): Asking for relay descriptors
    State(torState=Tor: On, networkState=Network: Enabled)
    event=Notice, output=Bootstrapped 45% (requesting_descriptors): Asking for relay descriptors
    << 650 NOTICE I learned some more directory information, but not enough to build a circuit: We need more microdescriptors: we have 0/6845, and can only build 0% of likely paths. (We have 0% of guards bw, 0% of midpoint bw, and 0% of end bw (no exits in consensus, using mid) = 0% of path bw.)
    event=Notice, output=I learned some more directory information, but not enough to build a circuit: We need more microdescriptors: we have 0/6845, and can only build 0% of likely paths. (We have 0% of guards bw, 0% of midpoint bw, and 0% of end bw (no exits in consensus, using mid) = 0% of path bw.)
Jan 15 14:45:53.000 [notice] Bootstrapped 50% (loading_descriptors): Loading relay descriptors
    << 650 NOTICE Bootstrapped 50% (loading_descriptors): Loading relay descriptors
    State(torState=Tor: On, networkState=Network: Enabled)
    event=Notice, output=Bootstrapped 50% (loading_descriptors): Loading relay descriptors
Jan 15 14:45:54.000 [notice] The current consensus contains exit nodes. Tor can build exit and internal paths.
    << 650 NOTICE The current consensus contains exit nodes. Tor can build exit and internal paths.
    event=Notice, output=The current consensus contains exit nodes. Tor can build exit and internal paths.
==== JAVA - TEST: RESTART 1
    State(torState=Tor: Stopping, networkState=Network: Enabled)
    AddressInfo(dns=null, http=null, socks=null, trans=null)
    Action.Restart
    >> SETCONF DisableNetwork=1

Jan 15 14:45:54.000 [notice] Closing no-longer-configured HTTP tunnel listener on 127.0.0.1:38231
Jan 15 14:45:54.000 [notice] Closing no-longer-configured Socks listener on 127.0.0.1:35255
Jan 15 14:45:54.000 [notice] DisableNetwork is set. Tor will not make or accept non-control network connections. Shutting down all existing connections.
    << 250 OK
    << 650 NOTICE Closing no-longer-configured HTTP tunnel listener on 127.0.0.1:38231
    event=Notice, output=Closing no-longer-configured HTTP tunnel listener on 127.0.0.1:38231
    << 650 NOTICE Closing no-longer-configured Socks listener on 127.0.0.1:35255
    event=Notice, output=Closing no-longer-configured Socks listener on 127.0.0.1:35255
    << 650 NOTICE DisableNetwork is set. Tor will not make or accept non-control network connections. Shutting down all existing connections.
    State(torState=Tor: Stopping, networkState=Network: Disabled)
    event=Notice, output=DisableNetwork is set. Tor will not make or accept non-control network connections. Shutting down all existing connections.
Jan 15 14:45:55.000 [notice] Interrupt: exiting cleanly.
    >> SIGNAL SHUTDOWN

    << 250 OK
    Replies off the control port were empty
    Tor has stopped
    Lifecycle(class=RealTorController@1511809161, event=onDestroy)
==== RUST: freeing config
==== JAVA: runLines completed
==== JAVA: ReentrantLock release
    State(torState=Tor: Off, networkState=Network: Disabled)
    State(torState=Tor: Starting, networkState=Network: Disabled)
==== JAVA: ReentrantLock acquired
==== RUST: acquiring config
==== RUST: setting lines to verify
==== RUST: verifying lines
Jan 15 14:45:56.000 [notice] Tor 0.4.6.9 running on Linux with Libevent 2.1.12-stable, OpenSSL 1.1.1m, Zlib 1.2.11, Liblzma N/A, Libzstd N/A and Glibc 2.34 as libc.
Jan 15 14:45:56.000 [notice] Tor can't help you if you use it wrong! Learn how to be safe at https://www.torproject.org/download/download#warning
Jan 15 14:45:56.000 [notice] Read configuration file "/tmp/junit5222000579364414621/torservice/torrc-defaults".
Jan 15 14:45:56.000 [notice] Read configuration file "/tmp/junit5222000579364414621/torservice/torrc".
==== RUST: setting lines to run
==== RUST: Starting Tor with args: [
    "tor",
    "--RunAsDaemon",
    "0",
    "-f",
    "/tmp/junit5222000579364414621/torservice/torrc",
    "--defaults-torrc",
    "/tmp/junit5222000579364414621/torservice/torrc-defaults",
    "--ignore-missing-torrc",
    "--ControlPort",
    "9155",
    "--SocksPort",
    "auto",
    "--HTTPTunnelPort",
    "auto",
    "--DormantClientTimeout",
    "10 minutes",
    "--DormantCanceledByStartup",
    "0",
    "--DisableNetwork",
    "1",
    "--SyslogIdentityTag",
    "TorManager",
    "--CacheDirectory",
    "/tmp/junit5222000579364414621/cache",
    "--DataDirectory",
    "/tmp/junit5222000579364414621/torservice/data",
    "--ControlPortWriteToFile",
    "/tmp/junit5222000579364414621/torservice/control.txt",
    "--CookieAuthentication",
    "1",
    "--CookieAuthFile",
    "/tmp/junit5222000579364414621/torservice/control_auth_cookie",
    "--GeoIPFile",
    "/tmp/junit5222000579364414621/torservice/geoip",
    "--GeoIPv6File",
    "/tmp/junit5222000579364414621/torservice/geoip6",
]
==== RUST: running lines
Jan 15 14:45:56.000 [notice] Tor 0.4.6.9 running on Linux with Libevent 2.1.12-stable, OpenSSL 1.1.1m, Zlib 1.2.11, Liblzma N/A, Libzstd N/A and Glibc 2.34 as libc.
Jan 15 14:45:56.000 [notice] Tor can't help you if you use it wrong! Learn how to be safe at https://www.torproject.org/download/download#warning
Jan 15 14:45:56.000 [notice] Read configuration file "/tmp/junit5222000579364414621/torservice/torrc-defaults".
Jan 15 14:45:56.000 [notice] Read configuration file "/tmp/junit5222000579364414621/torservice/torrc".
Jan 15 14:45:56.000 [notice] Opening Control listener on 127.0.0.1:9155
Jan 15 14:45:56.000 [notice] Opened Control listener connection (ready) on 127.0.0.1:9155
Jan 15 14:45:56.000 [notice] DisableNetwork is set. Tor will not make or accept non-control network connections. Shutting down all existing connections.
Jan 15 14:45:56.000 [notice] Parsing GEOIP IPv4 file /tmp/junit5222000579364414621/torservice/geoip.
Jan 15 14:45:56.000 [notice] Parsing GEOIP IPv6 file /tmp/junit5222000579364414621/torservice/geoip6.
Jan 15 14:45:56.000 [notice] Bootstrapped 0% (starting): Starting
Jan 15 14:45:56.000 [notice] Starting with guard context "default"
Jan 15 14:45:56.000 [notice] Delaying directory fetches: DisableNetwork is set.
Jan 15 14:45:56.000 [notice] New control connection opened from 127.0.0.1.
    Lifecycle(class=RealTorController@446575866, event=onCreate)
    >> TAKEOWNERSHIP

    << 250 OK
    >> SETEVENTS ERR NOTICE WARN

    << 250 OK
    >> SETCONF DisableNetwork=0

Jan 15 14:45:56.000 [notice] Opening Socks listener on 127.0.0.1:0
Jan 15 14:45:56.000 [notice] Socks listener listening on port 42085.
Jan 15 14:45:56.000 [notice] Opened Socks listener connection (ready) on 127.0.0.1:42085
Jan 15 14:45:56.000 [notice] Opening HTTP tunnel listener on 127.0.0.1:0
Jan 15 14:45:56.000 [notice] HTTP tunnel listener listening on port 39265.
Jan 15 14:45:56.000 [notice] Opened HTTP tunnel listener connection (ready) on 127.0.0.1:39265
Jan 15 14:45:56.000 [notice] Bootstrapped 5% (conn): Connecting to a relay
    << 250 OK
    << 650 NOTICE Opening Socks listener on 127.0.0.1:0
    event=Notice, output=Opening Socks listener on 127.0.0.1:0
    << 650 NOTICE Socks listener listening on port 42085.
    event=Notice, output=Socks listener listening on port 42085.
    << 650 NOTICE Opened Socks listener connection (ready) on 127.0.0.1:42085
    event=Notice, output=Opened Socks listener connection (ready) on 127.0.0.1:42085
    << 650 NOTICE Opening HTTP tunnel listener on 127.0.0.1:0
    event=Notice, output=Opening HTTP tunnel listener on 127.0.0.1:0
    << 650 NOTICE HTTP tunnel listener listening on port 39265.
    event=Notice, output=HTTP tunnel listener listening on port 39265.
    << 650 NOTICE Opened HTTP tunnel listener connection (ready) on 127.0.0.1:39265
    event=Notice, output=Opened HTTP tunnel listener connection (ready) on 127.0.0.1:39265
    << 650 NOTICE Bootstrapped 5% (conn): Connecting to a relay
    State(torState=Tor: On, networkState=Network: Disabled)
    event=Notice, output=Bootstrapped 5% (conn): Connecting to a relay
    State(torState=Tor: On, networkState=Network: Enabled)
Jan 15 14:45:56.000 [notice] Bootstrapped 10% (conn_done): Connected to a relay
    << 650 NOTICE Bootstrapped 10% (conn_done): Connected to a relay
    State(torState=Tor: On, networkState=Network: Enabled)
    event=Notice, output=Bootstrapped 10% (conn_done): Connected to a relay
Jan 15 14:45:56.000 [notice] Bootstrapped 14% (handshake): Handshaking with a relay
    << 650 NOTICE Bootstrapped 14% (handshake): Handshaking with a relay
    State(torState=Tor: On, networkState=Network: Enabled)
    event=Notice, output=Bootstrapped 14% (handshake): Handshaking with a relay
Jan 15 14:45:57.000 [notice] Bootstrapped 15% (handshake_done): Handshake with a relay done
Jan 15 14:45:57.000 [notice] Bootstrapped 45% (requesting_descriptors): Asking for relay descriptors
    << 650 NOTICE Bootstrapped 15% (handshake_done): Handshake with a relay done
    State(torState=Tor: On, networkState=Network: Enabled)
    event=Notice, output=Bootstrapped 15% (handshake_done): Handshake with a relay done
    << 650 NOTICE Bootstrapped 45% (requesting_descriptors): Asking for relay descriptors
    State(torState=Tor: On, networkState=Network: Enabled)
    event=Notice, output=Bootstrapped 45% (requesting_descriptors): Asking for relay descriptors
Jan 15 14:45:57.000 [notice] Bootstrapped 52% (loading_descriptors): Loading relay descriptors
    << 650 NOTICE Bootstrapped 52% (loading_descriptors): Loading relay descriptors
    State(torState=Tor: On, networkState=Network: Enabled)
    event=Notice, output=Bootstrapped 52% (loading_descriptors): Loading relay descriptors
Jan 15 14:45:59.000 [notice] Bootstrapped 59% (loading_descriptors): Loading relay descriptors
    << 650 NOTICE Bootstrapped 59% (loading_descriptors): Loading relay descriptors
    State(torState=Tor: On, networkState=Network: Enabled)
    event=Notice, output=Bootstrapped 59% (loading_descriptors): Loading relay descriptors
Jan 15 14:46:00.000 [notice] Bootstrapped 68% (loading_descriptors): Loading relay descriptors
    << 650 NOTICE Bootstrapped 68% (loading_descriptors): Loading relay descriptors
    State(torState=Tor: On, networkState=Network: Enabled)
    event=Notice, output=Bootstrapped 68% (loading_descriptors): Loading relay descriptors

============================================================ T= 1642275961
Tor 0.4.6.9 died: Caught signal 11
/home/administrator/AndroidStudioProjects/personal/components/kmp-tor/library/binaries/kmp-tor-binary-build/target/debug/libkmptor.so(+0x11bad1)[0x7faad1b17ad1]
[0x7faae900c82c]
[0x7faae900c82c]

[05nelsonm]

Narrowing it down, I believe it has either something to do with my test setup, or glibc. I created a Java application and tried loading the generated libKmpTor.so after extracting it and got an UnsatisfiedLinkError stating that the JVM couldn't find GLIBC_2.34 (I believe that was the version).

That said, compiling the JNI bindings for Android and everything runs well, except an occasional SIG 11 (seemingly the same problem that the GuardianProject's tor-android binaries suffer from). Wondering if it's something upstream, or b/c glibc is not statically linked.

lib.rs (Final JNI bindings for Java/Android)

#![allow(non_snake_case)]

extern crate tor_sys;

use jni::JNIEnv;
use jni::objects::{JClass, JList, JString, JObject};
use std::ffi::{CString, c_void};
use jni::sys::jstring;

/*
 * Success: Returns empty jstring
 * Error: Returns non-empty jstring (error message to throw TorManagerException)
 **/
#[no_mangle]
pub extern "system" fn Java_io_matthewnelson_kmp_tor_KmpTorLoaderJvm_runLines(
    env: JNIEnv,
    _class: JClass,
    // lines are a list of of strings to be run, already configured from kotlin side:
    // ex: [ "--ControlPortWriteToFile", "/path/to/file" ]
    lines: JObject // JList
) -> jstring {
    let mut verify: Vec<String> = vec![
        String::from("tor"), String::from("--verify-config"),
    ];

    let mut run: Vec<String> = vec![
        String::from("tor"),
    ];

    let lines: JList = env.get_list(lines).expect("expected List<String>").into();
    for i in 0..lines.size().unwrap() {
        let line = JString::from(lines.get(i.into()).expect("expected a String").unwrap());
        verify.push(env.get_string(line.clone()).unwrap().into());
        run.push(env.get_string(line.clone()).unwrap().into());
    }

    let verify: Vec<_> = verify.into_iter().map(|s| CString::new(s).unwrap()).collect();
    let verify: Vec<_> = verify.iter().map(|s| s.as_ptr()).collect();

    let run: Vec<_> = run.into_iter().map(|s| CString::new(s).unwrap()).collect();
    let run: Vec<_> = run.iter().map(|s| s.as_ptr()).collect();

    let config = unsafe {
        tor_sys::tor_main_configuration_new()
    };

    if config.is_null() {
        return env.new_string("TorConfig was null.").unwrap().into_inner();
    }

    let result = unsafe {
        // set lines to be verified
        tor_sys::tor_main_configuration_set_command_line(
            config,
            verify.len() as i32,
            verify.as_ptr()
        )
    };

    if result != 0 {
        return prepare_err_msg(config, &env, "Failed to set args for verification.");
    }

    let result = unsafe {
        // run lines to verify
        tor_sys::tor_run_main(config)
    };

    if result != 0 {
        return prepare_err_msg(config, &env, "Failed to verify args. Tor does not like a setting.");
    }

    let result = unsafe {
        // set lines to be run
        tor_sys::tor_main_configuration_set_command_line(
            config,
            run.len() as i32,
            run.as_ptr()
        )
    };

    if result != 0 {
        return prepare_err_msg(config, &env, "Failed to set args to run.");
    }

    let result = unsafe {
        // run lines
        // This is runBlocking on the current Thread (which is handled kotlin side)
        tor_sys::tor_run_main(config)
    };

    if result != 0 {
        return prepare_err_msg(config, &env, "Failed to run args.");
    }

    unsafe {
        // release config from memory
        tor_sys::tor_main_configuration_free(config);
    }

    return env.new_string("").unwrap().into_inner();
}

fn prepare_err_msg(config: *mut c_void, env: &JNIEnv, msg: &str) -> jstring {
    unsafe {
        tor_sys::tor_main_configuration_free(config)
    };

    return env.new_string(msg).unwrap().into_inner();
}

Android Functionality:

[afilini]

I would try adding some code to enforce only one instance of Tor running at a time: unfortunately Tor internally uses a lot of static variables to store the current state of the daemon, and those are shared among all threads of your process. So if you start two Tor instances in the same process (in different threads), you are gonna have some conflicts there because they would both be reading/writing to the same addresses. Maybe what's happening here is that the previous instance hasn't shut down completely when the next one starts and they "collide" in some way.

You could implement this in Rust (just use a Mutex) or in Kotlin if you prefer.

There's still one issue though, which is that if your Tor instance doesn't exit cleanly there's basically no way to restart it afterwards because the shared state will be corrupted. The only workaround I could think of involves putting all of the Tor code in a separate shared object which is not linked to your main binary, but it's just loaded at runtime using dlopen. Doing it at runtime means that you can also unload the library whenever you want (with dlclose), effectively dropping all of the static variable that Tor uses. So you can basically unload/load the library before every restart to ensure the state is clean.

Unfortunately that means that you would have to ship an extra shared lib with your binary (I don't think you can embed it inside), which is not ideal. Also, I don't know if recent mobile OSs let you load libraries at runtime, but I'm afraid they might not for safety reasons. So in the end I only made a prototype which I pushed to this branch, but I've never spent the time to clean it up and merge it. I could do it if there's interest for it though.

Unrelated, but something you could find useful to debug: to rule out glibc issues you could try building against musl. It's not officially "supported" because I don't think we test it in the CI, but I remember trying it a while back (musl on x86_64) and it was working fine.

[05nelsonm]

Yes, the underlying abstract class KmpTorLoader calls the protected abstract method startTor from a coroutine using a static Mutex; was better that way since that abstraction is in a separate module.

Doing it at runtime means that you can also unload the library whenever you want (with dlclose), effectively dropping all of the static variable that Tor uses.

Amazing... Gave me the idea to let the Jni loader class where System.loadLibrary is called drop off after runLines completes (upon JVM GCing the class, the shared lib will be unloaded). Loading the lib upon each call to startTor seems to resolve it. On Android I ran it through about 200 restart cycles. 0 crashes, so it most likely had to do with what you eluded to!

final KmpTorLoaderJvm (for Android, still need to work out Java)

actual class KmpTorLoaderJvm(provider: TorConfigProviderAndroid): KmpTorLoader(provider) {

    @Throws(TorManagerException::class, CancellationException::class)
    override suspend fun startTor(configLines: List<String>) {
        val exMessage = KmpTorLoaderJni().runLines(configLines)
        if (exMessage.isNotEmpty()) {
            throw TorManagerException(exMessage)
        }
    }
}

private class KmpTorLoaderJni {
    init {
        System.loadLibrary("KmpTor")
    }

    // Had to update method signature in Rust to:
    // Java_io_matthewnelson_kmp_tor_KmpTorLoaderJni_runLines(
    external fun runLines(lines: List<String>): String
}

Will let ya know.