Test failure
cryptonemo opened this issue · 0 comments
cryptonemo commented
Description
I'm seeing a repeatable failure using this code in testing.
running 1 test
test test_seal_lifecycle_32gib_porep_id_v1_1_top_8_8_0_api_v1_1 ... test test_seal_lifecycle_32gib_porep_id_v1_1_top_8_8_0_api_v1_1 has been running for over 60 seconds
2021-05-07T14:46:18.934 TRACE filecoin_proofs::api > generate_piece_commitment:start
2021-05-07T14:47:51.776 TRACE filecoin_proofs::api > generate_piece_commitment:finish
2021-05-07T14:47:51.778 INFO filecoin_proofs::api > add_piece:start
2021-05-07T14:55:03.070 INFO filecoin_proofs::api > add_piece:finish
2021-05-07T14:55:03.070 INFO filecoin_proofs::api::seal > seal_pre_commit_phase1:start: SectorId(9259733836259213201)
2021-05-07T14:55:24.140 INFO filecoin_proofs::api::seal > building merkle tree for the original data
2021-05-07T14:55:24.141 TRACE filecoin_proofs::api::seal > seal phase 1: sector_size 34359738368, base tree size 2147483647, base tree leafs 1073741824
2021-05-07T14:55:24.141 TRACE storage_proofs_core::merkle::builders > create_merkle_tree called with size 1073741824
2021-05-07T14:55:24.141 TRACE storage_proofs_core::merkle::builders > is_merkle_tree_size_valid(1073741824, arity 2) = true
2021-05-07T14:56:12.834 INFO filecoin_proofs::api::seal > verifying pieces
2021-05-07T14:56:12.835 INFO filecoin_proofs::pieces > verifying 1 pieces
2021-05-07T14:56:12.835 INFO storage_proofs_porep::stacked::vanilla::proof > replicate_phase1
2021-05-07T14:56:12.835 INFO storage_proofs_porep::stacked::vanilla::graph > using parent_cache[2048 / 1073741824]
2021-05-07T14:56:14.337 INFO storage_proofs_porep::stacked::vanilla::cache > parent cache: opening /var/tmp/filecoin-parents/v28-sdr-parent-21981246c370f9d76c7a77ab273d94bde0ceb4e938292334960bce05585dc117.cache, verify enabled: false
2021-05-07T14:56:14.342 INFO storage_proofs_porep::stacked::vanilla::proof > single core replication
2021-05-07T14:56:14.342 INFO storage_proofs_porep::stacked::vanilla::create_label::single > generate labels
2021-05-07T14:56:14.343 INFO storage_proofs_porep::stacked::vanilla::create_label::single > generating layer: 1
2021-05-07T15:10:44.224 INFO storage_proofs_porep::stacked::vanilla::create_label::single > storing labels on disk
2021-05-07T15:11:03.163 INFO storage_proofs_porep::stacked::vanilla::create_label::single > generated layer 1 store with id layer-1
2021-05-07T15:11:03.163 INFO storage_proofs_porep::stacked::vanilla::create_label::single > setting exp parents
2021-05-07T15:11:03.163 INFO storage_proofs_porep::stacked::vanilla::create_label::single > generating layer: 2
2021-05-07T15:28:49.346 INFO storage_proofs_porep::stacked::vanilla::create_label::single > storing labels on disk
2021-05-07T15:29:09.124 INFO storage_proofs_porep::stacked::vanilla::create_label::single > generated layer 2 store with id layer-2
2021-05-07T15:29:09.124 INFO storage_proofs_porep::stacked::vanilla::create_label::single > setting exp parents
2021-05-07T15:29:09.124 INFO storage_proofs_porep::stacked::vanilla::create_label::single > generating layer: 3
2021-05-07T15:46:48.068 INFO storage_proofs_porep::stacked::vanilla::create_label::single > storing labels on disk
2021-05-07T15:47:05.986 INFO storage_proofs_porep::stacked::vanilla::create_label::single > generated layer 3 store with id layer-3
2021-05-07T15:47:05.986 INFO storage_proofs_porep::stacked::vanilla::create_label::single > setting exp parents
2021-05-07T15:47:05.986 INFO storage_proofs_porep::stacked::vanilla::create_label::single > generating layer: 4
2021-05-07T16:04:48.502 INFO storage_proofs_porep::stacked::vanilla::create_label::single > storing labels on disk
2021-05-07T16:05:06.399 INFO storage_proofs_porep::stacked::vanilla::create_label::single > generated layer 4 store with id layer-4
2021-05-07T16:05:06.399 INFO storage_proofs_porep::stacked::vanilla::create_label::single > setting exp parents
2021-05-07T16:05:06.399 INFO storage_proofs_porep::stacked::vanilla::create_label::single > generating layer: 5
2021-05-07T16:22:53.601 INFO storage_proofs_porep::stacked::vanilla::create_label::single > storing labels on disk
2021-05-07T16:23:12.558 INFO storage_proofs_porep::stacked::vanilla::create_label::single > generated layer 5 store with id layer-5
2021-05-07T16:23:12.558 INFO storage_proofs_porep::stacked::vanilla::create_label::single > setting exp parents
2021-05-07T16:23:12.558 INFO storage_proofs_porep::stacked::vanilla::create_label::single > generating layer: 6
2021-05-07T16:40:52.397 INFO storage_proofs_porep::stacked::vanilla::create_label::single > storing labels on disk
2021-05-07T16:41:10.207 INFO storage_proofs_porep::stacked::vanilla::create_label::single > generated layer 6 store with id layer-6
2021-05-07T16:41:10.207 INFO storage_proofs_porep::stacked::vanilla::create_label::single > setting exp parents
2021-05-07T16:41:10.207 INFO storage_proofs_porep::stacked::vanilla::create_label::single > generating layer: 7
2021-05-07T16:58:50.165 INFO storage_proofs_porep::stacked::vanilla::create_label::single > storing labels on disk
2021-05-07T16:59:09.193 INFO storage_proofs_porep::stacked::vanilla::create_label::single > generated layer 7 store with id layer-7
2021-05-07T16:59:09.193 INFO storage_proofs_porep::stacked::vanilla::create_label::single > setting exp parents
2021-05-07T16:59:09.193 INFO storage_proofs_porep::stacked::vanilla::create_label::single > generating layer: 8
2021-05-07T17:16:46.607 INFO storage_proofs_porep::stacked::vanilla::create_label::single > storing labels on disk
2021-05-07T17:17:05.012 INFO storage_proofs_porep::stacked::vanilla::create_label::single > generated layer 8 store with id layer-8
2021-05-07T17:17:05.012 INFO storage_proofs_porep::stacked::vanilla::create_label::single > setting exp parents
2021-05-07T17:17:05.012 INFO storage_proofs_porep::stacked::vanilla::create_label::single > generating layer: 9
2021-05-07T17:34:41.737 INFO storage_proofs_porep::stacked::vanilla::create_label::single > storing labels on disk
2021-05-07T17:35:01.700 INFO storage_proofs_porep::stacked::vanilla::create_label::single > generated layer 9 store with id layer-9
2021-05-07T17:35:01.701 INFO storage_proofs_porep::stacked::vanilla::create_label::single > setting exp parents
2021-05-07T17:35:01.701 INFO storage_proofs_porep::stacked::vanilla::create_label::single > generating layer: 10
2021-05-07T17:52:42.417 INFO storage_proofs_porep::stacked::vanilla::create_label::single > storing labels on disk
2021-05-07T17:53:01.507 INFO storage_proofs_porep::stacked::vanilla::create_label::single > generated layer 10 store with id layer-10
2021-05-07T17:53:01.507 INFO storage_proofs_porep::stacked::vanilla::create_label::single > setting exp parents
2021-05-07T17:53:01.507 INFO storage_proofs_porep::stacked::vanilla::create_label::single > generating layer: 11
2021-05-07T18:10:41.241 INFO storage_proofs_porep::stacked::vanilla::create_label::single > storing labels on disk
2021-05-07T18:11:00.280 INFO storage_proofs_porep::stacked::vanilla::create_label::single > generated layer 11 store with id layer-11
2021-05-07T18:11:00.280 INFO storage_proofs_porep::stacked::vanilla::create_label::single > setting exp parents
2021-05-07T18:11:01.029 INFO filecoin_proofs::api::seal > seal_pre_commit_phase1:finish: SectorId(9259733836259213201)
2021-05-07T18:11:01.030 INFO filecoin_proofs::api > validate_cache_for_precommit_phase2:start
2021-05-07T18:11:01.031 INFO filecoin_proofs::api > validate_cache_for_precommit_phase2:finish
2021-05-07T18:11:01.448 INFO filecoin_proofs::api::seal > seal_pre_commit_phase2:start
2021-05-07T18:11:01.449 TRACE filecoin_proofs::api::seal > seal phase 2: base tree size 2147483647, base tree leafs 1073741824, rows to discard 7
2021-05-07T18:11:01.450 INFO storage_proofs_porep::stacked::vanilla::proof > replicate_phase2
2021-05-07T18:11:01.450 TRACE storage_proofs_porep::stacked::vanilla::proof > transform_and_replicate_layers
2021-05-07T18:11:01.450 TRACE storage_proofs_porep::stacked::vanilla::proof > nodes count 1073741824, data len 34359738368
2021-05-07T18:11:01.450 TRACE storage_proofs_porep::stacked::vanilla::proof > is_merkle_tree_size_valid(134217728, BINARY_ARITY) = true
2021-05-07T18:11:01.450 TRACE storage_proofs_porep::stacked::vanilla::proof > is_merkle_tree_size_valid(134217728, 8) = true
2021-05-07T18:11:01.451 TRACE storage_proofs_porep::stacked::vanilla::proof > tree_r_last using rows_to_discard=2
2021-05-07T18:11:01.452 INFO storage_proofs_porep::stacked::vanilla::proof > Building trees [1048576 descriptors max available]
2021-05-07T18:11:01.452 INFO storage_proofs_porep::stacked::vanilla::proof > generating tree c using the GPU
2021-05-07T18:11:01.452 INFO storage_proofs_porep::stacked::vanilla::proof > Building column hashes
2021-05-07T18:11:01.459 TRACE storage_proofs_porep::stacked::vanilla::proof > processing config 1/8 with column nodes 400000
2021-05-07T18:11:01.459 INFO client > register
2021-05-07T18:11:01.459 TRACE client > -> register
2021-05-07T18:11:01.459 INFO client > new client: 2746067640 - with process_id: 2746067640
2021-05-07T18:11:01.483 TRACE client > <- register
2021-05-07T18:11:01.483 TRACE client > -- register
2021-05-07T18:11:01.483 INFO client > schedule_one_of
2021-05-07T18:11:01.483 TRACE client > -> schedule_one_of
2021-05-07T18:11:01.485 TRACE mio::poll > registering event source with poller: token=Token(0), interests=READABLE | WRITABLE
2021-05-07T18:11:01.497 TRACE hyper::client::pool > checkout waiting for idle connection: ("http", 127.0.0.1:5000)
2021-05-07T18:11:01.497 DEBUG reqwest::connect > starting new connection: http://127.0.0.1:5000/
2021-05-07T18:11:01.498 TRACE hyper::client::connect::http > Http::connect; scheme=Some("http"), host=Some("127.0.0.1"), port=Some(Port(5000))
2021-05-07T18:11:01.498 DEBUG hyper::client::connect::http > connecting to 127.0.0.1:5000
2021-05-07T18:11:01.498 TRACE mio::poll > registering event source with poller: token=Token(1), interests=READABLE | WRITABLE
2021-05-07T18:11:01.498 TRACE mio::poll > deregistering event source from poller
2021-05-07T18:11:01.498 TRACE hyper::client::connect::http > connect error for 127.0.0.1:5000: ConnectError("tcp connect error", Os { code: 111, kind: ConnectionRefused, message: "Connection refused" })
2021-05-07T18:11:01.498 TRACE hyper::client::pool > checkout dropped for ("http", 127.0.0.1:5000)
2021-05-07T18:11:01.629 DEBUG client::global_mutex > try_lock
2021-05-07T18:11:01.629 TRACE client::global_mutex > -> try_lock
2021-05-07T18:11:01.630 DEBUG client::global_mutex > Trying to acquire the mutex - process id: 1452
2021-05-07T18:11:01.630 TRACE client::global_mutex > <- try_lock
2021-05-07T18:11:01.630 TRACE client::global_mutex > -- try_lock
2021-05-07T18:11:01.630 INFO scheduler > run_scheduler; address="127.0.0.1:5000"
2021-05-07T18:11:01.630 TRACE scheduler > -> run_scheduler
2021-05-07T18:11:01.891 TRACE storage_proofs_porep::stacked::vanilla::proof > node index 400000/400000/134217728
2021-05-07T18:11:02.127 INFO client > wait_allocation
2021-05-07T18:11:02.127 TRACE client > -> wait_allocation
2021-05-07T18:11:02.128 TRACE hyper::client::pool > checkout waiting for idle connection: ("http", 127.0.0.1:5000)
2021-05-07T18:11:02.128 DEBUG reqwest::connect > starting new connection: http://127.0.0.1:5000/
2021-05-07T18:11:02.128 TRACE hyper::client::connect::http > Http::connect; scheme=Some("http"), host=Some("127.0.0.1"), port=Some(Port(5000))
2021-05-07T18:11:02.128 DEBUG hyper::client::connect::http > connecting to 127.0.0.1:5000
2021-05-07T18:11:02.128 TRACE mio::poll > registering event source with poller: token=Token(16777217), interests=READABLE | WRITABLE
2021-05-07T18:11:02.128 TRACE client > <- wait_allocation
2021-05-07T18:11:02.128 TRACE client > -> wait_allocation
2021-05-07T18:11:02.128 TRACE mio::poll > deregistering event source from poller
2021-05-07T18:11:02.128 TRACE hyper::client::connect::http > connect error for 127.0.0.1:5000: ConnectError("tcp connect error", Os { code: 111, kind: ConnectionRefused, message: "Connection refused" })
2021-05-07T18:11:02.128 TRACE hyper::client::pool > checkout dropped for ("http", 127.0.0.1:5000)
2021-05-07T18:11:02.128 TRACE client > <- wait_allocation
2021-05-07T18:11:02.128 TRACE client > -- wait_allocation
2021-05-07T18:11:02.129 TRACE client > <- schedule_one_of
2021-05-07T18:11:02.129 TRACE client > -- schedule_one_of
thread '<unnamed>' panicked at 'failed building tree: Scheduler(RpcError(Client(reqwest::Error { kind: Request, url: Url { scheme: "http", username: "", password: None, host: Some(Ipv4(127.0.0.1)), port: Some(5000), path: "/", query: None, fragment: None }, source: hyper::Error(Connect, ConnectError("tcp connect error", Os { code: 111, kind: ConnectionRefused, message: "Connection refused" })) })))', /home/nemo/pl/rust-fil-proofs/storage-proofs-porep/src/stacked/vanilla/proof.rs:631:37
stack backtrace:
0: rust_begin_unwind
at /rustc/2fd73fabe469357a12c2c974c140f67e7cdd76d0/library/std/src/panicking.rs:493:5
1: core::panicking::panic_fmt
at /rustc/2fd73fabe469357a12c2c974c140f67e7cdd76d0/library/core/src/panicking.rs:92:14
2: core::option::expect_none_failed
at /rustc/2fd73fabe469357a12c2c974c140f67e7cdd76d0/library/core/src/option.rs:1300:5
3: <std::panic::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once
4: std::panicking::try
5: <rayon_core::job::HeapJob<BODY> as rayon_core::job::Job>::execute
6: rayon_core::registry::WorkerThread::wait_until_cold
7: rayon_core::registry::ThreadBuilder::run
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
thread '<unnamed>' panicked at 'failed to send columns: "SendError(..)"', /home/nemo/pl/rust-fil-proofs/storage-proofs-porep/src/stacked/vanilla/proof.rs:thread '554<unnamed>:' panicked at '34failed to receive base_data, tree_data for tree_c: RecvError
', stack backtrace:
/home/nemo/pl/rust-fil-proofs/storage-proofs-porep/src/stacked/vanilla/proof.rs:637:26
0: rust_begin_unwind
at /rustc/2fd73fabe469357a12c2c974c140f67e7cdd76d0/library/std/src/panicking.rs:493:5
1: core::panicking::panic_fmt
at /rustc/2fd73fabe469357a12c2c974c140f67e7cdd76d0/library/core/src/panicking.rs:92:14
2: core::option::expect_none_failed
at /rustc/2fd73fabe469357a12c2c974c140f67e7cdd76d0/library/core/src/option.rs:1300:5
3: <std::panic::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once
4: std::panicking::try
5: <rayon_core::job::HeapJob<BODY> as rayon_core::job::Job>::execute
6: rayon_core::registry::WorkerThread::wait_until_cold
7: rayon_core::registry::ThreadBuilder::run
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
stack backtrace:
0: rust_begin_unwind
at /rustc/2fd73fabe469357a12c2c974c140f67e7cdd76d0/library/std/src/panicking.rs:493:5
1: core::panicking::panic_fmt
at /rustc/2fd73fabe469357a12c2c974c140f67e7cdd76d0/library/core/src/panicking.rs:92:14
2: core::option::expect_none_failed
at /rustc/2fd73fabe469357a12c2c974c140f67e7cdd76d0/library/core/src/option.rs:1300:5
3: <std::panic::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once
4: <std::panic::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once
5: <rayon_core::job::StackJob<L,F,R> as rayon_core::job::Job>::execute
6: rayon_core::registry::WorkerThread::wait_until_cold
7: rayon_core::registry::ThreadBuilder::run
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
test test_seal_lifecycle_32gib_porep_id_v1_1_top_8_8_0_api_v1_1 ... FAILED
failures:
failures:
test_seal_lifecycle_32gib_porep_id_v1_1_top_8_8_0_api_v1_1
test result: FAILED. 0 passed; 1 failed; 0 ignored; 0 measured; 21 filtered out; finished in 12438.02s
2021-05-07T18:11:02.303 DEBUG rust_gpu_tools::opencl::utils > loaded devices: {Nvidia: [Device { brand: Nvidia, name: "GeForce RTX 2080 Ti", memory: 11552096256, platform: Platform(PlatformId(0x7f528c114c40)), unique_id: Some(0), device: Device(DeviceId(0x7f528c106cb0)) }]}
2021-05-07T18:11:02.305 TRACE mio::poll > registering with poller
2021-05-07T18:11:02.306 TRACE mio::poll > registering with poller
error: test failed, to rerun pass '-p filecoin-proofs --test api'