[INFO] cloning repository https://github.com/evant/adp [INFO] running `Command { std: "git" "-c" "credential.helper=" "-c" "credential.helper=/workspace/cargo-home/bin/git-credential-null" "clone" "--bare" "https://github.com/evant/adp" "/workspace/cache/git-repos/https%3A%2F%2Fgithub.com%2Fevant%2Fadp", kill_on_drop: false }` [INFO] [stderr] Cloning into bare repository '/workspace/cache/git-repos/https%3A%2F%2Fgithub.com%2Fevant%2Fadp'... [INFO] running `Command { std: "git" "rev-parse" "HEAD", kill_on_drop: false }` [INFO] [stdout] ee4c901bf25e9a98c3c5560485f191b58f7c207f [INFO] testing evant/adp against 1.60.0 for beta-1.61-1 [INFO] running `Command { std: "git" "clone" "/workspace/cache/git-repos/https%3A%2F%2Fgithub.com%2Fevant%2Fadp" "/workspace/builds/worker-31/source", kill_on_drop: false }` [INFO] [stderr] Cloning into '/workspace/builds/worker-31/source'... [INFO] [stderr] done. [INFO] validating manifest of git repo https://github.com/evant/adp on toolchain 1.60.0 [INFO] running `Command { std: "/workspace/cargo-home/bin/cargo" "+1.60.0" "metadata" "--manifest-path" "Cargo.toml" "--no-deps", kill_on_drop: false }` [INFO] started tweaking git repo https://github.com/evant/adp [INFO] finished tweaking git repo https://github.com/evant/adp [INFO] tweaked toml for git repo https://github.com/evant/adp written to /workspace/builds/worker-31/source/Cargo.toml [INFO] crate git repo https://github.com/evant/adp already has a lockfile, it will not be regenerated [INFO] running `Command { std: "/workspace/cargo-home/bin/cargo" "+1.60.0" "fetch" "--manifest-path" "Cargo.toml", kill_on_drop: false }` [INFO] [stderr] Blocking waiting for file lock on package cache [INFO] [stderr] Blocking waiting for file lock on package cache [INFO] [stderr] Downloading crates ... [INFO] [stderr] Downloaded sysinfo v0.20.5 [INFO] [stderr] Downloaded function_name v0.2.0 [INFO] [stderr] Downloaded retry v1.3.0 [INFO] [stderr] Downloaded temp_testdir v0.2.3 [INFO] [stderr] Downloaded try-block v0.1.0 [INFO] [stderr] Downloaded process_control v3.1.0 [INFO] [stderr] Downloaded ppv-lite86 v0.2.14 [INFO] [stderr] Downloaded named-semaphore v0.1.0 [INFO] [stderr] Downloaded ambassador v0.2.1 [INFO] [stderr] Downloaded function_name-proc-macro v0.2.0 [INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-31/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-31/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:b0c94ce3c1162fcb8e57cac5b65ec2f72eabb1eebea4fcc35e269e823f681646" "/opt/rustwide/cargo-home/bin/cargo" "+1.60.0" "metadata" "--no-deps" "--format-version=1", kill_on_drop: false }` [INFO] [stdout] 17cc8027987eb0d75255a9539576c8e1cbea24a0946795d7d4210bf7f9893177 [INFO] running `Command { std: "docker" "start" "-a" "17cc8027987eb0d75255a9539576c8e1cbea24a0946795d7d4210bf7f9893177", kill_on_drop: false }` [INFO] running `Command { std: "docker" "inspect" "17cc8027987eb0d75255a9539576c8e1cbea24a0946795d7d4210bf7f9893177", kill_on_drop: false }` [INFO] running `Command { std: "docker" "rm" "-f" "17cc8027987eb0d75255a9539576c8e1cbea24a0946795d7d4210bf7f9893177", kill_on_drop: false }` [INFO] [stdout] 17cc8027987eb0d75255a9539576c8e1cbea24a0946795d7d4210bf7f9893177 [INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-31/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-31/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=warn" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:b0c94ce3c1162fcb8e57cac5b65ec2f72eabb1eebea4fcc35e269e823f681646" "/opt/rustwide/cargo-home/bin/cargo" "+1.60.0" "build" "--frozen" "--message-format=json", kill_on_drop: false }` [INFO] [stdout] 94a525f43b870025652533e0a5fcc7f0444afa97994c12653d82819e4f48d83a [INFO] running `Command { std: "docker" "start" "-a" "94a525f43b870025652533e0a5fcc7f0444afa97994c12653d82819e4f48d83a", kill_on_drop: false }` [INFO] [stderr] Blocking waiting for file lock on package cache [INFO] [stderr] Compiling libc v0.2.104 [INFO] [stderr] Compiling cfg-if v1.0.0 [INFO] [stderr] Compiling lazy_static v1.4.0 [INFO] [stderr] Compiling proc-macro2 v1.0.30 [INFO] [stderr] Compiling autocfg v1.0.1 [INFO] [stderr] Compiling unicode-xid v0.2.2 [INFO] [stderr] Compiling crossbeam-utils v0.8.5 [INFO] [stderr] Compiling syn v1.0.80 [INFO] [stderr] Compiling crossbeam-epoch v0.9.5 [INFO] [stderr] Compiling getrandom v0.1.16 [INFO] [stderr] Compiling rayon-core v1.9.1 [INFO] [stderr] Compiling scopeguard v1.1.0 [INFO] [stderr] Compiling ppv-lite86 v0.2.14 [INFO] [stderr] Compiling once_cell v1.8.0 [INFO] [stderr] Compiling anyhow v1.0.44 [INFO] [stderr] Compiling either v1.6.1 [INFO] [stderr] Compiling sysinfo v0.20.5 [INFO] [stderr] Compiling ansi_term v0.12.1 [INFO] [stderr] Compiling pin-project-lite v0.2.7 [INFO] [stderr] Compiling tracing-core v0.1.21 [INFO] [stderr] Compiling sharded-slab v0.1.4 [INFO] [stderr] Compiling thread_local v1.1.3 [INFO] [stderr] Compiling memoffset v0.6.4 [INFO] [stderr] Compiling rayon v1.5.1 [INFO] [stderr] Compiling crossbeam-channel v0.5.1 [INFO] [stderr] Compiling tracing-subscriber v0.2.25 [INFO] [stderr] Compiling quote v1.0.10 [INFO] [stderr] Compiling num_cpus v1.13.0 [INFO] [stderr] Compiling errno v0.2.7 [INFO] [stderr] Compiling dirs-sys v0.3.6 [INFO] [stderr] Compiling process_control v3.1.0 [INFO] [stderr] Compiling fs2 v0.4.3 [INFO] [stderr] Compiling rand_core v0.5.1 [INFO] [stderr] Compiling dirs v4.0.0 [INFO] [stderr] Compiling crossbeam-deque v0.8.1 [INFO] [stderr] Compiling rand_chacha v0.2.2 [INFO] [stderr] Compiling rand v0.7.3 [INFO] [stderr] Compiling retry v1.3.0 [INFO] [stderr] Compiling thiserror-impl v1.0.30 [INFO] [stderr] Compiling tracing-attributes v0.1.18 [INFO] [stderr] Compiling ambassador v0.2.1 [INFO] [stderr] Compiling tracing v0.1.29 [INFO] [stderr] Compiling thiserror v1.0.30 [INFO] [stderr] Compiling named-semaphore v0.1.0 [INFO] [stderr] Compiling adp v0.1.0 (/opt/rustwide/workdir) [INFO] [stdout] warning: field is never read: `guard` [INFO] [stdout] --> src/main.rs:107:5 [INFO] [stdout] | [INFO] [stdout] 107 | guard: SemaphoreGuard<'a>, [INFO] [stdout] | ^^^^^^^^^^^^^^^^^^^^^^^^^ [INFO] [stdout] | [INFO] [stdout] = note: `#[warn(dead_code)]` on by default [INFO] [stdout] note: `Resource` has a derived impl for the trait `Debug`, but this is intentionally ignored during dead code analysis [INFO] [stdout] --> src/main.rs:103:10 [INFO] [stdout] | [INFO] [stdout] 103 | #[derive(Debug)] [INFO] [stdout] | ^^^^^ [INFO] [stdout] = note: this warning originates in the derive macro `Debug` (in Nightly builds, run with -Z macro-backtrace for more info) [INFO] [stdout] [INFO] [stdout] [INFO] [stdout] warning: 1 warning emitted [INFO] [stdout] [INFO] [stdout] [INFO] [stderr] Finished dev [unoptimized + debuginfo] target(s) in 25.87s [INFO] running `Command { std: "docker" "inspect" "94a525f43b870025652533e0a5fcc7f0444afa97994c12653d82819e4f48d83a", kill_on_drop: false }` [INFO] running `Command { std: "docker" "rm" "-f" "94a525f43b870025652533e0a5fcc7f0444afa97994c12653d82819e4f48d83a", kill_on_drop: false }` [INFO] [stdout] 94a525f43b870025652533e0a5fcc7f0444afa97994c12653d82819e4f48d83a [INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-31/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-31/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=warn" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:b0c94ce3c1162fcb8e57cac5b65ec2f72eabb1eebea4fcc35e269e823f681646" "/opt/rustwide/cargo-home/bin/cargo" "+1.60.0" "test" "--frozen" "--no-run" "--message-format=json", kill_on_drop: false }` [INFO] [stdout] 5bbc396a369c9194732c020cd95c21e0a3b6285f6b9c06d7708995fc34091b44 [INFO] running `Command { std: "docker" "start" "-a" "5bbc396a369c9194732c020cd95c21e0a3b6285f6b9c06d7708995fc34091b44", kill_on_drop: false }` [INFO] [stderr] Blocking waiting for file lock on package cache [INFO] [stderr] Compiling ident_case v1.0.1 [INFO] [stderr] Compiling strsim v0.10.0 [INFO] [stderr] Compiling fnv v1.0.7 [INFO] [stderr] Compiling serde v1.0.130 [INFO] [stderr] Compiling proc-macro2 v0.4.30 [INFO] [stderr] Compiling unicode-xid v0.1.0 [INFO] [stderr] Compiling syn v0.15.44 [INFO] [stderr] Compiling temp_testdir v0.2.3 [INFO] [stderr] Compiling try-block v0.1.0 [INFO] [stderr] Compiling darling_core v0.12.4 [INFO] [stderr] Compiling quote v0.6.13 [INFO] [stderr] Compiling darling_macro v0.12.4 [INFO] [stderr] Compiling darling v0.12.4 [INFO] [stderr] Compiling toml v0.5.8 [INFO] [stderr] Compiling derive_builder_core v0.10.2 [INFO] [stderr] Compiling proc-macro-crate v0.1.5 [INFO] [stderr] Compiling derive_builder_macro v0.10.2 [INFO] [stderr] Compiling function_name-proc-macro v0.2.0 [INFO] [stderr] Compiling function_name v0.2.0 [INFO] [stderr] Compiling derive_builder v0.10.2 [INFO] [stderr] Compiling adp v0.1.0 (/opt/rustwide/workdir) [INFO] [stdout] warning: unused import: `Read` [INFO] [stdout] --> src/lockfile.rs:127:27 [INFO] [stdout] | [INFO] [stdout] 127 | use std::io::{Cursor, Read, Result, Write}; [INFO] [stdout] | ^^^^ [INFO] [stdout] | [INFO] [stdout] = note: `#[warn(unused_imports)]` on by default [INFO] [stdout] [INFO] [stdout] [INFO] [stdout] warning: unused import: `Write` [INFO] [stdout] --> src/lockfile.rs:127:41 [INFO] [stdout] | [INFO] [stdout] 127 | use std::io::{Cursor, Read, Result, Write}; [INFO] [stdout] | ^^^^^ [INFO] [stdout] [INFO] [stdout] [INFO] [stdout] warning: field is never read: `guard` [INFO] [stdout] --> src/main.rs:107:5 [INFO] [stdout] | [INFO] [stdout] 107 | guard: SemaphoreGuard<'a>, [INFO] [stdout] | ^^^^^^^^^^^^^^^^^^^^^^^^^ [INFO] [stdout] | [INFO] [stdout] = note: `#[warn(dead_code)]` on by default [INFO] [stdout] note: `Resource` has a derived impl for the trait `Debug`, but this is intentionally ignored during dead code analysis [INFO] [stdout] --> src/main.rs:103:10 [INFO] [stdout] | [INFO] [stdout] 103 | #[derive(Debug)] [INFO] [stdout] | ^^^^^ [INFO] [stdout] = note: this warning originates in the derive macro `Debug` (in Nightly builds, run with -Z macro-backtrace for more info) [INFO] [stdout] [INFO] [stdout] [INFO] [stdout] warning: 3 warnings emitted [INFO] [stdout] [INFO] [stdout] [INFO] [stderr] Finished test [unoptimized + debuginfo] target(s) in 46.37s [INFO] running `Command { std: "docker" "inspect" "5bbc396a369c9194732c020cd95c21e0a3b6285f6b9c06d7708995fc34091b44", kill_on_drop: false }` [INFO] running `Command { std: "docker" "rm" "-f" "5bbc396a369c9194732c020cd95c21e0a3b6285f6b9c06d7708995fc34091b44", kill_on_drop: false }` [INFO] [stdout] 5bbc396a369c9194732c020cd95c21e0a3b6285f6b9c06d7708995fc34091b44 [INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-31/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-31/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=warn" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:b0c94ce3c1162fcb8e57cac5b65ec2f72eabb1eebea4fcc35e269e823f681646" "/opt/rustwide/cargo-home/bin/cargo" "+1.60.0" "test" "--frozen", kill_on_drop: false }` [INFO] [stdout] 5a53cb825b2d81d6fb76788a58c239bf7a4f5a13a1082da0e4d8cb6d78e927f6 [INFO] running `Command { std: "docker" "start" "-a" "5a53cb825b2d81d6fb76788a58c239bf7a4f5a13a1082da0e4d8cb6d78e927f6", kill_on_drop: false }` [INFO] [stderr] Blocking waiting for file lock on package cache [INFO] [stderr] warning: unused import: `Read` [INFO] [stderr] --> src/lockfile.rs:127:27 [INFO] [stderr] | [INFO] [stderr] 127 | use std::io::{Cursor, Read, Result, Write}; [INFO] [stderr] | ^^^^ [INFO] [stderr] | [INFO] [stderr] = note: `#[warn(unused_imports)]` on by default [INFO] [stderr] [INFO] [stderr] warning: unused import: `Write` [INFO] [stderr] --> src/lockfile.rs:127:41 [INFO] [stderr] | [INFO] [stderr] 127 | use std::io::{Cursor, Read, Result, Write}; [INFO] [stderr] | ^^^^^ [INFO] [stderr] [INFO] [stderr] warning: field is never read: `guard` [INFO] [stderr] --> src/main.rs:107:5 [INFO] [stderr] | [INFO] [stderr] 107 | guard: SemaphoreGuard<'a>, [INFO] [stderr] | ^^^^^^^^^^^^^^^^^^^^^^^^^ [INFO] [stderr] | [INFO] [stderr] = note: `#[warn(dead_code)]` on by default [INFO] [stderr] note: `Resource` has a derived impl for the trait `Debug`, but this is intentionally ignored during dead code analysis [INFO] [stderr] --> src/main.rs:103:10 [INFO] [stderr] | [INFO] [stderr] 103 | #[derive(Debug)] [INFO] [stderr] | ^^^^^ [INFO] [stderr] = note: this warning originates in the derive macro `Debug` (in Nightly builds, run with -Z macro-backtrace for more info) [INFO] [stderr] [INFO] [stderr] warning: `adp` (bin "adp" test) generated 3 warnings [INFO] [stderr] Finished test [unoptimized + debuginfo] target(s) in 3.49s [INFO] [stderr] Running unittests (/opt/rustwide/target/debug/deps/adp-c63e728017545636) [INFO] [stdout] [INFO] [stdout] running 13 tests [INFO] [stdout] test lockfile::tests::acquires_entry_none ... ok [INFO] [stdout] test lockfile::tests::acquires_entry_some ... ok [INFO] [stdout] test lockfile::tests::reads_entries ... ok [INFO] [stdout] test lockfile::tests::writes_entries ... ok [INFO] [stdout] test lockfile::tests::inserts_new_entries ... ok [INFO] [stdout] test lockfile::tests::removes_old_entries ... ok [INFO] [stdout] 2022-04-15T07:47:18.608785Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_first_time"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}: adp: try_acquire_resource start [INFO] [stdout] 2022-04-15T07:47:18.608926Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_first_time"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_first_time"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}: adp: serials=serial1 [INFO] [stdout] 2022-04-15T07:47:18.613239Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=1}: adp: try_acquire_resource start [INFO] [stdout] 2022-04-15T07:47:18.613183Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_first_time"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_first_time"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}: adp: lock_file=File { fd: 6, path: "/tmp/rstest.4/adp.lock", read: true, write: true } [INFO] [stdout] 2022-04-15T07:47:18.613385Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=1}: adp: serials=serial1,serial2 [INFO] [stdout] 2022-04-15T07:47:18.613485Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_first_time"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_first_time"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:read{reader=BufReader { reader: File { fd: 6, path: "/tmp/rstest.4/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries= [INFO] [stdout] 2022-04-15T07:47:18.613650Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_first_time"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_first_time"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:update{self=LockFileEntries({}) serials=["serial1"]}: adp::lockfile: insert=serial1 [INFO] [stdout] 2022-04-15T07:47:18.613740Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_first_time"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_first_time"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}: adp: serial=Some("serial1") entries=serial1:1 [INFO] [stdout] 2022-04-15T07:47:18.613800Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_first_time"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_first_time"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}: adp: value=0 adjust_to=1 [INFO] [stdout] 2022-04-15T07:47:18.613802Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial2"], processes: [] }, sem: Semaphore{ name: "obtains_the_correct_resource_when_device_is_removed"} , lock_file_path: "/tmp/rstest.1/adp.lock" } pid=1}: adp: try_acquire_resource start [INFO] [stdout] 2022-04-15T07:47:18.613843Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_first_time"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_first_time"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}: adp: value=1 [INFO] [stdout] 2022-04-15T07:47:18.613891Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial2"], processes: [] }, sem: Semaphore{ name: "obtains_the_correct_resource_when_device_is_removed"} , lock_file_path: "/tmp/rstest.1/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial2"], processes: [] }, sem: Semaphore{ name: "obtains_the_correct_resource_when_device_is_removed"} , lock_file_path: "/tmp/rstest.1/adp.lock" } pid=1}: adp: serials=serial2 [INFO] [stdout] 2022-04-15T07:47:18.613962Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial2"], processes: [] }, sem: Semaphore{ name: "obtains_the_correct_resource_when_device_is_removed"} , lock_file_path: "/tmp/rstest.1/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial2"], processes: [] }, sem: Semaphore{ name: "obtains_the_correct_resource_when_device_is_removed"} , lock_file_path: "/tmp/rstest.1/adp.lock" } pid=1}: adp: lock_file=File { fd: 3, path: "/tmp/rstest.1/adp.lock", read: true, write: true } [INFO] [stdout] 2022-04-15T07:47:18.614008Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_first_time"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_first_time"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:write{self=LockFileEntries({"serial1": Some(1)}) writer=BufWriter { writer: File { fd: 6, path: "/tmp/rstest.4/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=Some(1) [INFO] [stdout] 2022-04-15T07:47:18.614127Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial2"], processes: [] }, sem: Semaphore{ name: "obtains_the_correct_resource_when_device_is_removed"} , lock_file_path: "/tmp/rstest.1/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial2"], processes: [] }, sem: Semaphore{ name: "obtains_the_correct_resource_when_device_is_removed"} , lock_file_path: "/tmp/rstest.1/adp.lock" } pid=1}:read{reader=BufReader { reader: File { fd: 3, path: "/tmp/rstest.1/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1,serial2 [INFO] [stdout] 2022-04-15T07:47:18.614257Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial2"], processes: [] }, sem: Semaphore{ name: "obtains_the_correct_resource_when_device_is_removed"} , lock_file_path: "/tmp/rstest.1/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial2"], processes: [] }, sem: Semaphore{ name: "obtains_the_correct_resource_when_device_is_removed"} , lock_file_path: "/tmp/rstest.1/adp.lock" } pid=1}:update{self=LockFileEntries({"serial1": None, "serial2": None}) serials=["serial2"]}: adp::lockfile: remove=serial1 [INFO] [stdout] 2022-04-15T07:47:18.614314Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial2"], processes: [] }, sem: Semaphore{ name: "obtains_the_correct_resource_when_device_is_removed"} , lock_file_path: "/tmp/rstest.1/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial2"], processes: [] }, sem: Semaphore{ name: "obtains_the_correct_resource_when_device_is_removed"} , lock_file_path: "/tmp/rstest.1/adp.lock" } pid=1}:update{self=LockFileEntries({"serial1": None, "serial2": None}) serials=["serial2"]}: adp::lockfile: remove=serial2 [INFO] [stdout] 2022-04-15T07:47:18.614389Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_first_time"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}: adp: try_acquire_resource end [INFO] [stdout] 2022-04-15T07:47:18.614386Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial2"], processes: [] }, sem: Semaphore{ name: "obtains_the_correct_resource_when_device_is_removed"} , lock_file_path: "/tmp/rstest.1/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial2"], processes: [] }, sem: Semaphore{ name: "obtains_the_correct_resource_when_device_is_removed"} , lock_file_path: "/tmp/rstest.1/adp.lock" } pid=1}: adp: serial=Some("serial2") entries=serial2:1 [INFO] [stdout] 2022-04-15T07:47:18.614439Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial2"], processes: [] }, sem: Semaphore{ name: "obtains_the_correct_resource_when_device_is_removed"} , lock_file_path: "/tmp/rstest.1/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial2"], processes: [] }, sem: Semaphore{ name: "obtains_the_correct_resource_when_device_is_removed"} , lock_file_path: "/tmp/rstest.1/adp.lock" } pid=1}: adp: value=0 adjust_to=1 [INFO] [stdout] 2022-04-15T07:47:18.614437Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_first_time"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}: adp: resource=Some(Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_first_time"} , lock_file_path: "/tmp/rstest.4/adp.lock" }, guard: SemaphoreGuard { name: "single_device_single_run_first_time" } }) [INFO] [stdout] 2022-04-15T07:47:18.614477Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial2"], processes: [] }, sem: Semaphore{ name: "obtains_the_correct_resource_when_device_is_removed"} , lock_file_path: "/tmp/rstest.1/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial2"], processes: [] }, sem: Semaphore{ name: "obtains_the_correct_resource_when_device_is_removed"} , lock_file_path: "/tmp/rstest.1/adp.lock" } pid=1}: adp: value=1 [INFO] [stdout] 2022-04-15T07:47:18.614625Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial2"], processes: [] }, sem: Semaphore{ name: "obtains_the_correct_resource_when_device_is_removed"} , lock_file_path: "/tmp/rstest.1/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial2"], processes: [] }, sem: Semaphore{ name: "obtains_the_correct_resource_when_device_is_removed"} , lock_file_path: "/tmp/rstest.1/adp.lock" } pid=1}:write{self=LockFileEntries({"serial2": Some(1)}) writer=BufWriter { writer: File { fd: 3, path: "/tmp/rstest.1/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial2" pid=Some(1) [INFO] [stdout] 2022-04-15T07:47:18.614703Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_first_time"} , lock_file_path: "/tmp/rstest.4/adp.lock" }, guard: SemaphoreGuard { name: "single_device_single_run_first_time" } }}:read{reader=BufReader { reader: File { fd: 6, path: "/tmp/rstest.4/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1:1 [INFO] [stdout] 2022-04-15T07:47:18.614776Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_first_time"} , lock_file_path: "/tmp/rstest.4/adp.lock" }, guard: SemaphoreGuard { name: "single_device_single_run_first_time" } }}: adp: serial=serial1 entries=serial1:1 [INFO] [stdout] 2022-04-15T07:47:18.614824Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial2"], processes: [] }, sem: Semaphore{ name: "obtains_the_correct_resource_when_device_is_removed"} , lock_file_path: "/tmp/rstest.1/adp.lock" } pid=1}: adp: try_acquire_resource end [INFO] [stdout] 2022-04-15T07:47:18.614851Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_first_time"} , lock_file_path: "/tmp/rstest.4/adp.lock" }, guard: SemaphoreGuard { name: "single_device_single_run_first_time" } }}:release{self=LockFileEntries({"serial1": Some(1)}) serial="serial1"}: adp::lockfile: release=serial1 [INFO] [stdout] 2022-04-15T07:47:18.614861Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial2"], processes: [] }, sem: Semaphore{ name: "obtains_the_correct_resource_when_device_is_removed"} , lock_file_path: "/tmp/rstest.1/adp.lock" } pid=1}: adp: resource=Some(Resource { serial: "serial2", app: App { runtime: FakeRuntime { devices: ["serial2"], processes: [] }, sem: Semaphore{ name: "obtains_the_correct_resource_when_device_is_removed"} , lock_file_path: "/tmp/rstest.1/adp.lock" }, guard: SemaphoreGuard { name: "obtains_the_correct_resource_when_device_is_removed" } }) [INFO] [stdout] 2022-04-15T07:47:18.614917Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_first_time"} , lock_file_path: "/tmp/rstest.4/adp.lock" }, guard: SemaphoreGuard { name: "single_device_single_run_first_time" } }}: adp: serial=serial1 entries=serial1 [INFO] [stdout] 2022-04-15T07:47:18.615101Z DEBUG release{self=Resource { serial: "serial2", app: App { runtime: FakeRuntime { devices: ["serial2"], processes: [] }, sem: Semaphore{ name: "obtains_the_correct_resource_when_device_is_removed"} , lock_file_path: "/tmp/rstest.1/adp.lock" }, guard: SemaphoreGuard { name: "obtains_the_correct_resource_when_device_is_removed" } }}:read{reader=BufReader { reader: File { fd: 3, path: "/tmp/rstest.1/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial2:1 [INFO] [stdout] 2022-04-15T07:47:18.615170Z DEBUG release{self=Resource { serial: "serial2", app: App { runtime: FakeRuntime { devices: ["serial2"], processes: [] }, sem: Semaphore{ name: "obtains_the_correct_resource_when_device_is_removed"} , lock_file_path: "/tmp/rstest.1/adp.lock" }, guard: SemaphoreGuard { name: "obtains_the_correct_resource_when_device_is_removed" } }}: adp: serial=serial2 entries=serial2:1 [INFO] [stdout] 2022-04-15T07:47:18.615231Z DEBUG release{self=Resource { serial: "serial2", app: App { runtime: FakeRuntime { devices: ["serial2"], processes: [] }, sem: Semaphore{ name: "obtains_the_correct_resource_when_device_is_removed"} , lock_file_path: "/tmp/rstest.1/adp.lock" }, guard: SemaphoreGuard { name: "obtains_the_correct_resource_when_device_is_removed" } }}:release{self=LockFileEntries({"serial2": Some(1)}) serial="serial2"}: adp::lockfile: release=serial2 [INFO] [stdout] 2022-04-15T07:47:18.615286Z DEBUG release{self=Resource { serial: "serial2", app: App { runtime: FakeRuntime { devices: ["serial2"], processes: [] }, sem: Semaphore{ name: "obtains_the_correct_resource_when_device_is_removed"} , lock_file_path: "/tmp/rstest.1/adp.lock" }, guard: SemaphoreGuard { name: "obtains_the_correct_resource_when_device_is_removed" } }}: adp: serial=serial2 entries=serial2 [INFO] [stdout] 2022-04-15T07:47:18.613545Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=1}: adp: lock_file=File { fd: 7, path: "/tmp/rstest/adp.lock", read: true, write: true } [INFO] [stdout] 2022-04-15T07:47:18.615426Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=1}:read{reader=BufReader { reader: File { fd: 7, path: "/tmp/rstest/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries= [INFO] [stdout] 2022-04-15T07:47:18.615528Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=1}:update{self=LockFileEntries({}) serials=["serial1", "serial2"]}: adp::lockfile: insert=serial1 [INFO] [stdout] 2022-04-15T07:47:18.615580Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=1}:update{self=LockFileEntries({}) serials=["serial1", "serial2"]}: adp::lockfile: insert=serial2 [INFO] [stdout] 2022-04-15T07:47:18.615659Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=1}: adp: serial=Some("serial1") entries=serial1:1,serial2 [INFO] [stdout] 2022-04-15T07:47:18.615708Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=1}: adp: value=0 adjust_to=2 [INFO] [stdout] 2022-04-15T07:47:18.615748Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=1}: adp: value=2 [INFO] [stdout] 2022-04-15T07:47:18.615868Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=1}:write{self=LockFileEntries({"serial1": Some(1), "serial2": None}) writer=BufWriter { writer: File { fd: 7, path: "/tmp/rstest/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=Some(1) [INFO] [stdout] 2022-04-15T07:47:18.615922Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=1}:write{self=LockFileEntries({"serial1": Some(1), "serial2": None}) writer=BufWriter { writer: File { fd: 7, path: "/tmp/rstest/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial2" pid=None [INFO] [stdout] 2022-04-15T07:47:18.616065Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=1}: adp: try_acquire_resource end [INFO] [stdout] 2022-04-15T07:47:18.616100Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=1}: adp: resource=Some(Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" }, guard: SemaphoreGuard { name: "multiple_devices_multiple_runs_first_time" } }) [INFO] [stdout] 2022-04-15T07:47:18.616191Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=2}: adp: try_acquire_resource start [INFO] [stdout] 2022-04-15T07:47:18.616262Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=2}: adp: serials=serial1,serial2 [INFO] [stdout] 2022-04-15T07:47:18.616321Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=2}: adp: lock_file=File { fd: 7, path: "/tmp/rstest/adp.lock", read: true, write: true } [INFO] [stdout] 2022-04-15T07:47:18.616444Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=2}:read{reader=BufReader { reader: File { fd: 7, path: "/tmp/rstest/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1:1,serial2 [INFO] [stdout] 2022-04-15T07:47:18.616571Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=2}:update{self=LockFileEntries({"serial1": Some(1), "serial2": None}) serials=["serial1", "serial2"]}: adp::lockfile: remove=serial1 [INFO] [stdout] 2022-04-15T07:47:18.616633Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=2}:update{self=LockFileEntries({"serial1": Some(1), "serial2": None}) serials=["serial1", "serial2"]}: adp::lockfile: remove=serial2 [INFO] [stdout] 2022-04-15T07:47:18.616709Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=2}: adp: serial=Some("serial2") entries=serial1:1,serial2:2 [INFO] [stdout] 2022-04-15T07:47:18.616762Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=2}: adp: value=1 [INFO] [stdout] 2022-04-15T07:47:18.616897Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=2}:write{self=LockFileEntries({"serial1": Some(1), "serial2": Some(2)}) writer=BufWriter { writer: File { fd: 7, path: "/tmp/rstest/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=Some(1) [INFO] [stdout] 2022-04-15T07:47:18.616953Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=2}:write{self=LockFileEntries({"serial1": Some(1), "serial2": Some(2)}) writer=BufWriter { writer: File { fd: 7, path: "/tmp/rstest/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial2" pid=Some(2) [INFO] [stdout] 2022-04-15T07:47:18.616963Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_first_time"} , lock_file_path: "/tmp/rstest.4/adp.lock" }, guard: SemaphoreGuard { name: "single_device_single_run_first_time" } }}:write{self=LockFileEntries({"serial1": None}) writer=BufWriter { writer: File { fd: 6, path: "/tmp/rstest.4/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=None [INFO] [stdout] 2022-04-15T07:47:18.617083Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=2}: adp: try_acquire_resource end [INFO] [stdout] 2022-04-15T07:47:18.617122Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=2}: adp: resource=Some(Resource { serial: "serial2", app: App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" }, guard: SemaphoreGuard { name: "multiple_devices_multiple_runs_first_time" } }) [INFO] [stdout] 2022-04-15T07:47:18.617336Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" }, guard: SemaphoreGuard { name: "multiple_devices_multiple_runs_first_time" } }}:read{reader=BufReader { reader: File { fd: 6, path: "/tmp/rstest/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1:1,serial2:2 [INFO] [stdout] 2022-04-15T07:47:18.617416Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" }, guard: SemaphoreGuard { name: "multiple_devices_multiple_runs_first_time" } }}: adp: serial=serial1 entries=serial1:1,serial2:2 [INFO] [stdout] 2022-04-15T07:47:18.617485Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" }, guard: SemaphoreGuard { name: "multiple_devices_multiple_runs_first_time" } }}:release{self=LockFileEntries({"serial1": Some(1), "serial2": Some(2)}) serial="serial1"}: adp::lockfile: release=serial1 [INFO] [stdout] 2022-04-15T07:47:18.617542Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" }, guard: SemaphoreGuard { name: "multiple_devices_multiple_runs_first_time" } }}: adp: serial=serial1 entries=serial1,serial2:2 [INFO] [stdout] 2022-04-15T07:47:18.617690Z DEBUG release{self=Resource { serial: "serial2", app: App { runtime: FakeRuntime { devices: ["serial2"], processes: [] }, sem: Semaphore{ name: "obtains_the_correct_resource_when_device_is_removed"} , lock_file_path: "/tmp/rstest.1/adp.lock" }, guard: SemaphoreGuard { name: "obtains_the_correct_resource_when_device_is_removed" } }}:write{self=LockFileEntries({"serial2": None}) writer=BufWriter { writer: File { fd: 3, path: "/tmp/rstest.1/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial2" pid=None [INFO] [stdout] 2022-04-15T07:47:18.619197Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" }, guard: SemaphoreGuard { name: "multiple_devices_multiple_runs_first_time" } }}:write{self=LockFileEntries({"serial1": None, "serial2": Some(2)}) writer=BufWriter { writer: File { fd: 6, path: "/tmp/rstest/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=None [INFO] [stdout] 2022-04-15T07:47:18.619273Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" }, guard: SemaphoreGuard { name: "multiple_devices_multiple_runs_first_time" } }}:write{self=LockFileEntries({"serial1": None, "serial2": Some(2)}) writer=BufWriter { writer: File { fd: 6, path: "/tmp/rstest/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial2" pid=Some(2) [INFO] [stdout] 2022-04-15T07:47:18.619375Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "obtains_resource_if_process_is_no_longer_running"} , lock_file_path: "/tmp/rstest.2/adp.lock" } pid=2}: adp: try_acquire_resource start [INFO] [stdout] 2022-04-15T07:47:18.619503Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "obtains_resource_if_process_is_no_longer_running"} , lock_file_path: "/tmp/rstest.2/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "obtains_resource_if_process_is_no_longer_running"} , lock_file_path: "/tmp/rstest.2/adp.lock" } pid=2}: adp: serials=serial1 [INFO] [stdout] 2022-04-15T07:47:18.619590Z DEBUG release{self=Resource { serial: "serial2", app: App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" }, guard: SemaphoreGuard { name: "multiple_devices_multiple_runs_first_time" } }}:read{reader=BufReader { reader: File { fd: 4, path: "/tmp/rstest/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1,serial2:2 [INFO] [stdout] 2022-04-15T07:47:18.619584Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "obtains_resource_if_process_is_no_longer_running"} , lock_file_path: "/tmp/rstest.2/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "obtains_resource_if_process_is_no_longer_running"} , lock_file_path: "/tmp/rstest.2/adp.lock" } pid=2}: adp: lock_file=File { fd: 6, path: "/tmp/rstest.2/adp.lock", read: true, write: true } [INFO] [stdout] 2022-04-15T07:47:18.619672Z DEBUG release{self=Resource { serial: "serial2", app: App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" }, guard: SemaphoreGuard { name: "multiple_devices_multiple_runs_first_time" } }}: adp: serial=serial2 entries=serial1,serial2:2 [INFO] [stdout] 2022-04-15T07:47:18.619737Z DEBUG release{self=Resource { serial: "serial2", app: App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" }, guard: SemaphoreGuard { name: "multiple_devices_multiple_runs_first_time" } }}:release{self=LockFileEntries({"serial1": None, "serial2": Some(2)}) serial="serial2"}: adp::lockfile: release=serial2 [INFO] [stdout] 2022-04-15T07:47:18.619772Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "obtains_resource_if_process_is_no_longer_running"} , lock_file_path: "/tmp/rstest.2/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "obtains_resource_if_process_is_no_longer_running"} , lock_file_path: "/tmp/rstest.2/adp.lock" } pid=2}:read{reader=BufReader { reader: File { fd: 6, path: "/tmp/rstest.2/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1:1 [INFO] [stdout] 2022-04-15T07:47:18.619916Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "obtains_resource_if_process_is_no_longer_running"} , lock_file_path: "/tmp/rstest.2/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "obtains_resource_if_process_is_no_longer_running"} , lock_file_path: "/tmp/rstest.2/adp.lock" } pid=2}:update{self=LockFileEntries({"serial1": Some(1)}) serials=["serial1"]}: adp::lockfile: remove=serial1 [INFO] [stdout] 2022-04-15T07:47:18.620011Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "obtains_resource_if_process_is_no_longer_running"} , lock_file_path: "/tmp/rstest.2/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "obtains_resource_if_process_is_no_longer_running"} , lock_file_path: "/tmp/rstest.2/adp.lock" } pid=2}: adp: check=serial1 [INFO] [stdout] 2022-04-15T07:47:18.620088Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "obtains_resource_if_process_is_no_longer_running"} , lock_file_path: "/tmp/rstest.2/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "obtains_resource_if_process_is_no_longer_running"} , lock_file_path: "/tmp/rstest.2/adp.lock" } pid=2}:release{self=LockFileEntries({"serial1": Some(1)}) serial="serial1"}: adp::lockfile: release=serial1 [INFO] [stdout] 2022-04-15T07:47:18.620170Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "obtains_resource_if_process_is_no_longer_running"} , lock_file_path: "/tmp/rstest.2/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "obtains_resource_if_process_is_no_longer_running"} , lock_file_path: "/tmp/rstest.2/adp.lock" } pid=2}: adp: serial=Some("serial1") entries=serial1:2 [INFO] [stdout] 2022-04-15T07:47:18.620220Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "obtains_resource_if_process_is_no_longer_running"} , lock_file_path: "/tmp/rstest.2/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "obtains_resource_if_process_is_no_longer_running"} , lock_file_path: "/tmp/rstest.2/adp.lock" } pid=2}: adp: value=0 adjust_to=1 [INFO] [stdout] 2022-04-15T07:47:18.620261Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "obtains_resource_if_process_is_no_longer_running"} , lock_file_path: "/tmp/rstest.2/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "obtains_resource_if_process_is_no_longer_running"} , lock_file_path: "/tmp/rstest.2/adp.lock" } pid=2}: adp: value=1 [INFO] [stdout] 2022-04-15T07:47:18.620394Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "obtains_resource_if_process_is_no_longer_running"} , lock_file_path: "/tmp/rstest.2/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "obtains_resource_if_process_is_no_longer_running"} , lock_file_path: "/tmp/rstest.2/adp.lock" } pid=2}:write{self=LockFileEntries({"serial1": Some(2)}) writer=BufWriter { writer: File { fd: 6, path: "/tmp/rstest.2/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=Some(2) [INFO] [stdout] 2022-04-15T07:47:18.619798Z DEBUG release{self=Resource { serial: "serial2", app: App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" }, guard: SemaphoreGuard { name: "multiple_devices_multiple_runs_first_time" } }}: adp: serial=serial2 entries=serial1,serial2 [INFO] [stdout] 2022-04-15T07:47:18.620588Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "obtains_resource_if_process_is_no_longer_running"} , lock_file_path: "/tmp/rstest.2/adp.lock" } pid=2}: adp: try_acquire_resource end [INFO] [stdout] 2022-04-15T07:47:18.620624Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "obtains_resource_if_process_is_no_longer_running"} , lock_file_path: "/tmp/rstest.2/adp.lock" } pid=2}: adp: resource=Some(Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "obtains_resource_if_process_is_no_longer_running"} , lock_file_path: "/tmp/rstest.2/adp.lock" }, guard: SemaphoreGuard { name: "obtains_resource_if_process_is_no_longer_running" } }) [INFO] [stdout] 2022-04-15T07:47:18.623283Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=1}: adp: try_acquire_resource start [INFO] [stdout] 2022-04-15T07:47:18.623427Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=1}: adp: serials=serial1 [INFO] [stdout] 2022-04-15T07:47:18.623573Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=1}: adp: lock_file=File { fd: 5, path: "/tmp/rstest.3/adp.lock", read: true, write: true } [INFO] [stdout] 2022-04-15T07:47:18.623733Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=1}:read{reader=BufReader { reader: File { fd: 5, path: "/tmp/rstest.3/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries= [INFO] [stdout] 2022-04-15T07:47:18.623853Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=1}:update{self=LockFileEntries({}) serials=["serial1"]}: adp::lockfile: insert=serial1 [INFO] [stdout] 2022-04-15T07:47:18.623933Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=1}: adp: serial=Some("serial1") entries=serial1:1 [INFO] [stdout] 2022-04-15T07:47:18.623988Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=1}: adp: value=0 adjust_to=1 [INFO] [stdout] 2022-04-15T07:47:18.624031Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=1}: adp: value=1 [INFO] [stdout] 2022-04-15T07:47:18.624171Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=1}:write{self=LockFileEntries({"serial1": Some(1)}) writer=BufWriter { writer: File { fd: 5, path: "/tmp/rstest.3/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=Some(1) [INFO] [stdout] 2022-04-15T07:47:18.625554Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_second_time"} , lock_file_path: "/tmp/rstest.5/adp.lock" } pid=1}: adp: try_acquire_resource start [INFO] [stdout] 2022-04-15T07:47:18.625651Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_second_time"} , lock_file_path: "/tmp/rstest.5/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_second_time"} , lock_file_path: "/tmp/rstest.5/adp.lock" } pid=1}: adp: serials=serial1 [INFO] [stdout] 2022-04-15T07:47:18.625716Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_second_time"} , lock_file_path: "/tmp/rstest.5/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_second_time"} , lock_file_path: "/tmp/rstest.5/adp.lock" } pid=1}: adp: lock_file=File { fd: 7, path: "/tmp/rstest.5/adp.lock", read: true, write: true } [INFO] [stdout] 2022-04-15T07:47:18.625854Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_second_time"} , lock_file_path: "/tmp/rstest.5/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_second_time"} , lock_file_path: "/tmp/rstest.5/adp.lock" } pid=1}:read{reader=BufReader { reader: File { fd: 7, path: "/tmp/rstest.5/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1 [INFO] [stdout] 2022-04-15T07:47:18.625974Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_second_time"} , lock_file_path: "/tmp/rstest.5/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_second_time"} , lock_file_path: "/tmp/rstest.5/adp.lock" } pid=1}:update{self=LockFileEntries({"serial1": None}) serials=["serial1"]}: adp::lockfile: remove=serial1 [INFO] [stdout] 2022-04-15T07:47:18.626053Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_second_time"} , lock_file_path: "/tmp/rstest.5/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_second_time"} , lock_file_path: "/tmp/rstest.5/adp.lock" } pid=1}: adp: serial=Some("serial1") entries=serial1:1 [INFO] [stdout] 2022-04-15T07:47:18.626106Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_second_time"} , lock_file_path: "/tmp/rstest.5/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_second_time"} , lock_file_path: "/tmp/rstest.5/adp.lock" } pid=1}: adp: value=0 adjust_to=1 [INFO] [stdout] 2022-04-15T07:47:18.626152Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_second_time"} , lock_file_path: "/tmp/rstest.5/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_second_time"} , lock_file_path: "/tmp/rstest.5/adp.lock" } pid=1}: adp: value=1 [INFO] [stdout] 2022-04-15T07:47:18.626277Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_second_time"} , lock_file_path: "/tmp/rstest.5/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_second_time"} , lock_file_path: "/tmp/rstest.5/adp.lock" } pid=1}:write{self=LockFileEntries({"serial1": Some(1)}) writer=BufWriter { writer: File { fd: 7, path: "/tmp/rstest.5/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=Some(1) [INFO] [stdout] 2022-04-15T07:47:18.626542Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}: adp: try_acquire_resource start [INFO] [stdout] 2022-04-15T07:47:18.626646Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}: adp: serials=serial1 [INFO] [stdout] 2022-04-15T07:47:18.626742Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}: adp: lock_file=File { fd: 5, path: "/tmp/rstest.4/adp.lock", read: true, write: true } [INFO] [stdout] 2022-04-15T07:47:18.626875Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:read{reader=BufReader { reader: File { fd: 5, path: "/tmp/rstest.4/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries= [INFO] [stdout] test tests::single_device_single_run_first_time ... ok [INFO] [stdout] test tests::obtains_the_correct_resource_when_device_is_removed ... ok [INFO] [stdout] 2022-04-15T07:47:18.631095Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:update{self=LockFileEntries({}) serials=["serial1"]}: adp::lockfile: insert=serial1 [INFO] [stdout] 2022-04-15T07:47:18.631266Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}: adp: serial=Some("serial1") entries=serial1:1 [INFO] [stdout] 2022-04-15T07:47:18.631342Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}: adp: value=0 adjust_to=1 [INFO] [stdout] 2022-04-15T07:47:18.631396Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}: adp: value=1 [INFO] [stdout] 2022-04-15T07:47:18.631619Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:write{self=LockFileEntries({"serial1": Some(1)}) writer=BufWriter { writer: File { fd: 5, path: "/tmp/rstest.4/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=Some(1) [INFO] [stdout] 2022-04-15T07:47:18.643735Z DEBUG release{self=Resource { serial: "serial2", app: App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" }, guard: SemaphoreGuard { name: "multiple_devices_multiple_runs_first_time" } }}:write{self=LockFileEntries({"serial1": None, "serial2": None}) writer=BufWriter { writer: File { fd: 4, path: "/tmp/rstest/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=None [INFO] [stdout] 2022-04-15T07:47:18.643832Z DEBUG release{self=Resource { serial: "serial2", app: App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" }, guard: SemaphoreGuard { name: "multiple_devices_multiple_runs_first_time" } }}:write{self=LockFileEntries({"serial1": None, "serial2": None}) writer=BufWriter { writer: File { fd: 4, path: "/tmp/rstest/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial2" pid=None [INFO] [stdout] test tests::obtains_resource_if_process_is_no_longer_running ... ok [INFO] [stdout] 2022-04-15T07:47:18.674192Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_second_time"} , lock_file_path: "/tmp/rstest.5/adp.lock" } pid=1}: adp: try_acquire_resource end [INFO] [stdout] 2022-04-15T07:47:18.674285Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_second_time"} , lock_file_path: "/tmp/rstest.5/adp.lock" } pid=1}: adp: resource=Some(Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_second_time"} , lock_file_path: "/tmp/rstest.5/adp.lock" }, guard: SemaphoreGuard { name: "single_device_single_run_second_time" } }) [INFO] [stdout] 2022-04-15T07:47:18.674682Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_second_time"} , lock_file_path: "/tmp/rstest.5/adp.lock" }, guard: SemaphoreGuard { name: "single_device_single_run_second_time" } }}:read{reader=BufReader { reader: File { fd: 4, path: "/tmp/rstest.5/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1:1 [INFO] [stdout] 2022-04-15T07:47:18.674772Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_second_time"} , lock_file_path: "/tmp/rstest.5/adp.lock" }, guard: SemaphoreGuard { name: "single_device_single_run_second_time" } }}: adp: serial=serial1 entries=serial1:1 [INFO] [stdout] 2022-04-15T07:47:18.674837Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_second_time"} , lock_file_path: "/tmp/rstest.5/adp.lock" }, guard: SemaphoreGuard { name: "single_device_single_run_second_time" } }}:release{self=LockFileEntries({"serial1": Some(1)}) serial="serial1"}: adp::lockfile: release=serial1 [INFO] [stdout] 2022-04-15T07:47:18.674900Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_second_time"} , lock_file_path: "/tmp/rstest.5/adp.lock" }, guard: SemaphoreGuard { name: "single_device_single_run_second_time" } }}: adp: serial=serial1 entries=serial1 [INFO] [stdout] 2022-04-15T07:47:18.675059Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=1}: adp: try_acquire_resource end [INFO] [stdout] 2022-04-15T07:47:18.675096Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=1}: adp: resource=Some(Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" }, guard: SemaphoreGuard { name: "resource_blocks_until_one_is_released" } }) [INFO] [stdout] 2022-04-15T07:47:18.675319Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}: adp: try_acquire_resource end [INFO] [stdout] 2022-04-15T07:47:18.675375Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}: adp: resource=Some(Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }) [INFO] [stdout] 2022-04-15T07:47:18.675596Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }}:read{reader=BufReader { reader: File { fd: 3, path: "/tmp/rstest.4/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1:1 [INFO] [stdout] 2022-04-15T07:47:18.675676Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }}: adp: serial=serial1 entries=serial1:1 [INFO] [stdout] 2022-04-15T07:47:18.675742Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }}:release{self=LockFileEntries({"serial1": Some(1)}) serial="serial1"}: adp::lockfile: release=serial1 [INFO] [stdout] 2022-04-15T07:47:18.675801Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }}: adp: serial=serial1 entries=serial1 [INFO] [stdout] 2022-04-15T07:47:18.676092Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_second_time"} , lock_file_path: "/tmp/rstest.5/adp.lock" }, guard: SemaphoreGuard { name: "single_device_single_run_second_time" } }}:write{self=LockFileEntries({"serial1": None}) writer=BufWriter { writer: File { fd: 4, path: "/tmp/rstest.5/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=None [INFO] [stdout] test tests::multiple_devices_multiple_runs_first_time ... ok [INFO] [stdout] 2022-04-15T07:47:18.698691Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}: adp: try_acquire_resource start [INFO] [stdout] 2022-04-15T07:47:18.698799Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}: adp: serials=serial1 [INFO] [stdout] 2022-04-15T07:47:18.698875Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}: adp: lock_file=File { fd: 5, path: "/tmp/rstest.3/adp.lock", read: true, write: true } [INFO] [stdout] 2022-04-15T07:47:18.716151Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}:read{reader=BufReader { reader: File { fd: 5, path: "/tmp/rstest.3/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1:1 [INFO] [stdout] 2022-04-15T07:47:18.716389Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}:update{self=LockFileEntries({"serial1": Some(1)}) serials=["serial1"]}: adp::lockfile: remove=serial1 [INFO] [stdout] 2022-04-15T07:47:18.716483Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}: adp: check=serial1 [INFO] [stdout] 2022-04-15T07:47:18.716531Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}: adp: serial=None entries=serial1:1 [INFO] [stdout] 2022-04-15T07:47:18.716572Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}: adp: value=0 [INFO] [stdout] 2022-04-15T07:47:18.718755Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }}:write{self=LockFileEntries({"serial1": None}) writer=BufWriter { writer: File { fd: 3, path: "/tmp/rstest.4/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=None [INFO] [stdout] 2022-04-15T07:47:18.719258Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}: adp: try_acquire_resource start [INFO] [stdout] 2022-04-15T07:47:18.719358Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}: adp: serials=serial1 [INFO] [stdout] 2022-04-15T07:47:18.719449Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}: adp: lock_file=File { fd: 3, path: "/tmp/rstest.4/adp.lock", read: true, write: true } [INFO] [stdout] 2022-04-15T07:47:18.719618Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:read{reader=BufReader { reader: File { fd: 3, path: "/tmp/rstest.4/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1 [INFO] [stdout] 2022-04-15T07:47:18.719730Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:update{self=LockFileEntries({"serial1": None}) serials=["serial1"]}: adp::lockfile: remove=serial1 [INFO] [stdout] 2022-04-15T07:47:18.719808Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}: adp: serial=Some("serial1") entries=serial1:1 [INFO] [stdout] 2022-04-15T07:47:18.719855Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}: adp: value=1 [INFO] [stdout] 2022-04-15T07:47:18.727117Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:write{self=LockFileEntries({"serial1": Some(1)}) writer=BufWriter { writer: File { fd: 3, path: "/tmp/rstest.4/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=Some(1) [INFO] [stdout] 2022-04-15T07:47:18.727388Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}: adp: try_acquire_resource end [INFO] [stdout] 2022-04-15T07:47:18.727431Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}: adp: resource=Some(Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }) [INFO] [stdout] 2022-04-15T07:47:18.727690Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }}:read{reader=BufReader { reader: File { fd: 3, path: "/tmp/rstest.4/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1:1 [INFO] [stdout] 2022-04-15T07:47:18.727773Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }}: adp: serial=serial1 entries=serial1:1 [INFO] [stdout] 2022-04-15T07:47:18.727850Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }}:release{self=LockFileEntries({"serial1": Some(1)}) serial="serial1"}: adp::lockfile: release=serial1 [INFO] [stdout] 2022-04-15T07:47:18.727919Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }}: adp: serial=serial1 entries=serial1 [INFO] [stdout] test tests::single_device_single_run_second_time ... ok [INFO] [stdout] 2022-04-15T07:47:18.735959Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }}:write{self=LockFileEntries({"serial1": None}) writer=BufWriter { writer: File { fd: 3, path: "/tmp/rstest.4/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=None [INFO] [stdout] 2022-04-15T07:47:18.742821Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}: adp: try_acquire_resource start [INFO] [stdout] 2022-04-15T07:47:18.742928Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}: adp: serials=serial1 [INFO] [stdout] 2022-04-15T07:47:18.743055Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}: adp: lock_file=File { fd: 3, path: "/tmp/rstest.4/adp.lock", read: true, write: true } [INFO] [stdout] 2022-04-15T07:47:18.743374Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:read{reader=BufReader { reader: File { fd: 3, path: "/tmp/rstest.4/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1 [INFO] [stdout] 2022-04-15T07:47:18.743529Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:update{self=LockFileEntries({"serial1": None}) serials=["serial1"]}: adp::lockfile: remove=serial1 [INFO] [stdout] 2022-04-15T07:47:18.743613Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}: adp: serial=Some("serial1") entries=serial1:1 [INFO] [stdout] 2022-04-15T07:47:18.743666Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}: adp: value=1 [INFO] [stdout] 2022-04-15T07:47:18.743850Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:write{self=LockFileEntries({"serial1": Some(1)}) writer=BufWriter { writer: File { fd: 3, path: "/tmp/rstest.4/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=Some(1) [INFO] [stdout] 2022-04-15T07:47:18.744067Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}: adp: try_acquire_resource end [INFO] [stdout] 2022-04-15T07:47:18.744109Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}: adp: resource=Some(Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }) [INFO] [stdout] 2022-04-15T07:47:18.744312Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }}:read{reader=BufReader { reader: File { fd: 3, path: "/tmp/rstest.4/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1:1 [INFO] [stdout] 2022-04-15T07:47:18.744388Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }}: adp: serial=serial1 entries=serial1:1 [INFO] [stdout] 2022-04-15T07:47:18.744458Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }}:release{self=LockFileEntries({"serial1": Some(1)}) serial="serial1"}: adp::lockfile: release=serial1 [INFO] [stdout] 2022-04-15T07:47:18.744522Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }}: adp: serial=serial1 entries=serial1 [INFO] [stdout] 2022-04-15T07:47:18.771902Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }}:write{self=LockFileEntries({"serial1": None}) writer=BufWriter { writer: File { fd: 3, path: "/tmp/rstest.4/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=None [INFO] [stdout] test tests::single_device_three_runs ... ok [INFO] [stdout] 2022-04-15T07:47:19.198197Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" }, guard: SemaphoreGuard { name: "resource_blocks_until_one_is_released" } }}:read{reader=BufReader { reader: File { fd: 3, path: "/tmp/rstest.3/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1:1 [INFO] [stdout] 2022-04-15T07:47:19.198302Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" }, guard: SemaphoreGuard { name: "resource_blocks_until_one_is_released" } }}: adp: serial=serial1 entries=serial1:1 [INFO] [stdout] 2022-04-15T07:47:19.198363Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" }, guard: SemaphoreGuard { name: "resource_blocks_until_one_is_released" } }}:release{self=LockFileEntries({"serial1": Some(1)}) serial="serial1"}: adp::lockfile: release=serial1 [INFO] [stdout] 2022-04-15T07:47:19.198418Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" }, guard: SemaphoreGuard { name: "resource_blocks_until_one_is_released" } }}: adp: serial=serial1 entries=serial1 [INFO] [stdout] 2022-04-15T07:47:19.198580Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" }, guard: SemaphoreGuard { name: "resource_blocks_until_one_is_released" } }}:write{self=LockFileEntries({"serial1": None}) writer=BufWriter { writer: File { fd: 3, path: "/tmp/rstest.3/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=None [INFO] [stdout] 2022-04-15T07:47:19.200922Z DEBUG adp::tests: sem=1 [INFO] [stdout] 2022-04-15T07:47:19.201065Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}: adp: try_acquire_resource end [INFO] [stdout] 2022-04-15T07:47:19.201141Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}: adp: resource=None [INFO] [stdout] 2022-04-15T07:47:19.201169Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}: adp: try_acquire_resource start [INFO] [stdout] 2022-04-15T07:47:19.201262Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}: adp: serials=serial1 [INFO] [stdout] 2022-04-15T07:47:19.201365Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}: adp: lock_file=File { fd: 3, path: "/tmp/rstest.3/adp.lock", read: true, write: true } [INFO] [stdout] 2022-04-15T07:47:19.201546Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}:read{reader=BufReader { reader: File { fd: 3, path: "/tmp/rstest.3/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1 [INFO] [stdout] 2022-04-15T07:47:19.201650Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}:update{self=LockFileEntries({"serial1": None}) serials=["serial1"]}: adp::lockfile: remove=serial1 [INFO] [stdout] 2022-04-15T07:47:19.201723Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}: adp: serial=Some("serial1") entries=serial1:2 [INFO] [stdout] 2022-04-15T07:47:19.201766Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}: adp: value=1 [INFO] [stdout] 2022-04-15T07:47:19.204250Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}:write{self=LockFileEntries({"serial1": Some(2)}) writer=BufWriter { writer: File { fd: 3, path: "/tmp/rstest.3/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=Some(2) [INFO] [stdout] 2022-04-15T07:47:19.218952Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}: adp: try_acquire_resource end [INFO] [stdout] 2022-04-15T07:47:19.219116Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}: adp: resource=Some(Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" }, guard: SemaphoreGuard { name: "resource_blocks_until_one_is_released" } }) [INFO] [stdout] 2022-04-15T07:47:19.219201Z DEBUG adp::tests: send=serial1 [INFO] [stdout] 2022-04-15T07:47:19.226196Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" }, guard: SemaphoreGuard { name: "resource_blocks_until_one_is_released" } }}:read{reader=BufReader { reader: File { fd: 3, path: "/tmp/rstest.3/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1:2 [INFO] [stdout] 2022-04-15T07:47:19.226370Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" }, guard: SemaphoreGuard { name: "resource_blocks_until_one_is_released" } }}: adp: serial=serial1 entries=serial1:2 [INFO] [stdout] 2022-04-15T07:47:19.226463Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" }, guard: SemaphoreGuard { name: "resource_blocks_until_one_is_released" } }}:release{self=LockFileEntries({"serial1": Some(2)}) serial="serial1"}: adp::lockfile: release=serial1 [INFO] [stdout] 2022-04-15T07:47:19.226541Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" }, guard: SemaphoreGuard { name: "resource_blocks_until_one_is_released" } }}: adp: serial=serial1 entries=serial1 [INFO] [stdout] 2022-04-15T07:47:19.226757Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" }, guard: SemaphoreGuard { name: "resource_blocks_until_one_is_released" } }}:write{self=LockFileEntries({"serial1": None}) writer=BufWriter { writer: File { fd: 3, path: "/tmp/rstest.3/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=None [INFO] [stdout] test tests::resource_blocks_until_one_is_released ... ok [INFO] [stdout] [INFO] [stdout] test result: ok. 13 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.64s [INFO] [stdout] [INFO] running `Command { std: "docker" "inspect" "5a53cb825b2d81d6fb76788a58c239bf7a4f5a13a1082da0e4d8cb6d78e927f6", kill_on_drop: false }` [INFO] running `Command { std: "docker" "rm" "-f" "5a53cb825b2d81d6fb76788a58c239bf7a4f5a13a1082da0e4d8cb6d78e927f6", kill_on_drop: false }` [INFO] [stdout] 5a53cb825b2d81d6fb76788a58c239bf7a4f5a13a1082da0e4d8cb6d78e927f6