[INFO] cloning repository https://github.com/pedroven/job-queue-system
[INFO] running `Command { std: "git" "-c" "credential.helper=" "-c" "credential.helper=/workspace/cargo-home/bin/git-credential-null" "clone" "--bare" "https://github.com/pedroven/job-queue-system" "/workspace/cache/git-repos/https%3A%2F%2Fgithub.com%2Fpedroven%2Fjob-queue-system", kill_on_drop: false }`
[INFO] [stderr] Cloning into bare repository '/workspace/cache/git-repos/https%3A%2F%2Fgithub.com%2Fpedroven%2Fjob-queue-system'...
[INFO] running `Command { std: "git" "rev-parse" "HEAD", kill_on_drop: false }`
[INFO] [stdout] 33df3f1057ed6b1f55925c65f510fab3a8a98ea5
[INFO] testing pedroven/job-queue-system against 1.99.0-beta.1+cargoflags=--release for beta-release-1.99-2
[INFO] running `Command { std: "git" "clone" "/workspace/cache/git-repos/https%3A%2F%2Fgithub.com%2Fpedroven%2Fjob-queue-system" "/workspace/builds/worker-5-tc2/source", kill_on_drop: false }`
[INFO] [stderr] Cloning into '/workspace/builds/worker-5-tc2/source'...
[INFO] [stderr] done.
[INFO] started tweaking git repo https://github.com/pedroven/job-queue-system
[INFO] finished tweaking git repo https://github.com/pedroven/job-queue-system
[INFO] tweaked toml for git repo https://github.com/pedroven/job-queue-system written to /workspace/builds/worker-5-tc2/source/Cargo.toml
[INFO] validating manifest of git repo https://github.com/pedroven/job-queue-system on toolchain 1.99.0-beta.1
[INFO] running `Command { std: CARGO_HOME="/workspace/cargo-home" RUSTUP_HOME="/workspace/rustup-home" "/workspace/cargo-home/bin/cargo" "+1.99.0-beta.1" "metadata" "--manifest-path" "Cargo.toml" "--no-deps", kill_on_drop: false }`
[INFO] crate git repo https://github.com/pedroven/job-queue-system already has a lockfile, it will not be regenerated
[INFO] running `Command { std: CARGO_HOME="/workspace/cargo-home" RUSTUP_HOME="/workspace/rustup-home" "/workspace/cargo-home/bin/cargo" "+1.99.0-beta.1" "fetch" "--manifest-path" "Cargo.toml", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-5-tc2/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-5-tc2/target:/opt/rustwide/target:rw,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" "-m" "1610612736" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:8683fc1fc2eb5c9ac98e0d076ab094b2ffac7f99da555d2b6a2e27f346de2ec7" "sleep" "infinity", kill_on_drop: false }`
[INFO] [stdout] 55f963d6e4cb592f4144493c9bdd8644454bb0bcf3cab7310dfa1e3dce7ffec5
[INFO] running `Command { std: "docker" "start" "55f963d6e4cb592f4144493c9bdd8644454bb0bcf3cab7310dfa1e3dce7ffec5", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "inspect" "55f963d6e4cb592f4144493c9bdd8644454bb0bcf3cab7310dfa1e3dce7ffec5", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "exec" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-w" "/opt/rustwide/workdir" "--user" "0:0" "55f963d6e4cb592f4144493c9bdd8644454bb0bcf3cab7310dfa1e3dce7ffec5" "/opt/rustwide/cargo-home/bin/cargo" "+1.99.0-beta.1" "metadata" "--no-deps" "--format-version=1", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "inspect" "55f963d6e4cb592f4144493c9bdd8644454bb0bcf3cab7310dfa1e3dce7ffec5", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "exec" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=warn" "-e" "RUSTDOCFLAGS=--cap-lints=warn" "-w" "/opt/rustwide/workdir" "--user" "0:0" "55f963d6e4cb592f4144493c9bdd8644454bb0bcf3cab7310dfa1e3dce7ffec5" "/opt/rustwide/cargo-home/bin/cargo" "+1.99.0-beta.1" "build" "--frozen" "--message-format=json" "--release", kill_on_drop: false }`
[INFO] [stderr]    Compiling zerocopy v0.8.48
[INFO] [stderr]    Compiling rand_core v0.6.4
[INFO] [stderr]    Compiling siphasher v1.0.2
[INFO] [stderr]    Compiling libc v0.2.185
[INFO] [stderr]    Compiling cc v1.2.59
[INFO] [stderr]    Compiling num-traits v0.2.19
[INFO] [stderr]    Compiling phf_shared v0.11.3
[INFO] [stderr]    Compiling fallible-streaming-iterator v0.1.9
[INFO] [stderr]    Compiling syn v2.0.117
[INFO] [stderr]    Compiling winnow v0.7.15
[INFO] [stderr]    Compiling memchr v2.8.0
[INFO] [stderr]    Compiling fallible-iterator v0.3.0
[INFO] [stderr]    Compiling rand v0.8.6
[INFO] [stderr]    Compiling phf_generator v0.11.3
[INFO] [stderr]    Compiling serde_json v1.0.149
[INFO] [stderr]    Compiling getrandom v0.4.2
[INFO] [stderr]    Compiling chrono v0.4.44
[INFO] [stderr]    Compiling uuid v1.23.0
[INFO] [stderr]    Compiling libsqlite3-sys v0.28.0
[INFO] [stderr]    Compiling phf_macros v0.11.3
[INFO] [stderr]    Compiling serde_derive v1.0.228
[INFO] [stderr]    Compiling job-queue-macros v0.1.0 (/opt/rustwide/workdir/job-queue-macros)
[INFO] [stderr]    Compiling phf v0.11.3
[INFO] [stderr]    Compiling cron v0.16.0
[INFO] [stderr]    Compiling ahash v0.8.12
[INFO] [stderr]    Compiling hashbrown v0.14.5
[INFO] [stderr]    Compiling hashlink v0.9.1
[INFO] [stderr]    Compiling serde v1.0.228
[INFO] [stderr]    Compiling rusqlite v0.31.0
[INFO] [stderr]    Compiling job-queue-system v0.1.0 (/opt/rustwide/workdir)
[INFO] [stderr]     Finished `release` profile [optimized] target(s) in 1m 37s
[INFO] running `Command { std: "docker" "inspect" "55f963d6e4cb592f4144493c9bdd8644454bb0bcf3cab7310dfa1e3dce7ffec5", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "exec" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=warn" "-e" "RUSTDOCFLAGS=--cap-lints=warn" "-w" "/opt/rustwide/workdir" "--user" "0:0" "55f963d6e4cb592f4144493c9bdd8644454bb0bcf3cab7310dfa1e3dce7ffec5" "/opt/rustwide/cargo-home/bin/cargo" "+1.99.0-beta.1" "test" "--frozen" "--no-run" "--message-format=json" "--release", kill_on_drop: false }`
[INFO] [stderr]    Compiling job-queue-system v0.1.0 (/opt/rustwide/workdir)
[INFO] [stderr]     Finished `release` profile [optimized] target(s) in 4.62s
[INFO] running `Command { std: "docker" "inspect" "55f963d6e4cb592f4144493c9bdd8644454bb0bcf3cab7310dfa1e3dce7ffec5", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "exec" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=warn" "-e" "RUSTDOCFLAGS=--cap-lints=warn" "-w" "/opt/rustwide/workdir" "--user" "0:0" "55f963d6e4cb592f4144493c9bdd8644454bb0bcf3cab7310dfa1e3dce7ffec5" "/opt/rustwide/cargo-home/bin/cargo" "+1.99.0-beta.1" "test" "--frozen" "--release", kill_on_drop: false }`
[INFO] [stderr]     Finished `release` profile [optimized] target(s) in 0.07s
[INFO] [stderr]      Running unittests src/lib.rs (/opt/rustwide/target/release/deps/job_queue_system-392c08f6835f711c)
[INFO] [stdout] 
[INFO] [stdout] running 90 tests
[INFO] [stdout] test consumer::tests::test_consume_handles_empty_payload ... ok
[INFO] [stdout] test consumer::tests::test_consume_returns_ok ... ok
[INFO] [stdout] test consumer::tests::test_registry_consumer_errors_on_unknown_task ... ok
[INFO] [stdout] test consumer::tests::test_registry_consumer_routes_to_correct_handler ... ok
[INFO] [stdout] test consumer::tests::test_registry_consumer_dispatches_handler ... ok
[INFO] [stdout] test models::tests::test_job_priority_wire_format_is_stable ... ok
[INFO] [stdout] test models::tests::test_job_with_task_name_sets_name ... ok
[INFO] [stdout] test persistence::memory::tests::test_in_memory_cancelled_status_is_sticky ... ok
[INFO] [stdout] test persistence::memory::tests::test_in_memory_find_by_id ... ok
[INFO] [stdout] test persistence::memory::tests::test_in_memory_find_by_id_not_found ... ok
[INFO] [stdout] test persistence::memory::tests::test_in_memory_pending_count_excludes_non_pending ... ok
[INFO] [stdout] test persistence::memory::tests::test_in_memory_save_and_find_dead_letter ... ok
[INFO] [stdout] test persistence::memory::tests::test_in_memory_save_and_find_pending ... ok
[INFO] [stdout] test persistence::memory::tests::test_in_memory_update_retry_count ... ok
[INFO] [stdout] test persistence::memory::tests::test_in_memory_update_status_excludes_from_pending ... ok
[INFO] [stdout] test persistence::memory::tests::test_in_memory_update_status_not_found ... ok
[INFO] [stdout] test persistence::memory::tests::test_in_memory_update_retry_count_not_found ... ok
[INFO] [stdout] test persistence::sqlite::tests::test_sqlite_save_and_find_pending ... ok
[INFO] [stdout] test persistence::sqlite::tests::test_sqlite_cancelled_status_is_sticky ... ok
[INFO] [stdout] test persistence::sqlite::tests::test_sqlite_find_pending_only_returns_pending ... ok
[INFO] [stdout] test persistence::sqlite::tests::test_sqlite_update_status_to_completed ... ok
[INFO] [stdout] test persistence::sqlite::tests::test_sqlite_find_by_id_not_found ... ok
[INFO] [stdout] test persistence::sqlite::tests::test_sqlite_update_status_not_found ... ok
[INFO] [stdout] test persistence::sqlite::tests::test_sqlite_preserves_task_name ... ok
[INFO] [stdout] test producer::tests::test_produce_at_hard_threshold_rejects ... ok
[INFO] [stdout] test persistence::sqlite::tests::test_sqlite_save_duplicate_id_returns_already_exists ... ok
[INFO] [stdout] test persistence::sqlite::tests::test_sqlite_find_all_pending_preserves_task_name ... ok
[INFO] [stdout] test persistence::sqlite::tests::test_sqlite_pending_count_excludes_non_pending ... ok
[INFO] [stdout] test persistence::sqlite::tests::test_sqlite_update_retry_count_not_found ... ok
[INFO] [stdout] test producer::tests::test_produce_enqueues_job ... ok
[INFO] [stdout] test producer::tests::test_produce_recovers_when_depth_drops ... ok
[INFO] [stdout] test persistence::sqlite::tests::test_sqlite_update_status_missing_after_guard_still_returns_not_found ... ok
[INFO] [stdout] test producer::tests::test_produce_returns_ok ... ok
[INFO] [stdout] test persistence::sqlite::tests::test_sqlite_save_and_find_dead_letter ... ok
[INFO] [stdout] test producer::tests::test_with_config_rejects_invalid_thresholds ... ok
[INFO] [stdout] test queue::core::tests::test_cancel_pending_marks_status_and_removes_from_queue ... ok
[INFO] [stdout] test queue::core::tests::test_cancel_running_marks_status ... ok
[INFO] [stdout] test persistence::sqlite::tests::test_sqlite_update_status ... ok
[INFO] [stdout] test queue::core::tests::test_cancel_terminal_returns_cannot_cancel ... ok
[INFO] [stdout] test queue::core::tests::test_cancel_unknown_job_returns_not_found ... ok
[INFO] [stdout] test persistence::sqlite::tests::test_sqlite_update_retry_count ... ok
[INFO] [stdout] test persistence::sqlite::tests::test_sqlite_find_by_id ... ok
[INFO] [stdout] test queue::core::tests::test_enqueue_priority_drains_before_normal ... ok
[INFO] [stdout] test queue::core::tests::test_enqueue_priority_persists_with_high_priority ... ok
[INFO] [stdout] test queue::core::tests::test_handle_job_tries_bails_after_cancel_between_attempts ... ok
[INFO] [stdout] test queue::core::tests::test_job_succeeds_after_retries ... ok
[INFO] [stdout] test queue::core::tests::test_job_exhausts_retries_moves_to_dlq ... ok
[INFO] [stdout] test queue::core::tests::test_job_succeeds_on_first_attempt ... ok
[INFO] [stdout] test queue::core::tests::test_enqueue_adds_job_to_queue ... ok
[INFO] [stdout] test queue::core::tests::test_process_job_updates_worker_status ... ok
[INFO] [stdout] test queue::core::tests::test_process_job_skips_when_already_cancelled ... ok
[INFO] [stdout] test queue::core::tests::test_queue_new_creates_correct_number_of_workers ... ok
[INFO] [stdout] test queue::core::tests::test_queue_new_workers_start_idle ... ok
[INFO] [stdout] test queue::core::tests::test_queue_new_zero_workers ... ok
[INFO] [stdout] test queue::core::tests::test_enqueue_preserves_fifo_order ... ok
[INFO] [stdout] test queue::core::tests::test_metrics_reporter_handle_stop_terminates_thread ... ok
[INFO] [stdout] test queue::core::tests::test_restart_reloads_priority_first_then_fifo ... ok
[INFO] [stdout] test queue::core::tests::test_wait_for_job_returns_front_job ... ok
[INFO] [stdout] test queue::metrics::tests::snapshot_with_no_activity_is_zeroed ... ok
[INFO] [stdout] test scheduler::model::tests::test_scheduled_job_new_computes_next_run_in_future ... ok
[INFO] [stdout] test queue::metrics::tests::failure_rate_uses_finalized_total ... ok
[INFO] [stdout] test scheduler::model::tests::test_scheduled_job_new_rejects_invalid_cron ... ok
[INFO] [stdout] test queue::core::tests::test_retry_count_is_persisted ... ok
[INFO] [stdout] test queue::metrics::tests::throughput_ewma_rises_with_activity_then_decays ... ok
[INFO] [stdout] test scheduler::runner::tests::test_refire_after_update_failure_dedupes_at_enqueue ... ok
[INFO] [stdout] test producer::tests::test_produce_below_soft_threshold_enqueues_without_error ... ok
[INFO] [stdout] test scheduler::runner::tests::test_tick_advances_next_run_at ... ok
[INFO] [stdout] test queue::metrics::tests::snapshot_aggregates_worker_statuses ... ok
[INFO] [stdout] test queue::metrics::tests::render_includes_key_fields ... ok
[INFO] [stdout] test scheduler::runner::tests::test_tick_ignores_disabled_jobs ... ok
[INFO] [stdout] test scheduler::runner::tests::test_tick_enqueues_due_jobs ... ok
[INFO] [stdout] test scheduler::runner::tests::test_tick_skips_jobs_not_yet_due ... ok
[INFO] [stdout] test task::tests::test_generate_job_id_is_unique ... ok
[INFO] [stdout] test task::tests::test_registry_register_and_get ... ok
[INFO] [stdout] test task::tests::test_task_definition_new ... ok
[INFO] [stdout] test scheduler::runner::tests::test_tick_isolates_failing_row_from_rest_of_batch ... ok
[INFO] [stdout] test task::tests::test_task_registry_macro ... ok
[INFO] [stdout] test scheduler::sqlite::tests::test_sqlite_disabled_excluded_from_find_enabled ... ok
[INFO] [stdout] test scheduler::sqlite::tests::test_sqlite_find_due_excludes_disabled ... ok
[INFO] [stdout] test scheduler::sqlite::tests::test_sqlite_save_is_upsert ... ok
[INFO] [stdout] test scheduler::sqlite::tests::test_sqlite_save_if_absent_preserves_existing_progress ... ok
[INFO] [stdout] test scheduler::sqlite::tests::test_sqlite_update_after_fire_not_found ... ok
[INFO] [stdout] test scheduler::sqlite::tests::test_sqlite_save_if_absent_inserts_when_missing ... ok
[INFO] [stdout] test scheduler::sqlite::tests::test_sqlite_find_due_filters_by_next_run_at ... ok
[INFO] [stdout] test scheduler::sqlite::tests::test_sqlite_save_and_find_enabled_roundtrip ... ok
[INFO] [stdout] test scheduler::sqlite::tests::test_sqlite_update_after_fire_persists_new_times ... ok
[INFO] [stdout] test scheduler::runner::tests::test_start_fires_ticks_in_background_and_stops_cleanly ... ok
[INFO] [stdout] test producer::tests::test_produce_at_soft_threshold_sleeps ... ok
[INFO] [stdout] test queue::core::tests::test_workers_consume_enqueued_jobs ... ok
[INFO] [stdout] test queue::core::tests::test_multiple_jobs_processed_concurrently ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 90 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.21s
[INFO] [stdout] 
[INFO] [stderr]      Running unittests src/main.rs (/opt/rustwide/target/release/deps/job_queue_system-4ec927a3ee6114e8)
[INFO] [stdout] 
[INFO] [stdout] running 0 tests
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s
[INFO] [stdout] 
[INFO] [stderr]      Running tests/integration.rs (/opt/rustwide/target/release/deps/integration-8130809e1443798c)
[INFO] [stdout] 
[INFO] [stdout] running 2 tests
[INFO] [stdout] test pending_jobs_are_restored_on_restart ... ok
[INFO] [stderr]      Running tests/nfr.rs (/opt/rustwide/target/release/deps/nfr-c68d8a67d72c137c)
[INFO] [stdout] test enqueue_and_consume_through_public_api ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 2 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.15s
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] running 3 tests
[INFO] [stdout] test nfr_backpressure_bounds_depth_under_concurrent_flood ... ok
[INFO] [stdout] test nfr_cancellation_pending_jobs_never_execute ... ok
[INFO] [stdout] test nfr_cancellation_running_job_finalizes_as_cancelled ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 3 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.29s
[INFO] [stdout] 
[INFO] [stderr]      Running tests/nfr_status_latency.rs (/opt/rustwide/target/release/deps/nfr_status_latency-2408cb0d3c012966)
[INFO] [stdout] 
[INFO] [stdout] running 1 test
[INFO] [stdout] test nfr_status_query_p99_under_100ms ... ignored, latency NFR; run with `cargo test --release -- --ignored`
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 0 passed; 0 failed; 1 ignored; 0 measured; 0 filtered out; finished in 0.00s
[INFO] [stdout] 
[INFO] [stderr]      Running tests/nfr_throughput.rs (/opt/rustwide/target/release/deps/nfr_throughput-4b9f2251f0c0562c)
[INFO] [stdout] 
[INFO] [stdout] running 1 test
[INFO] [stdout] test nfr_submissions_per_second_at_least_1000 ... ignored, throughput NFR; run with `cargo test --release -- --ignored`
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 0 passed; 0 failed; 1 ignored; 0 measured; 0 filtered out; finished in 0.00s
[INFO] [stdout] 
[INFO] [stderr]      Running tests/task_macro_opts.rs (/opt/rustwide/target/release/deps/task_macro_opts-271d631fad046ae6)
[INFO] [stdout] 
[INFO] [stdout] running 3 tests
[INFO] [stdout] test default_task_uses_normal_priority_and_three_attempts ... ok
[INFO] [stdout] test max_attempts_only_keeps_default_priority ... ok
[INFO] [stdout] test high_priority_args_are_baked_into_perform_async ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 3 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.01s
[INFO] [stdout] 
[INFO] [stderr]    Doc-tests job_queue_system
[INFO] [stdout] 
[INFO] [stdout] running 0 tests
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s
[INFO] [stdout] 
[INFO] running `Command { std: "docker" "inspect" "55f963d6e4cb592f4144493c9bdd8644454bb0bcf3cab7310dfa1e3dce7ffec5", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "55f963d6e4cb592f4144493c9bdd8644454bb0bcf3cab7310dfa1e3dce7ffec5", kill_on_drop: false }`
[INFO] [stdout] 55f963d6e4cb592f4144493c9bdd8644454bb0bcf3cab7310dfa1e3dce7ffec5
