[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.59.0 for beta-1.60-1 [INFO] running `Command { std: "git" "clone" "/workspace/cache/git-repos/https%3A%2F%2Fgithub.com%2Fevant%2Fadp" "/workspace/builds/worker-3/source", kill_on_drop: false }` [INFO] [stderr] Cloning into '/workspace/builds/worker-3/source'... [INFO] [stderr] done. [INFO] validating manifest of git repo https://github.com/evant/adp on toolchain 1.59.0 [INFO] running `Command { std: "/workspace/cargo-home/bin/cargo" "+1.59.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-3/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.59.0" "fetch" "--manifest-path" "Cargo.toml", kill_on_drop: false }` [INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-3/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-3/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:0cd99ca24d8e8c98e67c542213511d985b8778b5bdcbb160e038429496686047" "/opt/rustwide/cargo-home/bin/cargo" "+1.59.0" "metadata" "--no-deps" "--format-version=1", kill_on_drop: false }` [INFO] [stderr] WARNING: Your kernel does not support swap limit capabilities or the cgroup is not mounted. Memory limited without swap. [INFO] [stdout] fa2cb3717b93245f1e98bc27f83c3a61bf00b972bd2775a8a52e59e17c60cf4b [INFO] running `Command { std: "docker" "start" "-a" "fa2cb3717b93245f1e98bc27f83c3a61bf00b972bd2775a8a52e59e17c60cf4b", kill_on_drop: false }` [INFO] running `Command { std: "docker" "inspect" "fa2cb3717b93245f1e98bc27f83c3a61bf00b972bd2775a8a52e59e17c60cf4b", kill_on_drop: false }` [INFO] running `Command { std: "docker" "rm" "-f" "fa2cb3717b93245f1e98bc27f83c3a61bf00b972bd2775a8a52e59e17c60cf4b", kill_on_drop: false }` [INFO] [stdout] fa2cb3717b93245f1e98bc27f83c3a61bf00b972bd2775a8a52e59e17c60cf4b [INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-3/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-3/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:0cd99ca24d8e8c98e67c542213511d985b8778b5bdcbb160e038429496686047" "/opt/rustwide/cargo-home/bin/cargo" "+1.59.0" "build" "--frozen" "--message-format=json", kill_on_drop: false }` [INFO] [stdout] 8bdb6ff25cb7263c7a39fae98807bdd5121f3cef21e0679ae310468c5246210a [INFO] [stderr] WARNING: Your kernel does not support swap limit capabilities or the cgroup is not mounted. Memory limited without swap. [INFO] running `Command { std: "docker" "start" "-a" "8bdb6ff25cb7263c7a39fae98807bdd5121f3cef21e0679ae310468c5246210a", kill_on_drop: false }` [INFO] [stderr] Compiling sysinfo v0.20.5 [INFO] [stderr] Compiling tracing-subscriber v0.2.25 [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 thiserror-impl v1.0.30 [INFO] [stderr] Compiling ambassador v0.2.1 [INFO] [stderr] Compiling retry v1.3.0 [INFO] [stderr] Compiling rayon-core v1.9.1 [INFO] [stderr] Compiling dirs v4.0.0 [INFO] [stderr] Compiling rayon v1.5.1 [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] [INFO] [stdout] [INFO] [stdout] warning: 1 warning emitted [INFO] [stdout] [INFO] [stdout] [INFO] [stderr] Finished dev [unoptimized + debuginfo] target(s) in 29.78s [INFO] running `Command { std: "docker" "inspect" "8bdb6ff25cb7263c7a39fae98807bdd5121f3cef21e0679ae310468c5246210a", kill_on_drop: false }` [INFO] running `Command { std: "docker" "rm" "-f" "8bdb6ff25cb7263c7a39fae98807bdd5121f3cef21e0679ae310468c5246210a", kill_on_drop: false }` [INFO] [stdout] 8bdb6ff25cb7263c7a39fae98807bdd5121f3cef21e0679ae310468c5246210a [INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-3/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-3/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:0cd99ca24d8e8c98e67c542213511d985b8778b5bdcbb160e038429496686047" "/opt/rustwide/cargo-home/bin/cargo" "+1.59.0" "test" "--frozen" "--no-run" "--message-format=json", kill_on_drop: false }` [INFO] [stderr] WARNING: Your kernel does not support swap limit capabilities or the cgroup is not mounted. Memory limited without swap. [INFO] [stdout] 552db8f372e2835f076423373369d56013df75c595c32f116029545287210459 [INFO] running `Command { std: "docker" "start" "-a" "552db8f372e2835f076423373369d56013df75c595c32f116029545287210459", kill_on_drop: false }` [INFO] [stderr] Compiling syn v0.15.44 [INFO] [stderr] Compiling try-block v0.1.0 [INFO] [stderr] Compiling quote v0.6.13 [INFO] [stderr] Compiling darling_core v0.12.4 [INFO] [stderr] Compiling darling_macro v0.12.4 [INFO] [stderr] Compiling darling v0.12.4 [INFO] [stderr] Compiling derive_builder_core v0.10.2 [INFO] [stderr] Compiling function_name-proc-macro v0.2.0 [INFO] [stderr] Compiling derive_builder_macro v0.10.2 [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] [INFO] [stdout] [INFO] [stdout] warning: 3 warnings emitted [INFO] [stdout] [INFO] [stdout] [INFO] [stderr] Finished test [unoptimized + debuginfo] target(s) in 24.88s [INFO] running `Command { std: "docker" "inspect" "552db8f372e2835f076423373369d56013df75c595c32f116029545287210459", kill_on_drop: false }` [INFO] running `Command { std: "docker" "rm" "-f" "552db8f372e2835f076423373369d56013df75c595c32f116029545287210459", kill_on_drop: false }` [INFO] [stdout] 552db8f372e2835f076423373369d56013df75c595c32f116029545287210459 [INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-3/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-3/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:0cd99ca24d8e8c98e67c542213511d985b8778b5bdcbb160e038429496686047" "/opt/rustwide/cargo-home/bin/cargo" "+1.59.0" "test" "--frozen", kill_on_drop: false }` [INFO] [stderr] WARNING: Your kernel does not support swap limit capabilities or the cgroup is not mounted. Memory limited without swap. [INFO] [stdout] 4c1d2480f13b36846312349535727e6f588acc87f3eedea0da60be9b51fa731f [INFO] running `Command { std: "docker" "start" "-a" "4c1d2480f13b36846312349535727e6f588acc87f3eedea0da60be9b51fa731f", kill_on_drop: false }` [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] [INFO] [stderr] warning: `adp` (bin "adp" test) generated 3 warnings [INFO] [stderr] Finished test [unoptimized + debuginfo] target(s) in 0.13s [INFO] [stderr] Running unittests (/opt/rustwide/target/debug/deps/adp-78be96ef89b78a05) [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::removes_old_entries ... ok [INFO] [stdout] test lockfile::tests::inserts_new_entries ... ok [INFO] [stdout] test lockfile::tests::writes_entries ... ok [INFO] [stdout] 2022-02-28T06:34:22.736905Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=1}: adp: try_acquire_resource start [INFO] [stdout] 2022-02-28T06:34:22.737011Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest/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/adp.lock" } pid=1}: adp: serials=serial1 [INFO] [stdout] 2022-02-28T06:34:22.737111Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest/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/adp.lock" } pid=1}: adp: lock_file=File { fd: 3, path: "/tmp/rstest/adp.lock", read: true, write: true } [INFO] [stdout] 2022-02-28T06:34:22.737273Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest/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/adp.lock" } pid=1}:read{reader=BufReader { reader: File { fd: 3, path: "/tmp/rstest/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries= [INFO] [stdout] 2022-02-28T06:34:22.737379Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest/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/adp.lock" } pid=1}:update{self=LockFileEntries({}) serials=["serial1"]}: adp::lockfile: insert=serial1 [INFO] [stdout] 2022-02-28T06:34:22.737447Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest/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/adp.lock" } pid=1}: adp: serial=Some("serial1") entries=serial1:1 [INFO] [stdout] 2022-02-28T06:34:22.737493Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest/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/adp.lock" } pid=1}: adp: value=0 adjust_to=1 [INFO] [stdout] 2022-02-28T06:34:22.737530Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest/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/adp.lock" } pid=1}: adp: value=1 [INFO] [stdout] 2022-02-28T06:34:22.737659Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest/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/adp.lock" } pid=1}:write{self=LockFileEntries({"serial1": Some(1)}) writer=BufWriter { writer: File { fd: 3, path: "/tmp/rstest/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=Some(1) [INFO] [stdout] 2022-02-28T06:34:22.737817Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=1}: adp: try_acquire_resource end [INFO] [stdout] 2022-02-28T06:34:22.737852Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest/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/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }) [INFO] [stdout] 2022-02-28T06:34:22.738805Z 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.2/adp.lock" } pid=1}: adp: try_acquire_resource start [INFO] [stdout] 2022-02-28T06:34:22.738857Z 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/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }}:read{reader=BufReader { reader: File { fd: 4, path: "/tmp/rstest/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1:1 [INFO] [stdout] 2022-02-28T06:34:22.738898Z 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.2/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.2/adp.lock" } pid=1}: adp: serials=serial2 [INFO] [stdout] 2022-02-28T06:34:22.738924Z 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/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }}: adp: serial=serial1 entries=serial1:1 [INFO] [stdout] 2022-02-28T06:34:22.738949Z 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.2/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.2/adp.lock" } pid=1}: adp: lock_file=File { fd: 5, path: "/tmp/rstest.2/adp.lock", read: true, write: true } [INFO] [stdout] 2022-02-28T06:34:22.738986Z 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/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }}:release{self=LockFileEntries({"serial1": Some(1)}) serial="serial1"}: adp::lockfile: release=serial1 [INFO] [stdout] 2022-02-28T06:34:22.739040Z 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/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }}: adp: serial=serial1 entries=serial1 [INFO] [stdout] 2022-02-28T06:34:22.739068Z 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.2/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.2/adp.lock" } pid=1}:read{reader=BufReader { reader: File { fd: 5, path: "/tmp/rstest.2/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1,serial2 [INFO] [stdout] 2022-02-28T06:34:22.739152Z 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/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }}:write{self=LockFileEntries({"serial1": 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-02-28T06:34:22.739157Z 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.2/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.2/adp.lock" } pid=1}:update{self=LockFileEntries({"serial1": None, "serial2": None}) serials=["serial2"]}: adp::lockfile: remove=serial1 [INFO] [stdout] 2022-02-28T06:34:22.739199Z 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.2/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.2/adp.lock" } pid=1}:update{self=LockFileEntries({"serial1": None, "serial2": None}) serials=["serial2"]}: adp::lockfile: remove=serial2 [INFO] [stdout] 2022-02-28T06:34:22.739257Z 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.2/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.2/adp.lock" } pid=1}: adp: serial=Some("serial2") entries=serial2:1 [INFO] [stdout] 2022-02-28T06:34:22.739302Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=1}: adp: try_acquire_resource start [INFO] [stdout] 2022-02-28T06:34:22.739299Z 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.2/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.2/adp.lock" } pid=1}: adp: value=0 adjust_to=1 [INFO] [stdout] 2022-02-28T06:34:22.739334Z 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.2/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.2/adp.lock" } pid=1}: adp: value=1 [INFO] [stdout] 2022-02-28T06:34:22.739363Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest/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/adp.lock" } pid=1}: adp: serials=serial1 [INFO] [stdout] 2022-02-28T06:34:22.739411Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest/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/adp.lock" } pid=1}: adp: lock_file=File { fd: 4, path: "/tmp/rstest/adp.lock", read: true, write: true } [INFO] [stdout] 2022-02-28T06:34:22.739430Z 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.2/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.2/adp.lock" } pid=1}:write{self=LockFileEntries({"serial2": Some(1)}) writer=BufWriter { writer: File { fd: 5, path: "/tmp/rstest.2/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial2" pid=Some(1) [INFO] [stdout] 2022-02-28T06:34:22.739515Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest/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/adp.lock" } pid=1}:read{reader=BufReader { reader: File { fd: 4, path: "/tmp/rstest/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1 [INFO] [stdout] 2022-02-28T06:34:22.739547Z 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.2/adp.lock" } pid=1}: adp: try_acquire_resource end [INFO] [stdout] 2022-02-28T06:34:22.739574Z 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.2/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.2/adp.lock" }, guard: SemaphoreGuard { name: "obtains_the_correct_resource_when_device_is_removed" } }) [INFO] [stdout] 2022-02-28T06:34:22.739599Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest/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/adp.lock" } pid=1}:update{self=LockFileEntries({"serial1": None}) serials=["serial1"]}: adp::lockfile: remove=serial1 [INFO] [stdout] 2022-02-28T06:34:22.739659Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest/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/adp.lock" } pid=1}: adp: serial=Some("serial1") entries=serial1:1 [INFO] [stdout] 2022-02-28T06:34:22.739860Z 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.1/adp.lock" } pid=2}: adp: try_acquire_resource start [INFO] [stdout] 2022-02-28T06:34:22.739910Z 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.2/adp.lock" }, guard: SemaphoreGuard { name: "obtains_the_correct_resource_when_device_is_removed" } }}:read{reader=BufReader { reader: File { fd: 3, path: "/tmp/rstest.2/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial2:1 [INFO] [stdout] 2022-02-28T06:34:22.739945Z 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.1/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.1/adp.lock" } pid=2}: adp: serials=serial1 [INFO] [stdout] 2022-02-28T06:34:22.739994Z 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.1/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.1/adp.lock" } pid=2}: adp: lock_file=File { fd: 5, path: "/tmp/rstest.1/adp.lock", read: true, write: true } [INFO] [stdout] 2022-02-28T06:34:22.740026Z 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.3/adp.lock" } pid=1}: adp: try_acquire_resource start [INFO] [stdout] 2022-02-28T06:34:22.740116Z 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.3/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.3/adp.lock" } pid=1}: adp: serials=serial1,serial2 [INFO] [stdout] 2022-02-28T06:34:22.740112Z 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.1/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.1/adp.lock" } pid=2}:read{reader=BufReader { reader: File { fd: 5, path: "/tmp/rstest.1/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1:1 [INFO] [stdout] 2022-02-28T06:34:22.740214Z 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.1/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.1/adp.lock" } pid=2}:update{self=LockFileEntries({"serial1": Some(1)}) serials=["serial1"]}: adp::lockfile: remove=serial1 [INFO] [stdout] 2022-02-28T06:34:22.740348Z 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-02-28T06:34:22.740383Z 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.1/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.1/adp.lock" } pid=2}: adp: check=serial1 [INFO] [stdout] 2022-02-28T06:34:22.740448Z 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-02-28T06:34:22.740462Z 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.1/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.1/adp.lock" } pid=2}:release{self=LockFileEntries({"serial1": Some(1)}) serial="serial1"}: adp::lockfile: release=serial1 [INFO] [stdout] 2022-02-28T06:34:22.740524Z 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.1/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.1/adp.lock" } pid=2}: adp: serial=Some("serial1") entries=serial1:2 [INFO] [stdout] 2022-02-28T06:34:22.740540Z 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: 7, path: "/tmp/rstest.4/adp.lock", read: true, write: true } [INFO] [stdout] 2022-02-28T06:34:22.740567Z 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.1/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.1/adp.lock" } pid=2}: adp: value=0 adjust_to=1 [INFO] [stdout] 2022-02-28T06:34:22.740604Z 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.1/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.1/adp.lock" } pid=2}: adp: value=1 [INFO] [stdout] 2022-02-28T06:34:22.740662Z 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: 7, path: "/tmp/rstest.4/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries= [INFO] [stdout] 2022-02-28T06:34:22.740751Z 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-02-28T06:34:22.740202Z 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.3/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.3/adp.lock" } pid=1}: adp: lock_file=File { fd: 6, path: "/tmp/rstest.3/adp.lock", read: true, write: true } [INFO] [stdout] 2022-02-28T06:34:22.740809Z 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-02-28T06:34:22.740845Z 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-02-28T06:34:22.740877Z 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-02-28T06:34:22.740904Z 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.3/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.3/adp.lock" } pid=1}:read{reader=BufReader { reader: File { fd: 6, path: "/tmp/rstest.3/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries= [INFO] [stdout] 2022-02-28T06:34:22.739988Z 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.2/adp.lock" }, guard: SemaphoreGuard { name: "obtains_the_correct_resource_when_device_is_removed" } }}: adp: serial=serial2 entries=serial2:1 [INFO] [stdout] 2022-02-28T06:34:22.740975Z 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: 7, path: "/tmp/rstest.4/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=Some(1) [INFO] [stdout] 2022-02-28T06:34:22.740989Z 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.3/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.3/adp.lock" } pid=1}:update{self=LockFileEntries({}) serials=["serial1", "serial2"]}: adp::lockfile: insert=serial1 [INFO] [stdout] 2022-02-28T06:34:22.741029Z 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.3/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.3/adp.lock" } pid=1}:update{self=LockFileEntries({}) serials=["serial1", "serial2"]}: adp::lockfile: insert=serial2 [INFO] [stdout] 2022-02-28T06:34:22.741085Z 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.3/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.3/adp.lock" } pid=1}: adp: serial=Some("serial1") entries=serial1:1,serial2 [INFO] [stdout] 2022-02-28T06:34:22.741110Z 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-02-28T06:34:22.741122Z 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.3/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.3/adp.lock" } pid=1}: adp: value=0 adjust_to=2 [INFO] [stdout] 2022-02-28T06:34:22.741149Z 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.3/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.3/adp.lock" } pid=1}: adp: value=2 [INFO] [stdout] 2022-02-28T06:34:22.741250Z 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.3/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.3/adp.lock" } pid=1}:write{self=LockFileEntries({"serial1": Some(1), "serial2": None}) writer=BufWriter { writer: File { fd: 6, path: "/tmp/rstest.3/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=Some(1) [INFO] [stdout] 2022-02-28T06:34:22.741042Z 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.2/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-02-28T06:34:22.741804Z 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-02-28T06:34:22.741884Z 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-02-28T06:34:22.741933Z 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-02-28T06:34:22.742037Z 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-02-28T06:34:22.742121Z 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-02-28T06:34:22.742177Z 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-02-28T06:34:22.742214Z 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-02-28T06:34:22.742246Z 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-02-28T06:34:22.742341Z 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-02-28T06:34:22.742453Z 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-02-28T06:34:22.742480Z 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-02-28T06:34:22.742639Z 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: 7, path: "/tmp/rstest.5/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1:1 [INFO] [stdout] 2022-02-28T06:34:22.742690Z 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-02-28T06:34:22.742739Z 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-02-28T06:34:22.742785Z 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-02-28T06:34:22.742877Z 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: 7, path: "/tmp/rstest.5/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=None [INFO] [stdout] test tests::single_device_single_run_second_time ... ok [INFO] [stdout] 2022-02-28T06:34:22.743847Z 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.2/adp.lock" }, guard: SemaphoreGuard { name: "obtains_the_correct_resource_when_device_is_removed" } }}: adp: serial=serial2 entries=serial2 [INFO] [stdout] 2022-02-28T06:34:22.741288Z 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.3/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.3/adp.lock" } pid=1}:write{self=LockFileEntries({"serial1": Some(1), "serial2": None}) writer=BufWriter { writer: File { fd: 6, path: "/tmp/rstest.3/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial2" pid=None [INFO] [stdout] 2022-02-28T06:34:22.744086Z 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.5/adp.lock" } pid=1}: adp: try_acquire_resource start [INFO] [stdout] 2022-02-28T06:34:22.744133Z 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.3/adp.lock" } pid=1}: adp: try_acquire_resource end [INFO] [stdout] 2022-02-28T06:34:22.744160Z 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.5/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.5/adp.lock" } pid=1}: adp: serials=serial1 [INFO] [stdout] 2022-02-28T06:34:22.744165Z 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.3/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.3/adp.lock" }, guard: SemaphoreGuard { name: "multiple_devices_multiple_runs_first_time" } }) [INFO] [stdout] 2022-02-28T06:34:22.744233Z 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.5/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.5/adp.lock" } pid=1}: adp: lock_file=File { fd: 6, path: "/tmp/rstest.5/adp.lock", read: true, write: true } [INFO] [stdout] 2022-02-28T06:34:22.744255Z 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.3/adp.lock" } pid=2}: adp: try_acquire_resource start [INFO] [stdout] 2022-02-28T06:34:22.744326Z 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.3/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.3/adp.lock" } pid=2}: adp: serials=serial1,serial2 [INFO] [stdout] 2022-02-28T06:34:22.744331Z 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.5/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.5/adp.lock" } pid=1}:read{reader=BufReader { reader: File { fd: 6, path: "/tmp/rstest.5/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries= [INFO] [stdout] 2022-02-28T06:34:22.744412Z 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.5/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.5/adp.lock" } pid=1}:update{self=LockFileEntries({}) serials=["serial1"]}: adp::lockfile: insert=serial1 [INFO] [stdout] 2022-02-28T06:34:22.744465Z 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.5/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.5/adp.lock" } pid=1}: adp: serial=Some("serial1") entries=serial1:1 [INFO] [stdout] 2022-02-28T06:34:22.744381Z 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.3/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.3/adp.lock" } pid=2}: adp: lock_file=File { fd: 7, path: "/tmp/rstest.3/adp.lock", read: true, write: true } [INFO] [stdout] 2022-02-28T06:34:22.744634Z 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.3/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.3/adp.lock" } pid=2}:read{reader=BufReader { reader: File { fd: 7, path: "/tmp/rstest.3/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1:1,serial2 [INFO] [stdout] 2022-02-28T06:34:22.744740Z 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.3/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.3/adp.lock" } pid=2}:update{self=LockFileEntries({"serial1": Some(1), "serial2": None}) serials=["serial1", "serial2"]}: adp::lockfile: remove=serial1 [INFO] [stdout] 2022-02-28T06:34:22.744779Z 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.3/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.3/adp.lock" } pid=2}:update{self=LockFileEntries({"serial1": Some(1), "serial2": None}) serials=["serial1", "serial2"]}: adp::lockfile: remove=serial2 [INFO] [stdout] 2022-02-28T06:34:22.744831Z 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.3/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.3/adp.lock" } pid=2}: adp: serial=Some("serial2") entries=serial1:1,serial2:2 [INFO] [stdout] 2022-02-28T06:34:22.744863Z 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.3/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.3/adp.lock" } pid=2}: adp: value=1 [INFO] [stdout] 2022-02-28T06:34:22.744974Z 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.3/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.3/adp.lock" } pid=2}:write{self=LockFileEntries({"serial1": Some(1), "serial2": Some(2)}) writer=BufWriter { writer: File { fd: 7, path: "/tmp/rstest.3/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=Some(1) [INFO] [stdout] 2022-02-28T06:34:22.745024Z 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.3/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.3/adp.lock" } pid=2}:write{self=LockFileEntries({"serial1": Some(1), "serial2": Some(2)}) writer=BufWriter { writer: File { fd: 7, path: "/tmp/rstest.3/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial2" pid=Some(2) [INFO] [stdout] 2022-02-28T06:34:22.745141Z 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.3/adp.lock" } pid=2}: adp: try_acquire_resource end [INFO] [stdout] 2022-02-28T06:34:22.745166Z 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.3/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.3/adp.lock" }, guard: SemaphoreGuard { name: "multiple_devices_multiple_runs_first_time" } }) [INFO] [stdout] 2022-02-28T06:34:22.745365Z 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.3/adp.lock" }, guard: SemaphoreGuard { name: "multiple_devices_multiple_runs_first_time" } }}:read{reader=BufReader { reader: File { fd: 7, path: "/tmp/rstest.3/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1:1,serial2:2 [INFO] [stdout] 2022-02-28T06:34:22.745415Z 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.3/adp.lock" }, guard: SemaphoreGuard { name: "multiple_devices_multiple_runs_first_time" } }}: adp: serial=serial1 entries=serial1:1,serial2:2 [INFO] [stdout] 2022-02-28T06:34:22.745462Z 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.3/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-02-28T06:34:22.745507Z 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.3/adp.lock" }, guard: SemaphoreGuard { name: "multiple_devices_multiple_runs_first_time" } }}: adp: serial=serial1 entries=serial1,serial2:2 [INFO] [stdout] 2022-02-28T06:34:22.745620Z 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.3/adp.lock" }, guard: SemaphoreGuard { name: "multiple_devices_multiple_runs_first_time" } }}:write{self=LockFileEntries({"serial1": None, "serial2": Some(2)}) writer=BufWriter { writer: File { fd: 7, path: "/tmp/rstest.3/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=None [INFO] [stdout] 2022-02-28T06:34:22.745656Z 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.3/adp.lock" }, guard: SemaphoreGuard { name: "multiple_devices_multiple_runs_first_time" } }}:write{self=LockFileEntries({"serial1": None, "serial2": Some(2)}) writer=BufWriter { writer: File { fd: 7, path: "/tmp/rstest.3/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial2" pid=Some(2) [INFO] [stdout] 2022-02-28T06:34:22.745876Z 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.3/adp.lock" }, guard: SemaphoreGuard { name: "multiple_devices_multiple_runs_first_time" } }}:read{reader=BufReader { reader: File { fd: 7, path: "/tmp/rstest.3/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1,serial2:2 [INFO] [stdout] 2022-02-28T06:34:22.745930Z 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.3/adp.lock" }, guard: SemaphoreGuard { name: "multiple_devices_multiple_runs_first_time" } }}: adp: serial=serial2 entries=serial1,serial2:2 [INFO] [stdout] 2022-02-28T06:34:22.745990Z 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.3/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-02-28T06:34:22.746044Z 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.3/adp.lock" }, guard: SemaphoreGuard { name: "multiple_devices_multiple_runs_first_time" } }}: adp: serial=serial2 entries=serial1,serial2 [INFO] [stdout] 2022-02-28T06:34:22.746142Z 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.3/adp.lock" }, guard: SemaphoreGuard { name: "multiple_devices_multiple_runs_first_time" } }}:write{self=LockFileEntries({"serial1": None, "serial2": None}) writer=BufWriter { writer: File { fd: 7, path: "/tmp/rstest.3/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=None [INFO] [stdout] 2022-02-28T06:34:22.746175Z 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.3/adp.lock" }, guard: SemaphoreGuard { name: "multiple_devices_multiple_runs_first_time" } }}:write{self=LockFileEntries({"serial1": None, "serial2": None}) writer=BufWriter { writer: File { fd: 7, path: "/tmp/rstest.3/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial2" pid=None [INFO] [stdout] 2022-02-28T06:34:22.744032Z 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.2/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.2/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial2" pid=None [INFO] [stdout] 2022-02-28T06:34:22.746869Z 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.1/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.1/adp.lock" } pid=2}:write{self=LockFileEntries({"serial1": Some(2)}) writer=BufWriter { writer: File { fd: 5, path: "/tmp/rstest.1/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=Some(2) [INFO] [stdout] 2022-02-28T06:34:22.747029Z 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.1/adp.lock" } pid=2}: adp: try_acquire_resource end [INFO] [stdout] 2022-02-28T06:34:22.747058Z 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.1/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.1/adp.lock" }, guard: SemaphoreGuard { name: "obtains_resource_if_process_is_no_longer_running" } }) [INFO] [stdout] 2022-02-28T06:34:22.741140Z 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-02-28T06:34:22.744500Z 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.5/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.5/adp.lock" } pid=1}: adp: value=0 adjust_to=1 [INFO] [stdout] 2022-02-28T06:34:22.747892Z 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: 3, path: "/tmp/rstest.4/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1:1 [INFO] [stdout] 2022-02-28T06:34:22.747909Z 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.5/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.5/adp.lock" } pid=1}: adp: value=1 [INFO] [stdout] 2022-02-28T06:34:22.747951Z 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-02-28T06:34:22.748003Z 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-02-28T06:34:22.748047Z 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-02-28T06:34:22.748054Z 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.5/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.5/adp.lock" } pid=1}:write{self=LockFileEntries({"serial1": Some(1)}) writer=BufWriter { writer: File { fd: 6, path: "/tmp/rstest.5/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=Some(1) [INFO] [stdout] 2022-02-28T06:34:22.748155Z 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: 3, path: "/tmp/rstest.4/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=None [INFO] [stdout] 2022-02-28T06:34:22.748189Z 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.5/adp.lock" } pid=1}: adp: try_acquire_resource end [INFO] [stdout] 2022-02-28T06:34:22.748220Z 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.5/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.5/adp.lock" }, guard: SemaphoreGuard { name: "resource_blocks_until_one_is_released" } }) [INFO] [stdout] test tests::multiple_devices_multiple_runs_first_time ... ok [INFO] [stdout] test tests::obtains_resource_if_process_is_no_longer_running ... ok [INFO] [stdout] 2022-02-28T06:34:22.740276Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest/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/adp.lock" } pid=1}: adp: value=1 [INFO] [stdout] 2022-02-28T06:34:22.751905Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest/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/adp.lock" } pid=1}:write{self=LockFileEntries({"serial1": Some(1)}) writer=BufWriter { writer: File { fd: 4, path: "/tmp/rstest/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=Some(1) [INFO] [stdout] 2022-02-28T06:34:22.752081Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=1}: adp: try_acquire_resource end [INFO] [stdout] 2022-02-28T06:34:22.752115Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest/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/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }) [INFO] [stdout] 2022-02-28T06:34:22.752297Z 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/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }}:read{reader=BufReader { reader: File { fd: 3, path: "/tmp/rstest/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1:1 [INFO] [stdout] 2022-02-28T06:34:22.752360Z 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/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }}: adp: serial=serial1 entries=serial1:1 [INFO] [stdout] 2022-02-28T06:34:22.752411Z 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/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }}:release{self=LockFileEntries({"serial1": Some(1)}) serial="serial1"}: adp::lockfile: release=serial1 [INFO] [stdout] 2022-02-28T06:34:22.752458Z 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/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }}: adp: serial=serial1 entries=serial1 [INFO] [stdout] 2022-02-28T06:34:22.752563Z 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/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }}:write{self=LockFileEntries({"serial1": None}) writer=BufWriter { writer: File { fd: 3, path: "/tmp/rstest/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=None [INFO] [stdout] 2022-02-28T06:34:22.752709Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=1}: adp: try_acquire_resource start [INFO] [stdout] 2022-02-28T06:34:22.752775Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest/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/adp.lock" } pid=1}: adp: serials=serial1 [INFO] [stdout] 2022-02-28T06:34:22.752826Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest/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/adp.lock" } pid=1}: adp: lock_file=File { fd: 3, path: "/tmp/rstest/adp.lock", read: true, write: true } [INFO] [stdout] 2022-02-28T06:34:22.752930Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest/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/adp.lock" } pid=1}:read{reader=BufReader { reader: File { fd: 3, path: "/tmp/rstest/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1 [INFO] [stdout] 2022-02-28T06:34:22.753012Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest/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/adp.lock" } pid=1}:update{self=LockFileEntries({"serial1": None}) serials=["serial1"]}: adp::lockfile: remove=serial1 [INFO] [stdout] 2022-02-28T06:34:22.753070Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest/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/adp.lock" } pid=1}: adp: serial=Some("serial1") entries=serial1:1 [INFO] [stdout] 2022-02-28T06:34:22.753106Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest/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/adp.lock" } pid=1}: adp: value=1 [INFO] [stdout] 2022-02-28T06:34:22.753217Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest/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/adp.lock" } pid=1}:write{self=LockFileEntries({"serial1": Some(1)}) writer=BufWriter { writer: File { fd: 3, path: "/tmp/rstest/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=Some(1) [INFO] [stdout] 2022-02-28T06:34:22.753333Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=1}: adp: try_acquire_resource end [INFO] [stdout] 2022-02-28T06:34:22.753361Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest/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/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }) [INFO] [stdout] 2022-02-28T06:34:22.753510Z 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/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }}:read{reader=BufReader { reader: File { fd: 3, path: "/tmp/rstest/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1:1 [INFO] [stdout] 2022-02-28T06:34:22.753564Z 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/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }}: adp: serial=serial1 entries=serial1:1 [INFO] [stdout] 2022-02-28T06:34:22.753615Z 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/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }}:release{self=LockFileEntries({"serial1": Some(1)}) serial="serial1"}: adp::lockfile: release=serial1 [INFO] [stdout] 2022-02-28T06:34:22.753659Z 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/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }}: adp: serial=serial1 entries=serial1 [INFO] [stdout] 2022-02-28T06:34:22.753760Z 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/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }}:write{self=LockFileEntries({"serial1": None}) writer=BufWriter { writer: File { fd: 3, path: "/tmp/rstest/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=None [INFO] [stdout] test tests::obtains_the_correct_resource_when_device_is_removed ... ok [INFO] [stdout] test tests::single_device_single_run_first_time ... ok [INFO] [stdout] test tests::single_device_three_runs ... ok [INFO] [stdout] 2022-02-28T06:34:22.757129Z 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.5/adp.lock" } pid=2}: adp: try_acquire_resource start [INFO] [stdout] 2022-02-28T06:34:22.757212Z 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.5/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.5/adp.lock" } pid=2}: adp: serials=serial1 [INFO] [stdout] 2022-02-28T06:34:22.757267Z 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.5/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.5/adp.lock" } pid=2}: adp: lock_file=File { fd: 3, path: "/tmp/rstest.5/adp.lock", read: true, write: true } [INFO] [stdout] 2022-02-28T06:34:22.757385Z 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.5/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.5/adp.lock" } pid=2}:read{reader=BufReader { reader: File { fd: 3, path: "/tmp/rstest.5/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1:1 [INFO] [stdout] 2022-02-28T06:34:22.757470Z 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.5/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.5/adp.lock" } pid=2}:update{self=LockFileEntries({"serial1": Some(1)}) serials=["serial1"]}: adp::lockfile: remove=serial1 [INFO] [stdout] 2022-02-28T06:34:22.757531Z 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.5/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.5/adp.lock" } pid=2}: adp: check=serial1 [INFO] [stdout] 2022-02-28T06:34:22.757566Z 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.5/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.5/adp.lock" } pid=2}: adp: serial=None entries=serial1:1 [INFO] [stdout] 2022-02-28T06:34:22.757599Z 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.5/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.5/adp.lock" } pid=2}: adp: value=0 [INFO] [stdout] 2022-02-28T06:34:23.248678Z 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.5/adp.lock" }, guard: SemaphoreGuard { name: "resource_blocks_until_one_is_released" } }}:read{reader=BufReader { reader: File { fd: 3, path: "/tmp/rstest.5/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1:1 [INFO] [stdout] 2022-02-28T06:34:23.248770Z 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.5/adp.lock" }, guard: SemaphoreGuard { name: "resource_blocks_until_one_is_released" } }}: adp: serial=serial1 entries=serial1:1 [INFO] [stdout] 2022-02-28T06:34:23.248830Z 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.5/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-02-28T06:34:23.248881Z 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.5/adp.lock" }, guard: SemaphoreGuard { name: "resource_blocks_until_one_is_released" } }}: adp: serial=serial1 entries=serial1 [INFO] [stdout] 2022-02-28T06:34:23.249019Z 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.5/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.5/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=None [INFO] [stdout] 2022-02-28T06:34:23.249176Z DEBUG adp::tests: sem=1 [INFO] [stdout] 2022-02-28T06:34:23.249276Z 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.5/adp.lock" } pid=2}: adp: try_acquire_resource end [INFO] [stdout] 2022-02-28T06:34:23.249322Z 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.5/adp.lock" } pid=2}: adp: resource=None [INFO] [stdout] 2022-02-28T06:34:23.249348Z 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.5/adp.lock" } pid=2}: adp: try_acquire_resource start [INFO] [stdout] 2022-02-28T06:34:23.249422Z 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.5/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.5/adp.lock" } pid=2}: adp: serials=serial1 [INFO] [stdout] 2022-02-28T06:34:23.249482Z 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.5/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.5/adp.lock" } pid=2}: adp: lock_file=File { fd: 3, path: "/tmp/rstest.5/adp.lock", read: true, write: true } [INFO] [stdout] 2022-02-28T06:34:23.249610Z 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.5/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.5/adp.lock" } pid=2}:read{reader=BufReader { reader: File { fd: 3, path: "/tmp/rstest.5/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1 [INFO] [stdout] 2022-02-28T06:34:23.249702Z 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.5/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.5/adp.lock" } pid=2}:update{self=LockFileEntries({"serial1": None}) serials=["serial1"]}: adp::lockfile: remove=serial1 [INFO] [stdout] 2022-02-28T06:34:23.249766Z 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.5/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.5/adp.lock" } pid=2}: adp: serial=Some("serial1") entries=serial1:2 [INFO] [stdout] 2022-02-28T06:34:23.249804Z 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.5/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.5/adp.lock" } pid=2}: adp: value=1 [INFO] [stdout] 2022-02-28T06:34:23.249927Z 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.5/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.5/adp.lock" } pid=2}:write{self=LockFileEntries({"serial1": Some(2)}) writer=BufWriter { writer: File { fd: 3, path: "/tmp/rstest.5/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=Some(2) [INFO] [stdout] 2022-02-28T06:34:23.250065Z 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.5/adp.lock" } pid=2}: adp: try_acquire_resource end [INFO] [stdout] 2022-02-28T06:34:23.250092Z 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.5/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.5/adp.lock" }, guard: SemaphoreGuard { name: "resource_blocks_until_one_is_released" } }) [INFO] [stdout] 2022-02-28T06:34:23.250140Z DEBUG adp::tests: send=serial1 [INFO] [stdout] 2022-02-28T06:34:23.250271Z 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.5/adp.lock" }, guard: SemaphoreGuard { name: "resource_blocks_until_one_is_released" } }}:read{reader=BufReader { reader: File { fd: 3, path: "/tmp/rstest.5/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1:2 [INFO] [stdout] 2022-02-28T06:34:23.250317Z 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.5/adp.lock" }, guard: SemaphoreGuard { name: "resource_blocks_until_one_is_released" } }}: adp: serial=serial1 entries=serial1:2 [INFO] [stdout] 2022-02-28T06:34:23.250360Z 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.5/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-02-28T06:34:23.250399Z 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.5/adp.lock" }, guard: SemaphoreGuard { name: "resource_blocks_until_one_is_released" } }}: adp: serial=serial1 entries=serial1 [INFO] [stdout] 2022-02-28T06:34:23.250485Z 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.5/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.5/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.53s [INFO] [stdout] [INFO] running `Command { std: "docker" "inspect" "4c1d2480f13b36846312349535727e6f588acc87f3eedea0da60be9b51fa731f", kill_on_drop: false }` [INFO] running `Command { std: "docker" "rm" "-f" "4c1d2480f13b36846312349535727e6f588acc87f3eedea0da60be9b51fa731f", kill_on_drop: false }` [INFO] [stdout] 4c1d2480f13b36846312349535727e6f588acc87f3eedea0da60be9b51fa731f