[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 master#62efba8a050c64249dab942951bb28f710208bc8 for pr-90799
[INFO] running `Command { std: "git" "clone" "/workspace/cache/git-repos/https%3A%2F%2Fgithub.com%2Fevant%2Fadp" "/workspace/builds/worker-62/source", kill_on_drop: false }`
[INFO] [stderr] Cloning into '/workspace/builds/worker-62/source'...
[INFO] [stderr] done.
[INFO] validating manifest of git repo https://github.com/evant/adp on toolchain 62efba8a050c64249dab942951bb28f710208bc8
[INFO] running `Command { std: "/workspace/cargo-home/bin/cargo" "+62efba8a050c64249dab942951bb28f710208bc8" "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-62/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" "+62efba8a050c64249dab942951bb28f710208bc8" "fetch" "--manifest-path" "Cargo.toml", kill_on_drop: false }`
[INFO] [stderr]     Blocking waiting for file lock on package cache
[INFO] [stderr]     Blocking waiting for file lock on package cache
[INFO] [stderr]  Downloading crates ...
[INFO] [stderr]   Downloaded retry v1.3.0
[INFO] [stderr]   Downloaded temp_testdir v0.2.3
[INFO] [stderr]   Downloaded sysinfo v0.20.5
[INFO] [stderr]   Downloaded try-block v0.1.0
[INFO] [stderr]   Downloaded function_name-proc-macro v0.2.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] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-62/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-62/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:e8397a04204aaf8b9f284182a6f9e27a3c2e67044d0943b4415b160bfc957681" "/opt/rustwide/cargo-home/bin/cargo" "+62efba8a050c64249dab942951bb28f710208bc8" "metadata" "--no-deps" "--format-version=1", kill_on_drop: false }`
[INFO] [stdout] 8d8e31ca4ee072acc71ce8be07e1bf1b9b57005c4715e8a0933b46aca7b9981d
[INFO] running `Command { std: "docker" "start" "-a" "8d8e31ca4ee072acc71ce8be07e1bf1b9b57005c4715e8a0933b46aca7b9981d", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "inspect" "8d8e31ca4ee072acc71ce8be07e1bf1b9b57005c4715e8a0933b46aca7b9981d", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "8d8e31ca4ee072acc71ce8be07e1bf1b9b57005c4715e8a0933b46aca7b9981d", kill_on_drop: false }`
[INFO] [stdout] 8d8e31ca4ee072acc71ce8be07e1bf1b9b57005c4715e8a0933b46aca7b9981d
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-62/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-62/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=forbid" "-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:e8397a04204aaf8b9f284182a6f9e27a3c2e67044d0943b4415b160bfc957681" "/opt/rustwide/cargo-home/bin/cargo" "+62efba8a050c64249dab942951bb28f710208bc8" "build" "--frozen" "--message-format=json", kill_on_drop: false }`
[INFO] [stdout] f8128b9fb3c89fc3efa3ca530aa124a519e2c4d6a7f0f30e89a18752d2475f81
[INFO] running `Command { std: "docker" "start" "-a" "f8128b9fb3c89fc3efa3ca530aa124a519e2c4d6a7f0f30e89a18752d2475f81", kill_on_drop: false }`
[INFO] [stderr]    Compiling libc v0.2.104
[INFO] [stderr]    Compiling cfg-if v1.0.0
[INFO] [stderr]    Compiling lazy_static v1.4.0
[INFO] [stderr]    Compiling proc-macro2 v1.0.30
[INFO] [stderr]    Compiling unicode-xid v0.2.2
[INFO] [stderr]    Compiling crossbeam-utils v0.8.5
[INFO] [stderr]    Compiling syn v1.0.80
[INFO] [stderr]    Compiling getrandom v0.1.16
[INFO] [stderr]    Compiling crossbeam-epoch v0.9.5
[INFO] [stderr]    Compiling scopeguard v1.1.0
[INFO] [stderr]    Compiling rayon-core v1.9.1
[INFO] [stderr]    Compiling ppv-lite86 v0.2.14
[INFO] [stderr]    Compiling once_cell v1.8.0
[INFO] [stderr]    Compiling anyhow v1.0.44
[INFO] [stderr]    Compiling sysinfo v0.20.5
[INFO] [stderr]    Compiling pin-project-lite v0.2.7
[INFO] [stderr]    Compiling ansi_term v0.12.1
[INFO] [stderr]    Compiling memoffset v0.6.4
[INFO] [stderr]    Compiling rayon v1.5.1
[INFO] [stderr]    Compiling tracing-core v0.1.21
[INFO] [stderr]    Compiling sharded-slab v0.1.4
[INFO] [stderr]    Compiling thread_local v1.1.3
[INFO] [stderr]    Compiling tracing-subscriber v0.2.25
[INFO] [stderr]    Compiling crossbeam-channel v0.5.1
[INFO] [stderr]    Compiling quote v1.0.10
[INFO] [stderr]    Compiling num_cpus v1.13.0
[INFO] [stderr]    Compiling dirs-sys v0.3.6
[INFO] [stderr]    Compiling errno v0.2.7
[INFO] [stderr]    Compiling process_control v3.1.0
[INFO] [stderr]    Compiling fs2 v0.4.3
[INFO] [stderr]    Compiling crossbeam-deque v0.8.1
[INFO] [stderr]    Compiling dirs v4.0.0
[INFO] [stderr]    Compiling rand_core v0.5.1
[INFO] [stderr]    Compiling rand_chacha v0.2.2
[INFO] [stderr]    Compiling rand v0.7.3
[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 retry v1.3.0
[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] 
[INFO] [stdout] 
[INFO] [stdout] warning: 1 warning emitted
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 51.92s
[INFO] running `Command { std: "docker" "inspect" "f8128b9fb3c89fc3efa3ca530aa124a519e2c4d6a7f0f30e89a18752d2475f81", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "f8128b9fb3c89fc3efa3ca530aa124a519e2c4d6a7f0f30e89a18752d2475f81", kill_on_drop: false }`
[INFO] [stdout] f8128b9fb3c89fc3efa3ca530aa124a519e2c4d6a7f0f30e89a18752d2475f81
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-62/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-62/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=forbid" "-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:e8397a04204aaf8b9f284182a6f9e27a3c2e67044d0943b4415b160bfc957681" "/opt/rustwide/cargo-home/bin/cargo" "+62efba8a050c64249dab942951bb28f710208bc8" "test" "--frozen" "--no-run" "--message-format=json", kill_on_drop: false }`
[INFO] [stdout] 6e4d08cc0c3079e46f42f385d283ce4b0f0725720ac4d972981077937a58f536
[INFO] running `Command { std: "docker" "start" "-a" "6e4d08cc0c3079e46f42f385d283ce4b0f0725720ac4d972981077937a58f536", kill_on_drop: false }`
[INFO] [stderr]     Blocking waiting for file lock on package cache
[INFO] [stderr]     Blocking waiting for file lock on package cache
[INFO] [stderr]    Compiling ident_case v1.0.1
[INFO] [stderr]    Compiling strsim v0.10.0
[INFO] [stderr]    Compiling fnv v1.0.7
[INFO] [stderr]    Compiling serde v1.0.130
[INFO] [stderr]    Compiling try-block v0.1.0
[INFO] [stderr]    Compiling temp_testdir v0.2.3
[INFO] [stderr]    Compiling darling_core v0.12.4
[INFO] [stderr]    Compiling darling_macro v0.12.4
[INFO] [stderr]    Compiling toml v0.5.8
[INFO] [stderr]    Compiling darling v0.12.4
[INFO] [stderr]    Compiling derive_builder_core v0.10.2
[INFO] [stderr]    Compiling proc-macro-crate v0.1.5
[INFO] [stderr]    Compiling derive_builder_macro v0.10.2
[INFO] [stderr]    Compiling function_name-proc-macro v0.2.0
[INFO] [stderr]    Compiling derive_builder v0.10.2
[INFO] [stderr]    Compiling function_name v0.2.0
[INFO] [stderr]    Compiling adp v0.1.0 (/opt/rustwide/workdir)
[INFO] [stdout] warning: unused import: `Read`
[INFO] [stdout]    --> src/lockfile.rs:127:27
[INFO] [stdout]     |
[INFO] [stdout] 127 |     use std::io::{Cursor, Read, Result, Write};
[INFO] [stdout]     |                           ^^^^
[INFO] [stdout]     |
[INFO] [stdout]     = note: `#[warn(unused_imports)]` on by default
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] warning: unused import: `Write`
[INFO] [stdout]    --> src/lockfile.rs:127:41
[INFO] [stdout]     |
[INFO] [stdout] 127 |     use std::io::{Cursor, Read, Result, Write};
[INFO] [stdout]     |                                         ^^^^^
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] warning: field is never read: `guard`
[INFO] [stdout]    --> src/main.rs:107:5
[INFO] [stdout]     |
[INFO] [stdout] 107 |     guard: SemaphoreGuard<'a>,
[INFO] [stdout]     |     ^^^^^^^^^^^^^^^^^^^^^^^^^
[INFO] [stdout]     |
[INFO] [stdout]     = note: `#[warn(dead_code)]` on by default
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] warning: 3 warnings emitted
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stderr]     Finished test [unoptimized + debuginfo] target(s) in 12.18s
[INFO] running `Command { std: "docker" "inspect" "6e4d08cc0c3079e46f42f385d283ce4b0f0725720ac4d972981077937a58f536", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "6e4d08cc0c3079e46f42f385d283ce4b0f0725720ac4d972981077937a58f536", kill_on_drop: false }`
[INFO] [stdout] 6e4d08cc0c3079e46f42f385d283ce4b0f0725720ac4d972981077937a58f536
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-62/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-62/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=forbid" "-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:e8397a04204aaf8b9f284182a6f9e27a3c2e67044d0943b4415b160bfc957681" "/opt/rustwide/cargo-home/bin/cargo" "+62efba8a050c64249dab942951bb28f710208bc8" "test" "--frozen", kill_on_drop: false }`
[INFO] [stdout] a29c4f4a70d30a7c06fe8c7d8d132c4e045fd2a8f02f6fd55d6ce573b097e66e
[INFO] running `Command { std: "docker" "start" "-a" "a29c4f4a70d30a7c06fe8c7d8d132c4e045fd2a8f02f6fd55d6ce573b097e66e", kill_on_drop: false }`
[INFO] [stderr]     Blocking waiting for file lock on package cache
[INFO] [stderr] warning: unused import: `Read`
[INFO] [stderr]    --> src/lockfile.rs:127:27
[INFO] [stderr]     |
[INFO] [stderr] 127 |     use std::io::{Cursor, Read, Result, Write};
[INFO] [stderr]     |                           ^^^^
[INFO] [stderr]     |
[INFO] [stderr]     = note: `#[warn(unused_imports)]` on by default
[INFO] [stderr] 
[INFO] [stderr] warning: unused import: `Write`
[INFO] [stderr]    --> src/lockfile.rs:127:41
[INFO] [stderr]     |
[INFO] [stderr] 127 |     use std::io::{Cursor, Read, Result, Write};
[INFO] [stderr]     |                                         ^^^^^
[INFO] [stderr] 
[INFO] [stderr] warning: field is never read: `guard`
[INFO] [stderr]    --> src/main.rs:107:5
[INFO] [stderr]     |
[INFO] [stderr] 107 |     guard: SemaphoreGuard<'a>,
[INFO] [stderr]     |     ^^^^^^^^^^^^^^^^^^^^^^^^^
[INFO] [stderr]     |
[INFO] [stderr]     = note: `#[warn(dead_code)]` on by default
[INFO] [stderr] 
[INFO] [stderr] warning: `adp` (bin "adp" test) generated 3 warnings
[INFO] [stderr]     Finished test [unoptimized + debuginfo] target(s) in 29.72s
[INFO] [stderr]      Running unittests (/opt/rustwide/target/debug/deps/adp-e5ed8ba93922c8e0)
[INFO] [stdout] 
[INFO] [stdout] running 13 tests
[INFO] [stdout] test lockfile::tests::acquires_entry_none ... ok
[INFO] [stdout] test lockfile::tests::reads_entries ... ok
[INFO] [stdout] test lockfile::tests::removes_old_entries ... ok
[INFO] [stdout] test lockfile::tests::writes_entries ... ok
[INFO] [stdout] 2021-12-04T11:26:48.512589Z DEBUG read{reader=[115, 101, 114, 105, 97, 108, 49, 10, 115, 101, 114, 105, 97, 108, 50, 58, 50, 10]}: adp::lockfile: entries=serial1,serial2:2
[INFO] [stdout] 2021-12-04T11:26:48.512785Z DEBUG update{self=LockFileEntries({"serial1": None, "serial2": Some(2)}) serials=["serial1", "serial2", "serial3"]}: adp::lockfile: remove=serial1
[INFO] [stdout] 2021-12-04T11:26:48.512824Z DEBUG update{self=LockFileEntries({"serial1": None, "serial2": Some(2)}) serials=["serial1", "serial2", "serial3"]}: adp::lockfile: remove=serial2
[INFO] [stdout] 2021-12-04T11:26:48.512871Z DEBUG update{self=LockFileEntries({"serial1": None, "serial2": Some(2)}) serials=["serial1", "serial2", "serial3"]}: adp::lockfile: insert=serial3
[INFO] [stdout] test lockfile::tests::inserts_new_entries ... ok
[INFO] [stdout] 2021-12-04T11:26:48.512617Z 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] 2021-12-04T11:26:48.513250Z 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] 2021-12-04T11:26:48.513479Z 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] 2021-12-04T11:26:48.513680Z 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] 2021-12-04T11:26:48.513807Z 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] 2021-12-04T11:26:48.513873Z 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] 2021-12-04T11:26:48.513959Z 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] 2021-12-04T11:26:48.514031Z 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] 2021-12-04T11:26:48.514083Z 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] 2021-12-04T11:26:48.514265Z 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] 2021-12-04T11:26:48.514334Z 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] 2021-12-04T11:26:48.515151Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_second_time"} , lock_file_path: "/tmp/rstest.1/adp.lock" } pid=1}: adp: try_acquire_resource start
[INFO] [stdout] 2021-12-04T11:26:48.515270Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_second_time"} , 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_single_run_second_time"} , lock_file_path: "/tmp/rstest.1/adp.lock" } pid=1}: adp: serials=serial1
[INFO] [stdout] 2021-12-04T11:26:48.515373Z 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] 2021-12-04T11:26:48.515349Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_second_time"} , 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_single_run_second_time"} , lock_file_path: "/tmp/rstest.1/adp.lock" } pid=1}: adp: lock_file=File { fd: 3, path: "/tmp/rstest.1/adp.lock", read: true, write: true }
[INFO] [stdout] 2021-12-04T11:26:48.515453Z 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] 2021-12-04T11:26:48.515558Z 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] 2021-12-04T11:26:48.515543Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_second_time"} , 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_single_run_second_time"} , lock_file_path: "/tmp/rstest.1/adp.lock" } pid=1}:read{reader=BufReader { reader: File { fd: 3, path: "/tmp/rstest.1/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1
[INFO] [stdout] 2021-12-04T11:26:48.515631Z 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] 2021-12-04T11:26:48.515678Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_second_time"} , 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_single_run_second_time"} , lock_file_path: "/tmp/rstest.1/adp.lock" } pid=1}:update{self=LockFileEntries({"serial1": None}) serials=["serial1"]}: adp::lockfile: remove=serial1
[INFO] [stdout] 2021-12-04T11:26:48.515773Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_second_time"} , 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_single_run_second_time"} , lock_file_path: "/tmp/rstest.1/adp.lock" } pid=1}: adp: serial=Some("serial1") entries=serial1:1
[INFO] [stdout] 2021-12-04T11:26:48.515838Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_second_time"} , 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_single_run_second_time"} , lock_file_path: "/tmp/rstest.1/adp.lock" } pid=1}: adp: value=0 adjust_to=1
[INFO] [stdout] 2021-12-04T11:26:48.515777Z 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: 4, path: "/tmp/rstest/adp.lock", read: true, write: true }
[INFO] [stdout] 2021-12-04T11:26:48.515887Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_second_time"} , 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_single_run_second_time"} , lock_file_path: "/tmp/rstest.1/adp.lock" } pid=1}: adp: value=1
[INFO] [stdout] 2021-12-04T11:26:48.516044Z 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: 4, path: "/tmp/rstest/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1:1,serial2
[INFO] [stdout] 2021-12-04T11:26:48.516053Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_second_time"} , 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_single_run_second_time"} , lock_file_path: "/tmp/rstest.1/adp.lock" } pid=1}:write{self=LockFileEntries({"serial1": Some(1)}) writer=BufWriter { writer: File { fd: 3, path: "/tmp/rstest.1/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=Some(1)
[INFO] [stdout] 2021-12-04T11:26:48.516166Z 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] 2021-12-04T11:26:48.516272Z 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] 2021-12-04T11:26:48.516361Z 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] 2021-12-04T11:26:48.516382Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_second_time"} , lock_file_path: "/tmp/rstest.1/adp.lock" } pid=1}: adp: try_acquire_resource end
[INFO] [stdout] 2021-12-04T11:26:48.516426Z 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] 2021-12-04T11:26:48.516427Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_second_time"} , 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_single_run_second_time"} , lock_file_path: "/tmp/rstest.1/adp.lock" }, guard: SemaphoreGuard { name: "single_device_single_run_second_time" } })
[INFO] [stdout] 2021-12-04T11:26:48.516599Z 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: 4, path: "/tmp/rstest/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=Some(1)
[INFO] [stdout] 2021-12-04T11:26:48.516661Z 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: 4, path: "/tmp/rstest/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial2" pid=Some(2)
[INFO] [stdout] 2021-12-04T11:26:48.516720Z 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.1/adp.lock" }, guard: SemaphoreGuard { name: "single_device_single_run_second_time" } }}:read{reader=BufReader { reader: File { fd: 3, path: "/tmp/rstest.1/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1:1
[INFO] [stdout] 2021-12-04T11:26:48.516827Z 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] 2021-12-04T11:26:48.516887Z 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] 2021-12-04T11:26:48.516989Z 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.1/adp.lock" }, guard: SemaphoreGuard { name: "single_device_single_run_second_time" } }}: adp: serial=serial1 entries=serial1:1
[INFO] [stdout] 2021-12-04T11:26:48.517093Z 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.1/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] 2021-12-04T11:26:48.517169Z 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.1/adp.lock" }, guard: SemaphoreGuard { name: "single_device_single_run_second_time" } }}: adp: serial=serial1 entries=serial1
[INFO] [stdout] 2021-12-04T11:26:48.517179Z 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: 4, path: "/tmp/rstest/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1:1,serial2:2
[INFO] [stdout] 2021-12-04T11:26:48.517258Z 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] 2021-12-04T11:26:48.517395Z 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] 2021-12-04T11:26:48.517473Z 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] 2021-12-04T11:26:48.517501Z 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.2/adp.lock" } pid=1}: adp: try_acquire_resource start
[INFO] [stdout] 2021-12-04T11:26:48.517658Z 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.2/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.2/adp.lock" } pid=1}: adp: serials=serial1
[INFO] [stdout] 2021-12-04T11:26:48.517785Z 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.2/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.2/adp.lock" } pid=1}: adp: lock_file=File { fd: 5, path: "/tmp/rstest.2/adp.lock", read: true, write: true }
[INFO] [stdout] 2021-12-04T11:26:48.517994Z 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.2/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.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] 2021-12-04T11:26:48.518140Z 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.2/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.2/adp.lock" } pid=1}:update{self=LockFileEntries({}) serials=["serial1"]}: adp::lockfile: insert=serial1
[INFO] [stdout] 2021-12-04T11:26:48.518239Z 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.2/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.2/adp.lock" } pid=1}: adp: serial=Some("serial1") entries=serial1:1
[INFO] [stdout] 2021-12-04T11:26:48.518300Z 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.2/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.2/adp.lock" } pid=1}: adp: value=0 adjust_to=1
[INFO] [stdout] 2021-12-04T11:26:48.518521Z 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.2/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.2/adp.lock" } pid=1}: adp: value=1
[INFO] [stdout] 2021-12-04T11:26:48.521509Z 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.3/adp.lock" } pid=1}: adp: try_acquire_resource start
[INFO] [stdout] 2021-12-04T11:26:48.521665Z 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.3/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.3/adp.lock" } pid=1}: adp: serials=serial2
[INFO] [stdout] 2021-12-04T11:26:48.521754Z 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.3/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.3/adp.lock" } pid=1}: adp: lock_file=File { fd: 6, path: "/tmp/rstest.3/adp.lock", read: true, write: true }
[INFO] [stdout] 2021-12-04T11:26:48.521987Z 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.3/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.3/adp.lock" } pid=1}:read{reader=BufReader { reader: File { fd: 6, path: "/tmp/rstest.3/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1,serial2
[INFO] [stdout] 2021-12-04T11:26:48.522168Z 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.3/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.3/adp.lock" } pid=1}:update{self=LockFileEntries({"serial1": None, "serial2": None}) serials=["serial2"]}: adp::lockfile: remove=serial1
[INFO] [stdout] 2021-12-04T11:26:48.522239Z 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.3/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.3/adp.lock" } pid=1}:update{self=LockFileEntries({"serial1": None, "serial2": None}) serials=["serial2"]}: adp::lockfile: remove=serial2
[INFO] [stdout] 2021-12-04T11:26:48.522332Z 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.3/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.3/adp.lock" } pid=1}: adp: serial=Some("serial2") entries=serial2:1
[INFO] [stdout] 2021-12-04T11:26:48.522402Z 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.3/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.3/adp.lock" } pid=1}: adp: value=0 adjust_to=1
[INFO] [stdout] 2021-12-04T11:26:48.522453Z 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.3/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.3/adp.lock" } pid=1}: adp: value=1
[INFO] [stdout] 2021-12-04T11:26:48.522623Z 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.3/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.3/adp.lock" } pid=1}:write{self=LockFileEntries({"serial2": Some(1)}) writer=BufWriter { writer: File { fd: 6, path: "/tmp/rstest.3/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial2" pid=Some(1)
[INFO] [stdout] 2021-12-04T11:26:48.523818Z 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.1/adp.lock" }, guard: SemaphoreGuard { name: "single_device_single_run_second_time" } }}:write{self=LockFileEntries({"serial1": None}) writer=BufWriter { writer: File { fd: 3, path: "/tmp/rstest.1/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=None
[INFO] [stdout] 2021-12-04T11:26:48.525070Z 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.2/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.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] 2021-12-04T11:26:48.525725Z DEBUG read{reader=[115, 101, 114, 105, 97, 108, 49, 10, 115, 101, 114, 105, 97, 108, 50, 58, 50, 10]}: adp::lockfile: entries=serial1,serial2:2
[INFO] [stdout] test lockfile::tests::acquires_entry_some ... ok
[INFO] [stdout] 2021-12-04T11:26:48.527182Z 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: 4, path: "/tmp/rstest/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=None
[INFO] [stdout] 2021-12-04T11:26:48.527286Z 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: 4, path: "/tmp/rstest/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial2" pid=Some(2)
[INFO] [stdout] 2021-12-04T11:26:48.528036Z 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.2/adp.lock" } pid=1}: adp: try_acquire_resource end
[INFO] [stdout] 2021-12-04T11:26:48.528123Z 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.2/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.2/adp.lock" }, guard: SemaphoreGuard { name: "resource_blocks_until_one_is_released" } })
[INFO] [stdout] 2021-12-04T11:26:48.528149Z 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.5/adp.lock" } pid=2}: adp: try_acquire_resource start
[INFO] [stdout] 2021-12-04T11:26:48.528263Z DEBUG release{self=Resource { serial: "serial2", app: App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" }, guard: SemaphoreGuard { name: "multiple_devices_multiple_runs_first_time" } }}:read{reader=BufReader { reader: File { fd: 4, path: "/tmp/rstest/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1,serial2:2
[INFO] [stdout] 2021-12-04T11:26:48.528350Z 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] 2021-12-04T11:26:48.528350Z 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.5/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.5/adp.lock" } pid=2}: adp: serials=serial1
[INFO] [stdout] 2021-12-04T11:26:48.528402Z 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.3/adp.lock" } pid=1}: adp: try_acquire_resource end
[INFO] [stdout] 2021-12-04T11:26:48.528424Z 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] 2021-12-04T11:26:48.528450Z 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.3/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.3/adp.lock" }, guard: SemaphoreGuard { name: "obtains_the_correct_resource_when_device_is_removed" } })
[INFO] [stdout] 2021-12-04T11:26:48.528443Z 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.5/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.5/adp.lock" } pid=2}: adp: lock_file=File { fd: 5, path: "/tmp/rstest.5/adp.lock", read: true, write: true }
[INFO] [stdout] 2021-12-04T11:26:48.528496Z 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] 2021-12-04T11:26:48.528854Z 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.3/adp.lock" }, guard: SemaphoreGuard { name: "obtains_the_correct_resource_when_device_is_removed" } }}:read{reader=BufReader { reader: File { fd: 7, path: "/tmp/rstest.3/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial2:1
[INFO] [stdout] 2021-12-04T11:26:48.528951Z 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.3/adp.lock" }, guard: SemaphoreGuard { name: "obtains_the_correct_resource_when_device_is_removed" } }}: adp: serial=serial2 entries=serial2:1
[INFO] [stdout] 2021-12-04T11:26:48.529026Z 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.3/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] 2021-12-04T11:26:48.529020Z DEBUG release{self=Resource { serial: "serial2", app: App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" }, guard: SemaphoreGuard { name: "multiple_devices_multiple_runs_first_time" } }}:write{self=LockFileEntries({"serial1": None, "serial2": None}) writer=BufWriter { writer: File { fd: 4, path: "/tmp/rstest/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=None
[INFO] [stdout] 2021-12-04T11:26:48.529144Z DEBUG release{self=Resource { serial: "serial2", app: App { runtime: FakeRuntime { devices: ["serial1", "serial2"], processes: [] }, sem: Semaphore{ name: "multiple_devices_multiple_runs_first_time"} , lock_file_path: "/tmp/rstest/adp.lock" }, guard: SemaphoreGuard { name: "multiple_devices_multiple_runs_first_time" } }}:write{self=LockFileEntries({"serial1": None, "serial2": None}) writer=BufWriter { writer: File { fd: 4, path: "/tmp/rstest/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial2" pid=None
[INFO] [stdout] 2021-12-04T11:26:48.529162Z 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.3/adp.lock" }, guard: SemaphoreGuard { name: "obtains_the_correct_resource_when_device_is_removed" } }}: adp: serial=serial2 entries=serial2
[INFO] [stdout] 2021-12-04T11:26:48.529385Z 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.3/adp.lock" }, guard: SemaphoreGuard { name: "obtains_the_correct_resource_when_device_is_removed" } }}:write{self=LockFileEntries({"serial2": None}) writer=BufWriter { writer: File { fd: 7, path: "/tmp/rstest.3/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial2" pid=None
[INFO] [stdout] 2021-12-04T11:26:48.531671Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}: adp: try_acquire_resource start
[INFO] [stdout] 2021-12-04T11:26:48.531848Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}: adp: serials=serial1
[INFO] [stdout] 2021-12-04T11:26:48.532041Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}: adp: lock_file=File { fd: 3, path: "/tmp/rstest.4/adp.lock", read: true, write: true }
[INFO] [stdout] 2021-12-04T11:26:48.532305Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:read{reader=BufReader { reader: File { fd: 3, path: "/tmp/rstest.4/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=
[INFO] [stdout] 2021-12-04T11:26:48.532490Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:update{self=LockFileEntries({}) serials=["serial1"]}: adp::lockfile: insert=serial1
[INFO] [stdout] 2021-12-04T11:26:48.532610Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}: adp: serial=Some("serial1") entries=serial1:1
[INFO] [stdout] 2021-12-04T11:26:48.532698Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}: adp: value=0 adjust_to=1
[INFO] [stdout] 2021-12-04T11:26:48.532765Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}: adp: value=1
[INFO] [stdout] 2021-12-04T11:26:48.528701Z 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.5/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.5/adp.lock" } pid=2}:read{reader=BufReader { reader: File { fd: 5, path: "/tmp/rstest.5/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1:1
[INFO] [stdout] 2021-12-04T11:26:48.532947Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:write{self=LockFileEntries({"serial1": Some(1)}) writer=BufWriter { writer: File { fd: 3, path: "/tmp/rstest.4/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=Some(1)
[INFO] [stdout] 2021-12-04T11:26:48.533128Z 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.5/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.5/adp.lock" } pid=2}:update{self=LockFileEntries({"serial1": Some(1)}) serials=["serial1"]}: adp::lockfile: remove=serial1
[INFO] [stdout] 2021-12-04T11:26:48.533261Z 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.5/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.5/adp.lock" } pid=2}: adp: check=serial1
[INFO] [stdout] 2021-12-04T11:26:48.533377Z 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.5/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.5/adp.lock" } pid=2}:release{self=LockFileEntries({"serial1": Some(1)}) serial="serial1"}: adp::lockfile: release=serial1
[INFO] [stdout] 2021-12-04T11:26:48.533481Z 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.5/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.5/adp.lock" } pid=2}: adp: serial=Some("serial1") entries=serial1:2
[INFO] [stdout] 2021-12-04T11:26:48.533575Z 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.5/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.5/adp.lock" } pid=2}: adp: value=0 adjust_to=1
[INFO] [stdout] 2021-12-04T11:26:48.533639Z 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.5/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.5/adp.lock" } pid=2}: adp: value=1
[INFO] [stdout] 2021-12-04T11:26:48.533729Z 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.2/adp.lock" } pid=2}: adp: try_acquire_resource start
[INFO] [stdout] 2021-12-04T11:26:48.533848Z 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.2/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.2/adp.lock" } pid=2}: adp: serials=serial1
[INFO] [stdout] 2021-12-04T11:26:48.533866Z 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.5/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.5/adp.lock" } pid=2}:write{self=LockFileEntries({"serial1": Some(2)}) writer=BufWriter { writer: File { fd: 5, path: "/tmp/rstest.5/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=Some(2)
[INFO] [stdout] 2021-12-04T11:26:48.533923Z 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.2/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.2/adp.lock" } pid=2}: adp: lock_file=File { fd: 3, path: "/tmp/rstest.2/adp.lock", read: true, write: true }
[INFO] [stdout] 2021-12-04T11:26:48.534110Z 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.2/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.2/adp.lock" } pid=2}:read{reader=BufReader { reader: File { fd: 3, path: "/tmp/rstest.2/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1:1
[INFO] [stdout] 2021-12-04T11:26:48.534240Z 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.2/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.2/adp.lock" } pid=2}:update{self=LockFileEntries({"serial1": Some(1)}) serials=["serial1"]}: adp::lockfile: remove=serial1
[INFO] [stdout] 2021-12-04T11:26:48.534329Z 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.2/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.2/adp.lock" } pid=2}: adp: check=serial1
[INFO] [stdout] 2021-12-04T11:26:48.534398Z 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.2/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.2/adp.lock" } pid=2}: adp: serial=None entries=serial1:1
[INFO] [stdout] 2021-12-04T11:26:48.534378Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_first_time"} , lock_file_path: "/tmp/rstest.6/adp.lock" } pid=1}: adp: try_acquire_resource start
[INFO] [stdout] 2021-12-04T11:26:48.534452Z 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.2/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.2/adp.lock" } pid=2}: adp: value=0
[INFO] [stdout] 2021-12-04T11:26:48.535028Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_first_time"} , lock_file_path: "/tmp/rstest.6/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.6/adp.lock" } pid=1}: adp: serials=serial1
[INFO] [stdout] 2021-12-04T11:26:48.535190Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_first_time"} , lock_file_path: "/tmp/rstest.6/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.6/adp.lock" } pid=1}: adp: lock_file=File { fd: 3, path: "/tmp/rstest.6/adp.lock", read: true, write: true }
[INFO] [stdout] 2021-12-04T11:26:48.535467Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_first_time"} , lock_file_path: "/tmp/rstest.6/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.6/adp.lock" } pid=1}:read{reader=BufReader { reader: File { fd: 3, path: "/tmp/rstest.6/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=
[INFO] [stdout] 2021-12-04T11:26:48.535611Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_first_time"} , lock_file_path: "/tmp/rstest.6/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.6/adp.lock" } pid=1}:update{self=LockFileEntries({}) serials=["serial1"]}: adp::lockfile: insert=serial1
[INFO] [stdout] 2021-12-04T11:26:48.535699Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_first_time"} , lock_file_path: "/tmp/rstest.6/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.6/adp.lock" } pid=1}: adp: serial=Some("serial1") entries=serial1:1
[INFO] [stdout] 2021-12-04T11:26:48.535755Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_first_time"} , lock_file_path: "/tmp/rstest.6/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.6/adp.lock" } pid=1}: adp: value=0 adjust_to=1
[INFO] [stdout] 2021-12-04T11:26:48.535813Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_first_time"} , lock_file_path: "/tmp/rstest.6/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.6/adp.lock" } pid=1}: adp: value=1
[INFO] [stdout] 2021-12-04T11:26:48.535977Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_first_time"} , lock_file_path: "/tmp/rstest.6/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.6/adp.lock" } pid=1}:write{self=LockFileEntries({"serial1": Some(1)}) writer=BufWriter { writer: File { fd: 3, path: "/tmp/rstest.6/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=Some(1)
[INFO] [stdout] test tests::single_device_single_run_second_time ... ok
[INFO] [stdout] test tests::multiple_devices_multiple_runs_first_time ... ok
[INFO] [stdout] test tests::obtains_the_correct_resource_when_device_is_removed ... ok
[INFO] [stdout] 2021-12-04T11:26:48.550476Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}: adp: try_acquire_resource end
[INFO] [stdout] 2021-12-04T11:26:48.550609Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}: adp: resource=Some(Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } })
[INFO] [stdout] 2021-12-04T11:26:48.550997Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_first_time"} , lock_file_path: "/tmp/rstest.6/adp.lock" } pid=1}: adp: try_acquire_resource end
[INFO] [stdout] 2021-12-04T11:26:48.551064Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }}:read{reader=BufReader { reader: File { fd: 3, path: "/tmp/rstest.4/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1:1
[INFO] [stdout] 2021-12-04T11:26:48.551102Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_single_run_first_time"} , lock_file_path: "/tmp/rstest.6/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.6/adp.lock" }, guard: SemaphoreGuard { name: "single_device_single_run_first_time" } })
[INFO] [stdout] 2021-12-04T11:26:48.551155Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }}: adp: serial=serial1 entries=serial1:1
[INFO] [stdout] 2021-12-04T11:26:48.551232Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }}:release{self=LockFileEntries({"serial1": Some(1)}) serial="serial1"}: adp::lockfile: release=serial1
[INFO] [stdout] 2021-12-04T11:26:48.551302Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }}: adp: serial=serial1 entries=serial1
[INFO] [stdout] 2021-12-04T11:26:48.551508Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }}:write{self=LockFileEntries({"serial1": None}) writer=BufWriter { writer: File { fd: 3, path: "/tmp/rstest.4/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=None
[INFO] [stdout] 2021-12-04T11:26:48.551491Z 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.6/adp.lock" }, guard: SemaphoreGuard { name: "single_device_single_run_first_time" } }}:read{reader=BufReader { reader: File { fd: 4, path: "/tmp/rstest.6/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1:1
[INFO] [stdout] 2021-12-04T11:26:48.551624Z 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.6/adp.lock" }, guard: SemaphoreGuard { name: "single_device_single_run_first_time" } }}: adp: serial=serial1 entries=serial1:1
[INFO] [stdout] 2021-12-04T11:26:48.551701Z 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.6/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] 2021-12-04T11:26:48.551747Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}: adp: try_acquire_resource start
[INFO] [stdout] 2021-12-04T11:26:48.551783Z 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.6/adp.lock" }, guard: SemaphoreGuard { name: "single_device_single_run_first_time" } }}: adp: serial=serial1 entries=serial1
[INFO] [stdout] 2021-12-04T11:26:48.551842Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}: adp: serials=serial1
[INFO] [stdout] 2021-12-04T11:26:48.551911Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}: adp: lock_file=File { fd: 3, path: "/tmp/rstest.4/adp.lock", read: true, write: true }
[INFO] [stdout] 2021-12-04T11:26:48.551962Z 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.6/adp.lock" }, guard: SemaphoreGuard { name: "single_device_single_run_first_time" } }}:write{self=LockFileEntries({"serial1": None}) writer=BufWriter { writer: File { fd: 4, path: "/tmp/rstest.6/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=None
[INFO] [stdout] 2021-12-04T11:26:48.552054Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:read{reader=BufReader { reader: File { fd: 3, path: "/tmp/rstest.4/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1
[INFO] [stdout] 2021-12-04T11:26:48.552260Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:update{self=LockFileEntries({"serial1": None}) serials=["serial1"]}: adp::lockfile: remove=serial1
[INFO] [stdout] 2021-12-04T11:26:48.552347Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}: adp: serial=Some("serial1") entries=serial1:1
[INFO] [stdout] 2021-12-04T11:26:48.552405Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}: adp: value=1
[INFO] [stdout] 2021-12-04T11:26:48.552565Z 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.5/adp.lock" } pid=2}: adp: try_acquire_resource end
[INFO] [stdout] 2021-12-04T11:26:48.552675Z 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.5/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.5/adp.lock" }, guard: SemaphoreGuard { name: "obtains_resource_if_process_is_no_longer_running" } })
[INFO] [stdout] 2021-12-04T11:26:48.557618Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:write{self=LockFileEntries({"serial1": Some(1)}) writer=BufWriter { writer: File { fd: 3, path: "/tmp/rstest.4/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=Some(1)
[INFO] [stdout] test tests::obtains_resource_if_process_is_no_longer_running ... ok
[INFO] [stdout] test tests::single_device_single_run_first_time ... ok
[INFO] [stdout] 2021-12-04T11:26:48.572008Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}: adp: try_acquire_resource end
[INFO] [stdout] 2021-12-04T11:26:48.572116Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}: adp: resource=Some(Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } })
[INFO] [stdout] 2021-12-04T11:26:48.572536Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }}:read{reader=BufReader { reader: File { fd: 3, path: "/tmp/rstest.4/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1:1
[INFO] [stdout] 2021-12-04T11:26:48.572626Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }}: adp: serial=serial1 entries=serial1:1
[INFO] [stdout] 2021-12-04T11:26:48.572701Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }}:release{self=LockFileEntries({"serial1": Some(1)}) serial="serial1"}: adp::lockfile: release=serial1
[INFO] [stdout] 2021-12-04T11:26:48.572808Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }}: adp: serial=serial1 entries=serial1
[INFO] [stdout] 2021-12-04T11:26:48.573013Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }}:write{self=LockFileEntries({"serial1": None}) writer=BufWriter { writer: File { fd: 3, path: "/tmp/rstest.4/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=None
[INFO] [stdout] 2021-12-04T11:26:48.573247Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}: adp: try_acquire_resource start
[INFO] [stdout] 2021-12-04T11:26:48.573343Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}: adp: serials=serial1
[INFO] [stdout] 2021-12-04T11:26:48.573425Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}: adp: lock_file=File { fd: 3, path: "/tmp/rstest.4/adp.lock", read: true, write: true }
[INFO] [stdout] 2021-12-04T11:26:48.573580Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:read{reader=BufReader { reader: File { fd: 3, path: "/tmp/rstest.4/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1
[INFO] [stdout] 2021-12-04T11:26:48.573704Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:update{self=LockFileEntries({"serial1": None}) serials=["serial1"]}: adp::lockfile: remove=serial1
[INFO] [stdout] 2021-12-04T11:26:48.573794Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}: adp: serial=Some("serial1") entries=serial1:1
[INFO] [stdout] 2021-12-04T11:26:48.573851Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}: adp: value=1
[INFO] [stdout] 2021-12-04T11:26:48.583471Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:try_acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}:write{self=LockFileEntries({"serial1": Some(1)}) writer=BufWriter { writer: File { fd: 3, path: "/tmp/rstest.4/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=Some(1)
[INFO] [stdout] 2021-12-04T11:26:48.592351Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}: adp: try_acquire_resource end
[INFO] [stdout] 2021-12-04T11:26:48.592468Z DEBUG acquire_resource{self=App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" } pid=1}: adp: resource=Some(Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } })
[INFO] [stdout] 2021-12-04T11:26:48.592855Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }}:read{reader=BufReader { reader: File { fd: 3, path: "/tmp/rstest.4/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1:1
[INFO] [stdout] 2021-12-04T11:26:48.592976Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }}: adp: serial=serial1 entries=serial1:1
[INFO] [stdout] 2021-12-04T11:26:48.593056Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }}:release{self=LockFileEntries({"serial1": Some(1)}) serial="serial1"}: adp::lockfile: release=serial1
[INFO] [stdout] 2021-12-04T11:26:48.593130Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }}: adp: serial=serial1 entries=serial1
[INFO] [stdout] 2021-12-04T11:26:48.593550Z DEBUG release{self=Resource { serial: "serial1", app: App { runtime: FakeRuntime { devices: ["serial1"], processes: [] }, sem: Semaphore{ name: "single_device_three_runs"} , lock_file_path: "/tmp/rstest.4/adp.lock" }, guard: SemaphoreGuard { name: "single_device_three_runs" } }}:write{self=LockFileEntries({"serial1": None}) writer=BufWriter { writer: File { fd: 3, path: "/tmp/rstest.4/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=None
[INFO] [stdout] test tests::single_device_three_runs ... ok
[INFO] [stdout] 2021-12-04T11:26:49.029124Z 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.2/adp.lock" }, guard: SemaphoreGuard { name: "resource_blocks_until_one_is_released" } }}:read{reader=BufReader { reader: File { fd: 3, path: "/tmp/rstest.2/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1:1
[INFO] [stdout] 2021-12-04T11:26:49.029282Z 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.2/adp.lock" }, guard: SemaphoreGuard { name: "resource_blocks_until_one_is_released" } }}: adp: serial=serial1 entries=serial1:1
[INFO] [stdout] 2021-12-04T11:26:49.029366Z 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.2/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] 2021-12-04T11:26:49.029454Z 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.2/adp.lock" }, guard: SemaphoreGuard { name: "resource_blocks_until_one_is_released" } }}: adp: serial=serial1 entries=serial1
[INFO] [stdout] 2021-12-04T11:26:49.029685Z 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.2/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.2/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=None
[INFO] [stdout] 2021-12-04T11:26:49.029981Z DEBUG adp::tests: sem=1
[INFO] [stdout] 2021-12-04T11:26:49.030173Z 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.2/adp.lock" } pid=2}: adp: try_acquire_resource end
[INFO] [stdout] 2021-12-04T11:26:49.030293Z 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.2/adp.lock" } pid=2}: adp: resource=None
[INFO] [stdout] 2021-12-04T11:26:49.030328Z 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.2/adp.lock" } pid=2}: adp: try_acquire_resource start
[INFO] [stdout] 2021-12-04T11:26:49.030470Z 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.2/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.2/adp.lock" } pid=2}: adp: serials=serial1
[INFO] [stdout] 2021-12-04T11:26:49.030596Z 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.2/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.2/adp.lock" } pid=2}: adp: lock_file=File { fd: 3, path: "/tmp/rstest.2/adp.lock", read: true, write: true }
[INFO] [stdout] 2021-12-04T11:26:49.031085Z 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.2/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.2/adp.lock" } pid=2}:read{reader=BufReader { reader: File { fd: 3, path: "/tmp/rstest.2/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1
[INFO] [stdout] 2021-12-04T11:26:49.031232Z 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.2/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.2/adp.lock" } pid=2}:update{self=LockFileEntries({"serial1": None}) serials=["serial1"]}: adp::lockfile: remove=serial1
[INFO] [stdout] 2021-12-04T11:26:49.031328Z 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.2/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.2/adp.lock" } pid=2}: adp: serial=Some("serial1") entries=serial1:2
[INFO] [stdout] 2021-12-04T11:26:49.031409Z 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.2/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.2/adp.lock" } pid=2}: adp: value=1
[INFO] [stdout] 2021-12-04T11:26:49.032380Z 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.2/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.2/adp.lock" } pid=2}:write{self=LockFileEntries({"serial1": Some(2)}) writer=BufWriter { writer: File { fd: 3, path: "/tmp/rstest.2/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: serial="serial1" pid=Some(2)
[INFO] [stdout] 2021-12-04T11:26:49.057506Z 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.2/adp.lock" } pid=2}: adp: try_acquire_resource end
[INFO] [stdout] 2021-12-04T11:26:49.057635Z 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.2/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.2/adp.lock" }, guard: SemaphoreGuard { name: "resource_blocks_until_one_is_released" } })
[INFO] [stdout] 2021-12-04T11:26:49.057740Z DEBUG adp::tests: send=serial1
[INFO] [stdout] 2021-12-04T11:26:49.058151Z 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.2/adp.lock" }, guard: SemaphoreGuard { name: "resource_blocks_until_one_is_released" } }}:read{reader=BufReader { reader: File { fd: 3, path: "/tmp/rstest.2/adp.lock", read: true, write: true }, buffer: 0/8192 }}: adp::lockfile: entries=serial1:2
[INFO] [stdout] 2021-12-04T11:26:49.058241Z 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.2/adp.lock" }, guard: SemaphoreGuard { name: "resource_blocks_until_one_is_released" } }}: adp: serial=serial1 entries=serial1:2
[INFO] [stdout] 2021-12-04T11:26:49.058320Z 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.2/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] 2021-12-04T11:26:49.058395Z 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.2/adp.lock" }, guard: SemaphoreGuard { name: "resource_blocks_until_one_is_released" } }}: adp: serial=serial1 entries=serial1
[INFO] [stdout] 2021-12-04T11:26:49.059328Z 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.2/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.2/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.55s
[INFO] [stdout] 
[INFO] running `Command { std: "docker" "inspect" "a29c4f4a70d30a7c06fe8c7d8d132c4e045fd2a8f02f6fd55d6ce573b097e66e", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "a29c4f4a70d30a7c06fe8c7d8d132c4e045fd2a8f02f6fd55d6ce573b097e66e", kill_on_drop: false }`
[INFO] [stdout] a29c4f4a70d30a7c06fe8c7d8d132c4e045fd2a8f02f6fd55d6ce573b097e66e