[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 beta-2022-02-22 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-10/source", kill_on_drop: false }`
[INFO] [stderr] Cloning into '/workspace/builds/worker-10/source'...
[INFO] [stderr] done.
[INFO] validating manifest of git repo https://github.com/evant/adp on toolchain beta-2022-02-22
[INFO] running `Command { std: "/workspace/cargo-home/bin/cargo" "+beta-2022-02-22" "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-10/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" "+beta-2022-02-22" "fetch" "--manifest-path" "Cargo.toml", kill_on_drop: false }`
[INFO] [stderr]  Downloading crates ...
[INFO] [stderr]   Downloaded sysinfo v0.20.5
[INFO] [stderr]   Downloaded process_control v3.1.0
[INFO] [stderr]   Downloaded retry v1.3.0
[INFO] [stderr]   Downloaded ambassador v0.2.1
[INFO] [stderr]   Downloaded function_name v0.2.0
[INFO] [stderr]   Downloaded named-semaphore v0.1.0
[INFO] [stderr]   Downloaded try-block v0.1.0
[INFO] [stderr]   Downloaded function_name-proc-macro v0.2.0
[INFO] [stderr]   Downloaded temp_testdir v0.2.3
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-10/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-10/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" "+beta-2022-02-22" "metadata" "--no-deps" "--format-version=1", kill_on_drop: false }`
[INFO] [stdout] 3b144abd938c056e38e4e53bb16a15484d2869f4dbeadf0627f41160ea8af9a2
[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" "3b144abd938c056e38e4e53bb16a15484d2869f4dbeadf0627f41160ea8af9a2", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "inspect" "3b144abd938c056e38e4e53bb16a15484d2869f4dbeadf0627f41160ea8af9a2", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "3b144abd938c056e38e4e53bb16a15484d2869f4dbeadf0627f41160ea8af9a2", kill_on_drop: false }`
[INFO] [stdout] 3b144abd938c056e38e4e53bb16a15484d2869f4dbeadf0627f41160ea8af9a2
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-10/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-10/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" "+beta-2022-02-22" "build" "--frozen" "--message-format=json", kill_on_drop: false }`
[INFO] [stdout] 527affafab4be5c5e89cddd2d7fd1c6b8f121ddabb1627ae34125a11e8555cc2
[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" "527affafab4be5c5e89cddd2d7fd1c6b8f121ddabb1627ae34125a11e8555cc2", kill_on_drop: false }`
[INFO] [stderr]    Compiling libc v0.2.104
[INFO] [stderr]    Compiling syn v1.0.80
[INFO] [stderr]    Compiling ppv-lite86 v0.2.14
[INFO] [stderr]    Compiling sysinfo v0.20.5
[INFO] [stderr]    Compiling thread_local v1.1.3
[INFO] [stderr]    Compiling crossbeam-deque v0.8.1
[INFO] [stderr]    Compiling tracing-subscriber v0.2.25
[INFO] [stderr]    Compiling getrandom v0.1.16
[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 fs2 v0.4.3
[INFO] [stderr]    Compiling process_control v3.1.0
[INFO] [stderr]    Compiling rayon-core v1.9.1
[INFO] [stderr]    Compiling rand_core v0.5.1
[INFO] [stderr]    Compiling dirs v4.0.0
[INFO] [stderr]    Compiling rand_chacha v0.2.2
[INFO] [stderr]    Compiling rand v0.7.3
[INFO] [stderr]    Compiling rayon v1.5.1
[INFO] [stderr]    Compiling retry v1.3.0
[INFO] [stderr]    Compiling thiserror-impl v1.0.30
[INFO] [stderr]    Compiling tracing-attributes v0.1.18
[INFO] [stderr]    Compiling ambassador v0.2.1
[INFO] [stderr]    Compiling tracing v0.1.29
[INFO] [stderr]    Compiling thiserror v1.0.30
[INFO] [stderr]    Compiling named-semaphore v0.1.0
[INFO] [stderr]    Compiling adp v0.1.0 (/opt/rustwide/workdir)
[INFO] [stdout] warning: field is never read: `guard`
[INFO] [stdout]    --> src/main.rs:107:5
[INFO] [stdout]     |
[INFO] [stdout] 107 |     guard: SemaphoreGuard<'a>,
[INFO] [stdout]     |     ^^^^^^^^^^^^^^^^^^^^^^^^^
[INFO] [stdout]     |
[INFO] [stdout]     = note: `#[warn(dead_code)]` on by default
[INFO] [stdout] note: `Resource` has a derived impl for the trait `Debug`, but this is intentionally ignored during dead code analysis
[INFO] [stdout]    --> src/main.rs:103:10
[INFO] [stdout]     |
[INFO] [stdout] 103 | #[derive(Debug)]
[INFO] [stdout]     |          ^^^^^
[INFO] [stdout]     = note: this warning originates in the derive macro `Debug` (in Nightly builds, run with -Z macro-backtrace for more info)
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] warning: 1 warning emitted
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 46.14s
[INFO] running `Command { std: "docker" "inspect" "527affafab4be5c5e89cddd2d7fd1c6b8f121ddabb1627ae34125a11e8555cc2", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "527affafab4be5c5e89cddd2d7fd1c6b8f121ddabb1627ae34125a11e8555cc2", kill_on_drop: false }`
[INFO] [stdout] 527affafab4be5c5e89cddd2d7fd1c6b8f121ddabb1627ae34125a11e8555cc2
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-10/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-10/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" "+beta-2022-02-22" "test" "--frozen" "--no-run" "--message-format=json", kill_on_drop: false }`
[INFO] [stdout] 14135a34aeedee222624b24065903531c3f21ac785555dc1e87e1736b0da14bd
[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" "14135a34aeedee222624b24065903531c3f21ac785555dc1e87e1736b0da14bd", kill_on_drop: false }`
[INFO] [stderr]    Compiling proc-macro2 v0.4.30
[INFO] [stderr]    Compiling syn v0.15.44
[INFO] [stderr]    Compiling try-block v0.1.0
[INFO] [stderr]    Compiling toml v0.5.8
[INFO] [stderr]    Compiling darling_core v0.12.4
[INFO] [stderr]    Compiling quote v0.6.13
[INFO] [stderr]    Compiling proc-macro-crate v0.1.5
[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 derive_builder_macro v0.10.2
[INFO] [stderr]    Compiling function_name-proc-macro v0.2.0
[INFO] [stderr]    Compiling function_name v0.2.0
[INFO] [stderr]    Compiling derive_builder v0.10.2
[INFO] [stderr]    Compiling adp v0.1.0 (/opt/rustwide/workdir)
[INFO] [stdout] warning: unused import: `Read`
[INFO] [stdout]    --> src/lockfile.rs:127:27
[INFO] [stdout]     |
[INFO] [stdout] 127 |     use std::io::{Cursor, Read, Result, Write};
[INFO] [stdout]     |                           ^^^^
[INFO] [stdout]     |
[INFO] [stdout]     = note: `#[warn(unused_imports)]` on by default
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] warning: unused import: `Write`
[INFO] [stdout]    --> src/lockfile.rs:127:41
[INFO] [stdout]     |
[INFO] [stdout] 127 |     use std::io::{Cursor, Read, Result, Write};
[INFO] [stdout]     |                                         ^^^^^
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] warning: field is never read: `guard`
[INFO] [stdout]    --> src/main.rs:107:5
[INFO] [stdout]     |
[INFO] [stdout] 107 |     guard: SemaphoreGuard<'a>,
[INFO] [stdout]     |     ^^^^^^^^^^^^^^^^^^^^^^^^^
[INFO] [stdout]     |
[INFO] [stdout]     = note: `#[warn(dead_code)]` on by default
[INFO] [stdout] note: `Resource` has a derived impl for the trait `Debug`, but this is intentionally ignored during dead code analysis
[INFO] [stdout]    --> src/main.rs:103:10
[INFO] [stdout]     |
[INFO] [stdout] 103 | #[derive(Debug)]
[INFO] [stdout]     |          ^^^^^
[INFO] [stdout]     = note: this warning originates in the derive macro `Debug` (in Nightly builds, run with -Z macro-backtrace for more info)
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] warning: 3 warnings emitted
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stderr]     Finished test [unoptimized + debuginfo] target(s) in 32.82s
[INFO] running `Command { std: "docker" "inspect" "14135a34aeedee222624b24065903531c3f21ac785555dc1e87e1736b0da14bd", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "14135a34aeedee222624b24065903531c3f21ac785555dc1e87e1736b0da14bd", kill_on_drop: false }`
[INFO] [stdout] 14135a34aeedee222624b24065903531c3f21ac785555dc1e87e1736b0da14bd
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-10/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-10/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" "+beta-2022-02-22" "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] 10c629be7c377ae6ebef9cd7fed9533c492febad67679e49bb1656d60e620af5
[INFO] running `Command { std: "docker" "start" "-a" "10c629be7c377ae6ebef9cd7fed9533c492febad67679e49bb1656d60e620af5", 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] note: `Resource` has a derived impl for the trait `Debug`, but this is intentionally ignored during dead code analysis
[INFO] [stderr]    --> src/main.rs:103:10
[INFO] [stderr]     |
[INFO] [stderr] 103 | #[derive(Debug)]
[INFO] [stderr]     |          ^^^^^
[INFO] [stderr]     = note: this warning originates in the derive macro `Debug` (in Nightly builds, run with -Z macro-backtrace for more info)
[INFO] [stderr] 
[INFO] [stderr] warning: `adp` (bin "adp" test) generated 3 warnings
[INFO] [stderr]     Finished test [unoptimized + debuginfo] target(s) in 0.13s
[INFO] [stderr]      Running unittests (/opt/rustwide/target/debug/deps/adp-138bef39502d92d5)
[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::writes_entries ... ok
[INFO] [stdout] test lockfile::tests::reads_entries ... ok
[INFO] [stdout] test lockfile::tests::inserts_new_entries ... ok
[INFO] [stdout] test lockfile::tests::removes_old_entries ... ok
[INFO] [stdout] 2022-02-28T06:34:41.293204Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=1}: adp: try_acquire_resource start
[INFO] [stdout] 2022-02-28T06:34:41.293265Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.1/adp.lock" } pid=1}: adp: try_acquire_resource start
[INFO] [stdout] 2022-02-28T06:34:41.293303Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=1}: adp: serials=serial1,serial2
[INFO] [stdout] 2022-02-28T06:34:41.293349Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.1/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.1/adp.lock" } pid=1}: adp: serials=serial1
[INFO] [stdout] 2022-02-28T06:34:41.293394Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=1}: adp: lock_file=File { fd: 3, path: "/tmp/rstest/adp.lock", read: true, write: true }
[INFO] [stdout] 2022-02-28T06:34:41.293421Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.1/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.1/adp.lock" } pid=1}: adp: lock_file=File { fd: 4, path: "/tmp/rstest.1/adp.lock", read: true, write: true }
[INFO] [stdout] 2022-02-28T06:34:41.293546Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.1/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.1/adp.lock" } pid=1}:read{reader=BufReader { reader: File { fd: 4, path: "/tmp/rstest.1/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=
[INFO] [stdout] 2022-02-28T06:34:41.293640Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.1/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.1/adp.lock" } pid=1}:update{self=LockFileEntries({}) serials=["serial1"]}: adp::lockfile: insert=serial1
[INFO] [stdout] 2022-02-28T06:34:41.293705Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.1/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.1/adp.lock" } pid=1}: adp: serial=Some("serial1") entries=serial1:1
[INFO] [stdout] 2022-02-28T06:34:41.293746Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.1/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.1/adp.lock" } pid=1}: adp: value=0 adjust_to=1
[INFO] [stdout] 2022-02-28T06:34:41.293780Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.1/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.1/adp.lock" } pid=1}: adp: value=1
[INFO] [stdout] 2022-02-28T06:34:41.293886Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.1/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.1/adp.lock" } pid=1}:write{self=LockFileEntries({"serial1": Some(1)}) writer=BufWriter { writer: File { fd: 4, path: "/tmp/rstest.1/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=Some(1)
[INFO] [stdout] 2022-02-28T06:34:41.294027Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.1/adp.lock" } pid=1}: adp: try_acquire_resource end
[INFO] [stdout] 2022-02-28T06:34:41.294057Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.1/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.1/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } })
[INFO] [stdout] 2022-02-28T06:34:41.294211Z 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.1/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }}:read{reader=BufReader { reader: File { fd: 4, path: "/tmp/rstest.1/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1:1
[INFO] [stdout] 2022-02-28T06:34:41.294269Z 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.1/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }}: adp: serial=serial1 entries=serial1:1
[INFO] [stdout] 2022-02-28T06:34:41.294327Z 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.1/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:41.294376Z 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.1/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }}: adp: serial=serial1 entries=serial1
[INFO] [stdout] 2022-02-28T06:34:41.294474Z 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.1/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }}:write{self=LockFileEntries({"serial1": None}) writer=BufWriter { writer: File { fd: 4, path: "/tmp/rstest.1/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=None
[INFO] [stdout] 2022-02-28T06:34:41.294603Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.1/adp.lock" } pid=1}: adp: try_acquire_resource start
[INFO] [stdout] 2022-02-28T06:34:41.294665Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.1/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.1/adp.lock" } pid=1}: adp: serials=serial1
[INFO] [stdout] 2022-02-28T06:34:41.294709Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.1/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.1/adp.lock" } pid=1}: adp: lock_file=File { fd: 4, path: "/tmp/rstest.1/adp.lock", read: true, write: true }
[INFO] [stdout] 2022-02-28T06:34:41.294809Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.1/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.1/adp.lock" } pid=1}:read{reader=BufReader { reader: File { fd: 4, path: "/tmp/rstest.1/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1
[INFO] [stdout] 2022-02-28T06:34:41.294897Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.1/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.1/adp.lock" } pid=1}:update{self=LockFileEntries({"serial1": None}) serials=["serial1"]}: adp::lockfile: remove=serial1
[INFO] [stdout] 2022-02-28T06:34:41.294957Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.1/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.1/adp.lock" } pid=1}: adp: serial=Some("serial1") entries=serial1:1
[INFO] [stdout] 2022-02-28T06:34:41.294996Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.1/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.1/adp.lock" } pid=1}: adp: value=1
[INFO] [stdout] 2022-02-28T06:34:41.295091Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.1/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.1/adp.lock" } pid=1}:write{self=LockFileEntries({"serial1": Some(1)}) writer=BufWriter { writer: File { fd: 4, path: "/tmp/rstest.1/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=Some(1)
[INFO] [stdout] 2022-02-28T06:34:41.295194Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.1/adp.lock" } pid=1}: adp: try_acquire_resource end
[INFO] [stdout] 2022-02-28T06:34:41.295226Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.1/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.1/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } })
[INFO] [stdout] 2022-02-28T06:34:41.295380Z 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.1/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }}:read{reader=BufReader { reader: File { fd: 4, path: "/tmp/rstest.1/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1:1
[INFO] [stdout] 2022-02-28T06:34:41.295434Z 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.1/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }}: adp: serial=serial1 entries=serial1:1
[INFO] [stdout] 2022-02-28T06:34:41.295484Z 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.1/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:41.295528Z 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.1/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }}: adp: serial=serial1 entries=serial1
[INFO] [stdout] 2022-02-28T06:34:41.295625Z 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.1/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }}:write{self=LockFileEntries({"serial1": None}) writer=BufWriter { writer: File { fd: 4, path: "/tmp/rstest.1/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=None
[INFO] [stdout] 2022-02-28T06:34:41.298037Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_second_time"} , lock_file_path: "/tmp/rstest.2/adp.lock" } pid=1}: adp: try_acquire_resource start
[INFO] [stdout] 2022-02-28T06:34:41.298136Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_second_time"} , lock_file_path: "/tmp/rstest.2/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.2/adp.lock" } pid=1}: adp: serials=serial1
[INFO] [stdout] 2022-02-28T06:34:41.298189Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_second_time"} , lock_file_path: "/tmp/rstest.2/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.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:41.298303Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_second_time"} , lock_file_path: "/tmp/rstest.2/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.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
[INFO] [stdout] 2022-02-28T06:34:41.298387Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_second_time"} , lock_file_path: "/tmp/rstest.2/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.2/adp.lock" } pid=1}:update{self=LockFileEntries({"serial1": None}) serials=["serial1"]}: adp::lockfile: remove=serial1
[INFO] [stdout] 2022-02-28T06:34:41.298443Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_second_time"} , lock_file_path: "/tmp/rstest.2/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.2/adp.lock" } pid=1}: adp: serial=Some("serial1") entries=serial1:1
[INFO] [stdout] 2022-02-28T06:34:41.298479Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_second_time"} , lock_file_path: "/tmp/rstest.2/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.2/adp.lock" } pid=1}: adp: value=0 adjust_to=1
[INFO] [stdout] 2022-02-28T06:34:41.298506Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_second_time"} , lock_file_path: "/tmp/rstest.2/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.2/adp.lock" } pid=1}: adp: value=1
[INFO] [stdout] 2022-02-28T06:34:41.298605Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_second_time"} , lock_file_path: "/tmp/rstest.2/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.2/adp.lock" } pid=1}:write{self=LockFileEntries({"serial1": Some(1)}) writer=BufWriter { writer: File { fd: 5, path: "/tmp/rstest.2/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=Some(1)
[INFO] [stdout] 2022-02-28T06:34:41.298720Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_second_time"} , lock_file_path: "/tmp/rstest.2/adp.lock" } pid=1}: adp: try_acquire_resource end
[INFO] [stdout] 2022-02-28T06:34:41.298747Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_second_time"} , lock_file_path: "/tmp/rstest.2/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.2/adp.lock" }, guard: SemaphoreGuard { name: "single_device_single_run_second_time" } })
[INFO] [stdout] 2022-02-28T06:34:41.298903Z 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.2/adp.lock" }, guard: SemaphoreGuard { name: "single_device_single_run_second_time" } }}:read{reader=BufReader { reader: File { fd: 5, path: "/tmp/rstest.2/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1:1
[INFO] [stdout] 2022-02-28T06:34:41.298949Z 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.2/adp.lock" }, guard: SemaphoreGuard { name: "single_device_single_run_second_time" } }}: adp: serial=serial1 entries=serial1:1
[INFO] [stdout] 2022-02-28T06:34:41.298994Z 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.2/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:41.299035Z 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.2/adp.lock" }, guard: SemaphoreGuard { name: "single_device_single_run_second_time" } }}: adp: serial=serial1 entries=serial1
[INFO] [stdout] 2022-02-28T06:34:41.299123Z 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.2/adp.lock" }, guard: SemaphoreGuard { name: "single_device_single_run_second_time" } }}:write{self=LockFileEntries({"serial1": None}) writer=BufWriter { writer: File { fd: 5, path: "/tmp/rstest.2/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=None
[INFO] [stdout] 2022-02-28T06:34:41.299724Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=1}:read{reader=BufReader { reader: File { fd: 3, path: "/tmp/rstest/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=
[INFO] [stdout] 2022-02-28T06:34:41.299868Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=1}:update{self=LockFileEntries({}) serials=["serial1", "serial2"]}: adp::lockfile: insert=serial1
[INFO] [stdout] 2022-02-28T06:34:41.299910Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=1}:update{self=LockFileEntries({}) serials=["serial1", "serial2"]}: adp::lockfile: insert=serial2
[INFO] [stdout] 2022-02-28T06:34:41.299967Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=1}: adp: serial=Some("serial1") entries=serial1:1,serial2
[INFO] [stdout] 2022-02-28T06:34:41.300009Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=1}: adp: value=0 adjust_to=2
[INFO] [stdout] 2022-02-28T06:34:41.300043Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=1}: adp: value=2
[INFO] [stdout] 2022-02-28T06:34:41.300071Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_first_time"} , lock_file_path: "/tmp/rstest.2/adp.lock" } pid=1}: adp: try_acquire_resource start
[INFO] [stdout] 2022-02-28T06:34:41.300154Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_first_time"} , lock_file_path: "/tmp/rstest.2/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.2/adp.lock" } pid=1}: adp: serials=serial1
[INFO] [stdout] 2022-02-28T06:34:41.300164Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=1}:write{self=LockFileEntries({"serial1": Some(1), "serial2": None}) writer=BufWriter { writer: File { fd: 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:41.300212Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=1}:write{self=LockFileEntries({"serial1": Some(1), "serial2": None}) writer=BufWriter { writer: File { fd: 3, path: "/tmp/rstest/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial2" pid=None
[INFO] [stdout] 2022-02-28T06:34:41.300230Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_first_time"} , lock_file_path: "/tmp/rstest.2/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.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:41.300329Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_first_time"} , lock_file_path: "/tmp/rstest.2/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.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=
[INFO] [stdout] 2022-02-28T06:34:41.300353Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=1}: adp: try_acquire_resource end
[INFO] [stdout] 2022-02-28T06:34:41.300386Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=1}: adp: resource=Some(Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" }, guard: SemaphoreGuard { name: "multiple_devices_multiple_runs_first_time" } })
[INFO] [stdout] 2022-02-28T06:34:41.300402Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_first_time"} , lock_file_path: "/tmp/rstest.2/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.2/adp.lock" } pid=1}:update{self=LockFileEntries({}) serials=["serial1"]}: adp::lockfile: insert=serial1
[INFO] [stdout] 2022-02-28T06:34:41.300453Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_first_time"} , lock_file_path: "/tmp/rstest.2/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.2/adp.lock" } pid=1}: adp: serial=Some("serial1") entries=serial1:1
[INFO] [stdout] 2022-02-28T06:34:41.300472Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=2}: adp: try_acquire_resource start
[INFO] [stdout] 2022-02-28T06:34:41.300486Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_first_time"} , lock_file_path: "/tmp/rstest.2/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.2/adp.lock" } pid=1}: adp: value=0 adjust_to=1
[INFO] [stdout] 2022-02-28T06:34:41.300512Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_first_time"} , lock_file_path: "/tmp/rstest.2/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.2/adp.lock" } pid=1}: adp: value=1
[INFO] [stdout] 2022-02-28T06:34:41.300538Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=2}: adp: serials=serial1,serial2
[INFO] [stdout] 2022-02-28T06:34:41.300589Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=2}: adp: lock_file=File { fd: 3, path: "/tmp/rstest/adp.lock", read: true, write: true }
[INFO] [stdout] 2022-02-28T06:34:41.300602Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_first_time"} , lock_file_path: "/tmp/rstest.2/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.2/adp.lock" } pid=1}:write{self=LockFileEntries({"serial1": Some(1)}) writer=BufWriter { writer: File { fd: 5, path: "/tmp/rstest.2/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=Some(1)
[INFO] [stdout] 2022-02-28T06:34:41.300715Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_first_time"} , lock_file_path: "/tmp/rstest.2/adp.lock" } pid=1}: adp: try_acquire_resource end
[INFO] [stdout] 2022-02-28T06:34:41.300706Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=2}:read{reader=BufReader { reader: File { fd: 3, path: "/tmp/rstest/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1:1,serial2
[INFO] [stdout] 2022-02-28T06:34:41.300741Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_first_time"} , lock_file_path: "/tmp/rstest.2/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.2/adp.lock" }, guard: SemaphoreGuard { name: "single_device_single_run_first_time" } })
[INFO] [stdout] 2022-02-28T06:34:41.300791Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=2}:update{self=LockFileEntries({"serial1": Some(1), "serial2": None}) serials=["serial1", "serial2"]}: adp::lockfile: remove=serial1
[INFO] [stdout] 2022-02-28T06:34:41.300831Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=2}:update{self=LockFileEntries({"serial1": Some(1), "serial2": None}) serials=["serial1", "serial2"]}: adp::lockfile: remove=serial2
[INFO] [stdout] 2022-02-28T06:34:41.300891Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=2}: adp: serial=Some("serial2") entries=serial1:1,serial2:2
[INFO] [stdout] 2022-02-28T06:34:41.300904Z 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.2/adp.lock" }, guard: SemaphoreGuard { name: "single_device_single_run_first_time" } }}:read{reader=BufReader { reader: File { fd: 5, path: "/tmp/rstest.2/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1:1
[INFO] [stdout] 2022-02-28T06:34:41.300928Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=2}: adp: value=1
[INFO] [stdout] 2022-02-28T06:34:41.300956Z 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.2/adp.lock" }, guard: SemaphoreGuard { name: "single_device_single_run_first_time" } }}: adp: serial=serial1 entries=serial1:1
[INFO] [stdout] 2022-02-28T06:34:41.301004Z 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.2/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:41.301046Z 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.2/adp.lock" }, guard: SemaphoreGuard { name: "single_device_single_run_first_time" } }}: adp: serial=serial1 entries=serial1
[INFO] [stdout] 2022-02-28T06:34:41.301043Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=2}:write{self=LockFileEntries({"serial1": Some(1), "serial2": Some(2)}) writer=BufWriter { writer: File { fd: 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:41.301088Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=2}:write{self=LockFileEntries({"serial1": Some(1), "serial2": Some(2)}) writer=BufWriter { writer: File { fd: 3, path: "/tmp/rstest/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial2" pid=Some(2)
[INFO] [stdout] 2022-02-28T06:34:41.301144Z 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.2/adp.lock" }, guard: SemaphoreGuard { name: "single_device_single_run_first_time" } }}:write{self=LockFileEntries({"serial1": None}) writer=BufWriter { writer: File { fd: 5, path: "/tmp/rstest.2/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=None
[INFO] [stdout] 2022-02-28T06:34:41.301207Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=2}: adp: try_acquire_resource end
[INFO] [stdout] 2022-02-28T06:34:41.301237Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" } pid=2}: adp: resource=Some(Resource { serial: "serial2", app: App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" }, guard: SemaphoreGuard { name: "multiple_devices_multiple_runs_first_time" } })
[INFO] [stdout] 2022-02-28T06:34:41.301431Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" }, guard: SemaphoreGuard { name: "multiple_devices_multiple_runs_first_time" } }}:read{reader=BufReader { reader: File { fd: 3, path: "/tmp/rstest/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1:1,serial2:2
[INFO] [stdout] 2022-02-28T06:34:41.301490Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" }, guard: SemaphoreGuard { name: "multiple_devices_multiple_runs_first_time" } }}: adp: serial=serial1 entries=serial1:1,serial2:2
[INFO] [stdout] 2022-02-28T06:34:41.301548Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" }, guard: SemaphoreGuard { name: "multiple_devices_multiple_runs_first_time" } }}:release{self=LockFileEntries({"serial1": Some(1), "serial2": Some(2)}) serial="serial1"}: adp::lockfile: release=serial1
[INFO] [stdout] 2022-02-28T06:34:41.301597Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" }, guard: SemaphoreGuard { name: "multiple_devices_multiple_runs_first_time" } }}: adp: serial=serial1 entries=serial1,serial2:2
[INFO] [stdout] 2022-02-28T06:34:41.301702Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" }, guard: SemaphoreGuard { name: "multiple_devices_multiple_runs_first_time" } }}:write{self=LockFileEntries({"serial1": None, "serial2": Some(2)}) writer=BufWriter { writer: File { fd: 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:41.301740Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" }, guard: SemaphoreGuard { name: "multiple_devices_multiple_runs_first_time" } }}:write{self=LockFileEntries({"serial1": None, "serial2": Some(2)}) writer=BufWriter { writer: File { fd: 3, path: "/tmp/rstest/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial2" pid=Some(2)
[INFO] [stdout] 2022-02-28T06:34:41.301959Z DEBUG release{self=Resource { serial: "serial2", app: App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" }, guard: SemaphoreGuard { name: "multiple_devices_multiple_runs_first_time" } }}:read{reader=BufReader { reader: File { fd: 6, path: "/tmp/rstest/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1,serial2:2
[INFO] [stdout] 2022-02-28T06:34:41.302000Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=1}: adp: try_acquire_resource start
[INFO] [stdout] 2022-02-28T06:34:41.302016Z DEBUG release{self=Resource { serial: "serial2", app: App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" }, guard: SemaphoreGuard { name: "multiple_devices_multiple_runs_first_time" } }}: adp: serial=serial2 entries=serial1,serial2:2
[INFO] [stdout] 2022-02-28T06:34:41.302072Z DEBUG release{self=Resource { serial: "serial2", app: App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" }, guard: SemaphoreGuard { name: "multiple_devices_multiple_runs_first_time" } }}:release{self=LockFileEntries({"serial1": None, "serial2": Some(2)}) serial="serial2"}: adp::lockfile: release=serial2
[INFO] [stdout] 2022-02-28T06:34:41.302084Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=1}: adp: serials=serial1
[INFO] [stdout] 2022-02-28T06:34:41.302121Z DEBUG release{self=Resource { serial: "serial2", app: App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" }, guard: SemaphoreGuard { name: "multiple_devices_multiple_runs_first_time" } }}: adp: serial=serial2 entries=serial1,serial2
[INFO] [stdout] 2022-02-28T06:34:41.302159Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=1}: adp: lock_file=File { fd: 3, path: "/tmp/rstest.3/adp.lock", read: true, write: true }
[INFO] [stdout] 2022-02-28T06:34:41.302227Z DEBUG release{self=Resource { serial: "serial2", app: App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" }, guard: SemaphoreGuard { name: "multiple_devices_multiple_runs_first_time" } }}:write{self=LockFileEntries({"serial1": None, "serial2": None}) writer=BufWriter { writer: File { fd: 6, path: "/tmp/rstest/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=None
[INFO] [stdout] 2022-02-28T06:34:41.302265Z DEBUG release{self=Resource { serial: "serial2", app: App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" }, guard: SemaphoreGuard { name: "multiple_devices_multiple_runs_first_time" } }}:write{self=LockFileEntries({"serial1": None, "serial2": None}) writer=BufWriter { writer: File { fd: 6, path: "/tmp/rstest/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial2" pid=None
[INFO] [stdout] 2022-02-28T06:34:41.302274Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=1}:read{reader=BufReader { reader: File { fd: 3, path: "/tmp/rstest.3/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=
[INFO] [stdout] 2022-02-28T06:34:41.302359Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=1}:update{self=LockFileEntries({}) serials=["serial1"]}: adp::lockfile: insert=serial1
[INFO] [stdout] 2022-02-28T06:34:41.302417Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=1}: adp: serial=Some("serial1") entries=serial1:1
[INFO] [stdout] 2022-02-28T06:34:41.302458Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=1}: adp: value=0 adjust_to=1
[INFO] [stdout] 2022-02-28T06:34:41.302488Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=1}: adp: value=1
[INFO] [stdout] 2022-02-28T06:34:41.302588Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=1}:write{self=LockFileEntries({"serial1": Some(1)}) writer=BufWriter { writer: File { fd: 3, 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:41.302707Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=1}: adp: try_acquire_resource end
[INFO] [stdout] 2022-02-28T06:34:41.302736Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=1}: adp: resource=Some(Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" }, guard: SemaphoreGuard { name: "resource_blocks_until_one_is_released" } })
[INFO] [stdout] 2022-02-28T06:34:41.304184Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}: adp: try_acquire_resource start
[INFO] [stdout] 2022-02-28T06:34:41.304276Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}: adp: serials=serial1
[INFO] [stdout] 2022-02-28T06:34:41.304332Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}: adp: lock_file=File { fd: 5, path: "/tmp/rstest.3/adp.lock", read: true, write: true }
[INFO] [stdout] 2022-02-28T06:34:41.304454Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}:read{reader=BufReader { reader: File { fd: 5, path: "/tmp/rstest.3/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1:1
[INFO] [stdout] 2022-02-28T06:34:41.304541Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}:update{self=LockFileEntries({"serial1": Some(1)}) serials=["serial1"]}: adp::lockfile: remove=serial1
[INFO] [stdout] 2022-02-28T06:34:41.304605Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}: adp: check=serial1
[INFO] [stdout] 2022-02-28T06:34:41.304642Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}: adp: serial=None entries=serial1:1
[INFO] [stdout] 2022-02-28T06:34:41.304674Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}: adp: value=0
[INFO] [stdout] 2022-02-28T06:34:41.306097Z 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.4/adp.lock" } pid=1}: adp: try_acquire_resource start
[INFO] [stdout] 2022-02-28T06:34:41.306185Z 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.4/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.4/adp.lock" } pid=1}: adp: serials=serial2
[INFO] [stdout] 2022-02-28T06:34:41.306242Z 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.4/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.4/adp.lock" } pid=1}: adp: lock_file=File { fd: 3, path: "/tmp/rstest.4/adp.lock", read: true, write: true }
[INFO] [stdout] 2022-02-28T06:34:41.306368Z 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.4/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.4/adp.lock" } pid=1}:read{reader=BufReader { reader: File { fd: 3, path: "/tmp/rstest.4/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1,serial2
[INFO] [stdout] 2022-02-28T06:34:41.306462Z 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.4/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.4/adp.lock" } pid=1}:update{self=LockFileEntries({"serial1": None, "serial2": None}) serials=["serial2"]}: adp::lockfile: remove=serial1
[INFO] [stdout] 2022-02-28T06:34:41.306504Z 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.4/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.4/adp.lock" } pid=1}:update{self=LockFileEntries({"serial1": None, "serial2": None}) serials=["serial2"]}: adp::lockfile: remove=serial2
[INFO] [stdout] 2022-02-28T06:34:41.306560Z 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.4/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.4/adp.lock" } pid=1}: adp: serial=Some("serial2") entries=serial2:1
[INFO] [stdout] 2022-02-28T06:34:41.306602Z 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.4/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.4/adp.lock" } pid=1}: adp: value=0 adjust_to=1
[INFO] [stdout] 2022-02-28T06:34:41.306633Z 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.4/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.4/adp.lock" } pid=1}: adp: value=1
[INFO] [stdout] 2022-02-28T06:34:41.306751Z 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.4/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.4/adp.lock" } pid=1}:write{self=LockFileEntries({"serial2": Some(1)}) writer=BufWriter { writer: File { fd: 3, path: "/tmp/rstest.4/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial2" pid=Some(1)
[INFO] [stdout] 2022-02-28T06:34:41.306882Z 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.4/adp.lock" } pid=1}: adp: try_acquire_resource end
[INFO] [stdout] 2022-02-28T06:34:41.306914Z 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.4/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.4/adp.lock" }, guard: SemaphoreGuard { name: "obtains_the_correct_resource_when_device_is_removed" } })
[INFO] [stdout] 2022-02-28T06:34:41.307100Z 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.4/adp.lock" }, guard: SemaphoreGuard { name: "obtains_the_correct_resource_when_device_is_removed" } }}:read{reader=BufReader { reader: File { fd: 3, path: "/tmp/rstest.4/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial2:1
[INFO] [stdout] 2022-02-28T06:34:41.307155Z 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.4/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:41.307211Z 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.4/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:41.307258Z 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.4/adp.lock" }, guard: SemaphoreGuard { name: "obtains_the_correct_resource_when_device_is_removed" } }}: adp: serial=serial2 entries=serial2
[INFO] [stdout] 2022-02-28T06:34:41.307365Z 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.4/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.4/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial2" pid=None
[INFO] [stdout] test tests::single_device_single_run_second_time ... ok
[INFO] [stdout] test tests::single_device_single_run_first_time ... ok
[INFO] [stdout] 2022-02-28T06:34:41.309284Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "obtains_resource_if_process_is_no_longer_running"} , lock_file_path: "/tmp/rstest.2/adp.lock" } pid=2}: adp: try_acquire_resource start
[INFO] [stdout] 2022-02-28T06:34:41.309374Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "obtains_resource_if_process_is_no_longer_running"} , lock_file_path: "/tmp/rstest.2/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "obtains_resource_if_process_is_no_longer_running"} , lock_file_path: "/tmp/rstest.2/adp.lock" } pid=2}: adp: serials=serial1
[INFO] [stdout] 2022-02-28T06:34:41.309428Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "obtains_resource_if_process_is_no_longer_running"} , lock_file_path: "/tmp/rstest.2/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "obtains_resource_if_process_is_no_longer_running"} , lock_file_path: "/tmp/rstest.2/adp.lock" } pid=2}: adp: lock_file=File { fd: 5, path: "/tmp/rstest.2/adp.lock", read: true, write: true }
[INFO] [stdout] 2022-02-28T06:34:41.309546Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "obtains_resource_if_process_is_no_longer_running"} , lock_file_path: "/tmp/rstest.2/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "obtains_resource_if_process_is_no_longer_running"} , lock_file_path: "/tmp/rstest.2/adp.lock" } pid=2}:read{reader=BufReader { reader: File { fd: 5, path: "/tmp/rstest.2/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1:1
[INFO] [stdout] 2022-02-28T06:34:41.309633Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "obtains_resource_if_process_is_no_longer_running"} , lock_file_path: "/tmp/rstest.2/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "obtains_resource_if_process_is_no_longer_running"} , lock_file_path: "/tmp/rstest.2/adp.lock" } pid=2}:update{self=LockFileEntries({"serial1": Some(1)}) serials=["serial1"]}: adp::lockfile: remove=serial1
[INFO] [stdout] 2022-02-28T06:34:41.309701Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "obtains_resource_if_process_is_no_longer_running"} , lock_file_path: "/tmp/rstest.2/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "obtains_resource_if_process_is_no_longer_running"} , lock_file_path: "/tmp/rstest.2/adp.lock" } pid=2}: adp: check=serial1
[INFO] [stdout] 2022-02-28T06:34:41.309763Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "obtains_resource_if_process_is_no_longer_running"} , lock_file_path: "/tmp/rstest.2/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "obtains_resource_if_process_is_no_longer_running"} , lock_file_path: "/tmp/rstest.2/adp.lock" } pid=2}:release{self=LockFileEntries({"serial1": Some(1)}) serial="serial1"}: adp::lockfile: release=serial1
[INFO] [stdout] 2022-02-28T06:34:41.309819Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "obtains_resource_if_process_is_no_longer_running"} , lock_file_path: "/tmp/rstest.2/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "obtains_resource_if_process_is_no_longer_running"} , lock_file_path: "/tmp/rstest.2/adp.lock" } pid=2}: adp: serial=Some("serial1") entries=serial1:2
[INFO] [stdout] 2022-02-28T06:34:41.309860Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "obtains_resource_if_process_is_no_longer_running"} , lock_file_path: "/tmp/rstest.2/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "obtains_resource_if_process_is_no_longer_running"} , lock_file_path: "/tmp/rstest.2/adp.lock" } pid=2}: adp: value=0 adjust_to=1
[INFO] [stdout] 2022-02-28T06:34:41.309892Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "obtains_resource_if_process_is_no_longer_running"} , lock_file_path: "/tmp/rstest.2/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "obtains_resource_if_process_is_no_longer_running"} , lock_file_path: "/tmp/rstest.2/adp.lock" } pid=2}: adp: value=1
[INFO] [stdout] 2022-02-28T06:34:41.309995Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "obtains_resource_if_process_is_no_longer_running"} , lock_file_path: "/tmp/rstest.2/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "obtains_resource_if_process_is_no_longer_running"} , lock_file_path: "/tmp/rstest.2/adp.lock" } pid=2}:write{self=LockFileEntries({"serial1": Some(2)}) writer=BufWriter { writer: File { fd: 5, path: "/tmp/rstest.2/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=Some(2)
[INFO] [stdout] 2022-02-28T06:34:41.310110Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "obtains_resource_if_process_is_no_longer_running"} , lock_file_path: "/tmp/rstest.2/adp.lock" } pid=2}: adp: try_acquire_resource end
[INFO] [stdout] 2022-02-28T06:34:41.310139Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "obtains_resource_if_process_is_no_longer_running"} , lock_file_path: "/tmp/rstest.2/adp.lock" } pid=2}: adp: resource=Some(Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "obtains_resource_if_process_is_no_longer_running"} , lock_file_path: "/tmp/rstest.2/adp.lock" }, guard: SemaphoreGuard { name: "obtains_resource_if_process_is_no_longer_running" } })
[INFO] [stdout] 2022-02-28T06:34:41.310820Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.1/adp.lock" } pid=1}: adp: try_acquire_resource start
[INFO] [stdout] 2022-02-28T06:34:41.310896Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.1/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.1/adp.lock" } pid=1}: adp: serials=serial1
[INFO] [stdout] 2022-02-28T06:34:41.310947Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.1/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.1/adp.lock" } pid=1}: adp: lock_file=File { fd: 4, path: "/tmp/rstest.1/adp.lock", read: true, write: true }
[INFO] [stdout] 2022-02-28T06:34:41.311057Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.1/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.1/adp.lock" } pid=1}:read{reader=BufReader { reader: File { fd: 4, path: "/tmp/rstest.1/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1
[INFO] [stdout] 2022-02-28T06:34:41.311138Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.1/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.1/adp.lock" } pid=1}:update{self=LockFileEntries({"serial1": None}) serials=["serial1"]}: adp::lockfile: remove=serial1
[INFO] [stdout] 2022-02-28T06:34:41.311196Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.1/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.1/adp.lock" } pid=1}: adp: serial=Some("serial1") entries=serial1:1
[INFO] [stdout] 2022-02-28T06:34:41.311232Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.1/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.1/adp.lock" } pid=1}: adp: value=1
[INFO] [stdout] 2022-02-28T06:34:41.311336Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.1/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.1/adp.lock" } pid=1}:write{self=LockFileEntries({"serial1": Some(1)}) writer=BufWriter { writer: File { fd: 4, path: "/tmp/rstest.1/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=Some(1)
[INFO] [stdout] 2022-02-28T06:34:41.311453Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.1/adp.lock" } pid=1}: adp: try_acquire_resource end
[INFO] [stdout] 2022-02-28T06:34:41.311483Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.1/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.1/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } })
[INFO] [stdout] 2022-02-28T06:34:41.311638Z 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.1/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }}:read{reader=BufReader { reader: File { fd: 4, path: "/tmp/rstest.1/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1:1
[INFO] [stdout] 2022-02-28T06:34:41.311716Z 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.1/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }}: adp: serial=serial1 entries=serial1:1
[INFO] [stdout] 2022-02-28T06:34:41.312236Z 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.1/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:41.312289Z 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.1/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }}: adp: serial=serial1 entries=serial1
[INFO] [stdout] 2022-02-28T06:34:41.312384Z 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.1/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }}:write{self=LockFileEntries({"serial1": None}) writer=BufWriter { writer: File { fd: 4, path: "/tmp/rstest.1/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=None
[INFO] [stdout] test tests::obtains_resource_if_process_is_no_longer_running ... ok
[INFO] [stdout] test tests::obtains_the_correct_resource_when_device_is_removed ... ok
[INFO] [stdout] test tests::single_device_three_runs ... ok
[INFO] [stdout] test tests::multiple_devices_multiple_runs_first_time ... ok
[INFO] [stdout] 2022-02-28T06:34:41.803202Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" }, guard: SemaphoreGuard { name: "resource_blocks_until_one_is_released" } }}:read{reader=BufReader { reader: File { fd: 3, path: "/tmp/rstest.3/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1:1
[INFO] [stdout] 2022-02-28T06:34:41.803379Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" }, guard: SemaphoreGuard { name: "resource_blocks_until_one_is_released" } }}: adp: serial=serial1 entries=serial1:1
[INFO] [stdout] 2022-02-28T06:34:41.803451Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" }, guard: SemaphoreGuard { name: "resource_blocks_until_one_is_released" } }}:release{self=LockFileEntries({"serial1": Some(1)}) serial="serial1"}: adp::lockfile: release=serial1
[INFO] [stdout] 2022-02-28T06:34:41.803503Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" }, guard: SemaphoreGuard { name: "resource_blocks_until_one_is_released" } }}: adp: serial=serial1 entries=serial1
[INFO] [stdout] 2022-02-28T06:34:41.803661Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" }, guard: SemaphoreGuard { name: "resource_blocks_until_one_is_released" } }}:write{self=LockFileEntries({"serial1": None}) writer=BufWriter { writer: File { fd: 3, path: "/tmp/rstest.3/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=None
[INFO] [stdout] 2022-02-28T06:34:41.803895Z DEBUG adp::tests: sem=0
[INFO] [stdout] 2022-02-28T06:34:41.803959Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}: adp: try_acquire_resource end
[INFO] [stdout] 2022-02-28T06:34:41.804008Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}: adp: resource=None
[INFO] [stdout] 2022-02-28T06:34:41.804034Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}: adp: try_acquire_resource start
[INFO] [stdout] 2022-02-28T06:34:41.804108Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}: adp: serials=serial1
[INFO] [stdout] 2022-02-28T06:34:41.804230Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}: adp: lock_file=File { fd: 3, path: "/tmp/rstest.3/adp.lock", read: true, write: true }
[INFO] [stdout] 2022-02-28T06:34:41.804422Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}:read{reader=BufReader { reader: File { fd: 3, path: "/tmp/rstest.3/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1
[INFO] [stdout] 2022-02-28T06:34:41.804561Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}:update{self=LockFileEntries({"serial1": None}) serials=["serial1"]}: adp::lockfile: remove=serial1
[INFO] [stdout] 2022-02-28T06:34:41.804663Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}: adp: serial=Some("serial1") entries=serial1:2
[INFO] [stdout] 2022-02-28T06:34:41.807727Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}: adp: value=1
[INFO] [stdout] 2022-02-28T06:34:41.807943Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}:write{self=LockFileEntries({"serial1": Some(2)}) writer=BufWriter { writer: File { fd: 3, path: "/tmp/rstest.3/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=Some(2)
[INFO] [stdout] 2022-02-28T06:34:41.808103Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}: adp: try_acquire_resource end
[INFO] [stdout] 2022-02-28T06:34:41.808177Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" } pid=2}: adp: resource=Some(Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" }, guard: SemaphoreGuard { name: "resource_blocks_until_one_is_released" } })
[INFO] [stdout] 2022-02-28T06:34:41.808238Z DEBUG adp::tests: send=serial1
[INFO] [stdout] 2022-02-28T06:34:41.808408Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" }, guard: SemaphoreGuard { name: "resource_blocks_until_one_is_released" } }}:read{reader=BufReader { reader: File { fd: 3, path: "/tmp/rstest.3/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1:2
[INFO] [stdout] 2022-02-28T06:34:41.808495Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" }, guard: SemaphoreGuard { name: "resource_blocks_until_one_is_released" } }}: adp: serial=serial1 entries=serial1:2
[INFO] [stdout] 2022-02-28T06:34:41.808567Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" }, guard: SemaphoreGuard { name: "resource_blocks_until_one_is_released" } }}:release{self=LockFileEntries({"serial1": Some(2)}) serial="serial1"}: adp::lockfile: release=serial1
[INFO] [stdout] 2022-02-28T06:34:41.808611Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" }, guard: SemaphoreGuard { name: "resource_blocks_until_one_is_released" } }}: adp: serial=serial1 entries=serial1
[INFO] [stdout] 2022-02-28T06:34:41.808709Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [1] }, sem: Semaphore{ name: "resource_blocks_until_one_is_released"} , lock_file_path: "/tmp/rstest.3/adp.lock" }, guard: SemaphoreGuard { name: "resource_blocks_until_one_is_released" } }}:write{self=LockFileEntries({"serial1": None}) writer=BufWriter { writer: File { fd: 3, path: "/tmp/rstest.3/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=None
[INFO] [stdout] test tests::resource_blocks_until_one_is_released ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 13 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.52s
[INFO] [stdout] 
[INFO] running `Command { std: "docker" "inspect" "10c629be7c377ae6ebef9cd7fed9533c492febad67679e49bb1656d60e620af5", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "10c629be7c377ae6ebef9cd7fed9533c492febad67679e49bb1656d60e620af5", kill_on_drop: false }`
[INFO] [stdout] 10c629be7c377ae6ebef9cd7fed9533c492febad67679e49bb1656d60e620af5