Subspace CLI exits unexpectedly when starting farming

jim-counter · March 26, 2023, 1:10am

Issue Report

Environment

Operating System: Ubuntu 20.04
CPU Architecture: x64 i7-8700k
RAM: 32GiB
Storage: SSD
Plot Size: 1G
Subspace Deployment Method: CLi-0.1.11 V3

Problem

CLI exits unexpectedly with no errors logged.

Note that the user had just updated from CLI 0.1.10 ->0.1.11 due to experiencing this issue: Cannot block the current thread from within a runtime.

Steps to reproduce

Run CLI 0.1.11 v3.

Expected result

Node syncs and farming starts

What happens instead

Node syncs, farmer starts and then whole CLI exits with no error logged.

{"v":0,"name":"subspace-cli","msg":"Increase file limit from soft to hard (limit is 1048576)","level":30,"hostname":"001ubuntu","pid":18226,"time":"2023-03-26T00:57:57.352274057Z","target":"subspace_cli::utils","line":178,"file":"src/utils.rs"}
{"v":0,"name":"subspace-cli","msg":"[VALIDATE_CONFIG - START]","level":30,"hostname":"001ubuntu","pid":18226,"time":"2023-03-26T00:57:57.352544931Z","target":"subspace_cli::config","line":204,"file":"src/config.rs"}
{"v":0,"name":"subspace-cli","msg":"[PARSE_CONFIG - START]","level":30,"hostname":"001ubuntu","pid":18226,"time":"2023-03-26T00:57:57.352605768Z","target":"subspace_cli::config","line":194,"file":"src/config.rs"}
{"v":0,"name":"subspace-cli","msg":"[PARSE_CONFIG - END]","level":30,"hostname":"001ubuntu","pid":18226,"time":"2023-03-26T00:57:57.352982274Z","target":"subspace_cli::config","line":194,"file":"src/config.rs"}
{"v":0,"name":"subspace-cli","msg":"[VALIDATE_CONFIG - END]","level":30,"hostname":"001ubuntu","pid":18226,"time":"2023-03-26T00:57:57.353153315Z","target":"subspace_cli::config","line":204,"file":"src/config.rs"}
{"v":0,"name":"subspace-cli","msg":"Storage provider cache loaded - 1095991 items.","level":30,"hostname":"001ubuntu","pid":18226,"time":"2023-03-26T00:57:57.693021734Z","target":"subspace_service::piece_cache","line":60,"file":"/home/runner/.cargo/git/checkouts/subspace-5c1447fb849a5554/c0dbb17/crates/subspace-service/src/piece_cache.rs"}
{"v":0,"name":"subspace-cli","msg":"DSN instance configured.","level":30,"hostname":"001ubuntu","pid":18226,"time":"2023-03-26T00:57:58.140854168Z","target":"subspace_networking::create","line":386,"file":"/home/runner/.cargo/git/checkouts/subspace-5c1447fb849a5554/c0dbb17/crates/subspace-networking/src/create.rs","allow_non_global_addresses_in_dht":"false","peer_id":"12D3KooWP8acS4iptgjPvZj1TRpZodWdRb3NTyWV7TnVBj39mvro"}
{"v":0,"name":"subspace-cli","msg":"Last archived block 605869","level":30,"hostname":"001ubuntu","pid":18226,"time":"2023-03-26T00:58:01.482643216Z","target":"log","line":null,"file":null,"log.file":"/home/runner/.cargo/git/checkouts/subspace-5c1447fb849a5554/c0dbb17/crates/sc-consensus-subspace/src/archiver.rs","log.module_path":"sc_consensus_subspace::archiver","log.target":"subspace","log.line":206}
{"v":0,"name":"subspace-cli","msg":"Archiving already produced blocks 605870..=606240","level":30,"hostname":"001ubuntu","pid":18226,"time":"2023-03-26T00:58:01.507523469Z","target":"log","line":null,"file":null,"log.module_path":"sc_consensus_subspace::archiver","log.target":"subspace","log.file":"/home/runner/.cargo/git/checkouts/subspace-5c1447fb849a5554/c0dbb17/crates/sc-consensus-subspace/src/archiver.rs","log.line":261}
{"v":0,"name":"subspace-cli","msg":"🏷  Local node identity is: 12D3KooWP8acS4iptgjPvZj1TRpZodWdRb3NTyWV7TnVBj39mvro","level":30,"hostname":"001ubuntu","pid":18226,"time":"2023-03-26T00:58:05.110384949Z","target":"log","line":null,"file":null,"log.line":217,"log.target":"sub-libp2p","log.module_path":"sc_network::service","log.file":"/home/runner/.cargo/git/checkouts/substrate-7bc20b373ca3e834/100d6c9/client/network/src/service.rs"}
{"v":0,"name":"subspace-cli","msg":"🧑‍🌾 Starting Subspace Authorship worker","level":30,"hostname":"001ubuntu","pid":18226,"time":"2023-03-26T00:58:05.122615872Z","target":"log","line":null,"file":null,"log.target":"subspace","log.module_path":"sc_consensus_subspace","log.line":405,"log.file":"/home/runner/.cargo/git/checkouts/subspace-5c1447fb849a5554/c0dbb17/crates/sc-consensus-subspace/src/lib.rs"}
{"v":0,"name":"subspace-cli","msg":"💻 Operating system: linux","level":30,"hostname":"001ubuntu","pid":18226,"time":"2023-03-26T00:58:05.124925268Z","target":"log","line":null,"file":null,"log.line":106,"log.module_path":"sc_sysinfo","log.file":"/home/runner/.cargo/git/checkouts/substrate-7bc20b373ca3e834/100d6c9/client/sysinfo/src/lib.rs","log.target":"sc_sysinfo"}
{"v":0,"name":"subspace-cli","msg":"💻 CPU architecture: x86_64","level":30,"hostname":"001ubuntu","pid":18226,"time":"2023-03-26T00:58:05.12494172Z","target":"log","line":null,"file":null,"log.module_path":"sc_sysinfo","log.file":"/home/runner/.cargo/git/checkouts/substrate-7bc20b373ca3e834/100d6c9/client/sysinfo/src/lib.rs","log.line":107,"log.target":"sc_sysinfo"}
{"v":0,"name":"subspace-cli","msg":"💻 Target environment: gnu","level":30,"hostname":"001ubuntu","pid":18226,"time":"2023-03-26T00:58:05.124959059Z","target":"log","line":null,"file":null,"log.target":"sc_sysinfo","log.file":"/home/runner/.cargo/git/checkouts/substrate-7bc20b373ca3e834/100d6c9/client/sysinfo/src/lib.rs","log.line":109,"log.module_path":"sc_sysinfo"}
{"v":0,"name":"subspace-cli","msg":"💻 CPU: Intel(R) Core(TM) i7-8700K CPU @ 3.70GHz","level":30,"hostname":"001ubuntu","pid":18226,"time":"2023-03-26T00:58:05.124965939Z","target":"log","line":null,"file":null,"log.file":"/home/runner/.cargo/git/checkouts/substrate-7bc20b373ca3e834/100d6c9/client/sysinfo/src/lib.rs","log.module_path":"sc_sysinfo","log.target":"sc_sysinfo","log.line":113}
{"v":0,"name":"subspace-cli","msg":"💻 CPU cores: 6","level":30,"hostname":"001ubuntu","pid":18226,"time":"2023-03-26T00:58:05.12497251Z","target":"log","line":null,"file":null,"log.line":116,"log.target":"sc_sysinfo","log.module_path":"sc_sysinfo","log.file":"/home/runner/.cargo/git/checkouts/substrate-7bc20b373ca3e834/100d6c9/client/sysinfo/src/lib.rs"}
{"v":0,"name":"subspace-cli","msg":"💻 Memory: 31971MB","level":30,"hostname":"001ubuntu","pid":18226,"time":"2023-03-26T00:58:05.124979086Z","target":"log","line":null,"file":null,"log.file":"/home/runner/.cargo/git/checkouts/substrate-7bc20b373ca3e834/100d6c9/client/sysinfo/src/lib.rs","log.module_path":"sc_sysinfo","log.target":"sc_sysinfo","log.line":119}
{"v":0,"name":"subspace-cli","msg":"💻 Kernel: 5.19.0-35-generic","level":30,"hostname":"001ubuntu","pid":18226,"time":"2023-03-26T00:58:05.124985565Z","target":"log","line":null,"file":null,"log.module_path":"sc_sysinfo","log.file":"/home/runner/.cargo/git/checkouts/substrate-7bc20b373ca3e834/100d6c9/client/sysinfo/src/lib.rs","log.line":122,"log.target":"sc_sysinfo"}
{"v":0,"name":"subspace-cli","msg":"💻 Linux distribution: Ubuntu 22.04 LTS","level":30,"hostname":"001ubuntu","pid":18226,"time":"2023-03-26T00:58:05.124993664Z","target":"log","line":null,"file":null,"log.module_path":"sc_sysinfo","log.line":125,"log.target":"sc_sysinfo","log.file":"/home/runner/.cargo/git/checkouts/substrate-7bc20b373ca3e834/100d6c9/client/sysinfo/src/lib.rs"}
{"v":0,"name":"subspace-cli","msg":"💻 Virtual machine: no","level":30,"hostname":"001ubuntu","pid":18226,"time":"2023-03-26T00:58:05.125004358Z","target":"log","line":null,"file":null,"log.target":"sc_sysinfo","log.module_path":"sc_sysinfo","log.file":"/home/runner/.cargo/git/checkouts/substrate-7bc20b373ca3e834/100d6c9/client/sysinfo/src/lib.rs","log.line":128}
{"v":0,"name":"subspace-cli","msg":"📦 Highest known block at #606340","level":30,"hostname":"001ubuntu","pid":18226,"time":"2023-03-26T00:58:05.135156695Z","target":"log","line":null,"file":null,"log.target":"sc_service::builder","log.module_path":"sc_service::builder","log.line":493,"log.file":"/home/runner/.cargo/git/checkouts/substrate-7bc20b373ca3e834/100d6c9/client/service/src/builder.rs"}
{"v":0,"name":"subspace-cli","msg":"Running JSON-RPC HTTP server: addr=127.0.0.1:9933, allowed origins=[\"http://localhost:*\", \"http://127.0.0.1:*\", \"https://localhost:*\", \"https://127.0.0.1:*\", \"https://polkadot.js.org\"]","level":30,"hostname":"001ubuntu","pid":18226,"time":"2023-03-26T00:58:05.136326289Z","target":"log","line":null,"file":null,"log.file":"/home/runner/.cargo/git/checkouts/substrate-7bc20b373ca3e834/100d6c9/client/rpc-servers/src/lib.rs","log.line":121,"log.target":"sc_rpc_server","log.module_path":"sc_rpc_server"}
{"v":0,"name":"subspace-cli","msg":"Running JSON-RPC WS server: addr=127.0.0.1:9944, allowed origins=[\"http://localhost:*\", \"http://127.0.0.1:*\", \"https://localhost:*\", \"https://127.0.0.1:*\", \"https://polkadot.js.org\"]","level":30,"hostname":"001ubuntu","pid":18226,"time":"2023-03-26T00:58:05.136629249Z","target":"log","line":null,"file":null,"log.target":"sc_rpc_server","log.module_path":"sc_rpc_server","log.file":"/home/runner/.cargo/git/checkouts/substrate-7bc20b373ca3e834/100d6c9/client/rpc-servers/src/lib.rs","log.line":177}
{"v":0,"name":"subspace-cli","msg":"creating instance on iface 192.168.110.59","level":30,"hostname":"001ubuntu","pid":18226,"time":"2023-03-26T00:58:05.137927248Z","target":"log","line":null,"file":null,"log.target":"libp2p_mdns::behaviour::iface","log.file":"/home/runner/.cargo/registry/src/github.com-1ecc6299db9ec823/libp2p-mdns-0.42.0/src/behaviour/iface.rs","log.module_path":"libp2p_mdns::behaviour::iface","log.line":78}
{"v":0,"name":"subspace-cli","msg":"🔍 Discovered new external address for our node: /ip4/117.84.123.217/tcp/30333/p2p/12D3KooWP8acS4iptgjPvZj1TRpZodWdRb3NTyWV7TnVBj39mvro","level":30,"hostname":"001ubuntu","pid":18226,"time":"2023-03-26T00:58:06.733903739Z","target":"log","line":null,"file":null,"log.target":"sub-libp2p","log.module_path":"sc_network::discovery","log.file":"/home/runner/.cargo/git/checkouts/substrate-7bc20b373ca3e834/100d6c9/client/network/src/discovery.rs","log.line":576}
{"v":0,"name":"subspace-cli","msg":"🔍 Discovered new external address for our node: /ip4/117.84.124.123/tcp/30333/p2p/12D3KooWP8acS4iptgjPvZj1TRpZodWdRb3NTyWV7TnVBj39mvro","level":30,"hostname":"001ubuntu","pid":18226,"time":"2023-03-26T00:58:06.741337718Z","target":"log","line":null,"file":null,"log.target":"sub-libp2p","log.module_path":"sc_network::discovery","log.line":576,"log.file":"/home/runner/.cargo/git/checkouts/substrate-7bc20b373ca3e834/100d6c9/client/network/src/discovery.rs"}
{"v":0,"name":"subspace-cli","msg":"🔍 Discovered new external address for our node: /ip4/117.84.125.180/tcp/30333/p2p/12D3KooWP8acS4iptgjPvZj1TRpZodWdRb3NTyWV7TnVBj39mvro","level":30,"hostname":"001ubuntu","pid":18226,"time":"2023-03-26T00:58:06.79130466Z","target":"log","line":null,"file":null,"log.target":"sub-libp2p","log.module_path":"sc_network::discovery","log.line":576,"log.file":"/home/runner/.cargo/git/checkouts/substrate-7bc20b373ca3e834/100d6c9/client/network/src/discovery.rs"}
{"v":0,"name":"subspace-cli","msg":"⚙️  \u001b[1;37mPreparing\u001b[0m, target=#606363 (\u001b[1;37m31\u001b[0m peers), best: #\u001b[1;37m606342\u001b[0m (0xe33c…234c), finalized #\u001b[1;37m606242\u001b[0m (0xa900…cdcd), \u001b[32m⬇ 52.2kiB/s\u001b[0m \u001b[31m⬆ 18.9kiB/s\u001b[0m","level":30,"hostname":"001ubuntu","pid":18226,"time":"2023-03-26T00:58:10.137498057Z","target":"log","line":null,"file":null,"log.file":"/home/runner/.cargo/git/checkouts/substrate-7bc20b373ca3e834/100d6c9/client/informant/src/display.rs","log.line":130,"log.module_path":"sc_informant::display","log.target":"substrate"}
{"v":0,"name":"subspace-cli","msg":"⚙️  \u001b[1;37mPreparing  2.8 bps\u001b[0m, target=#606363 (\u001b[1;37m80\u001b[0m peers), best: #\u001b[1;37m606356\u001b[0m (0x5dbe…1646), finalized #\u001b[1;37m606256\u001b[0m (0xe38c…e463), \u001b[32m⬇ 63.9kiB/s\u001b[0m \u001b[31m⬆ 39.7kiB/s\u001b[0m","level":30,"hostname":"001ubuntu","pid":18226,"time":"2023-03-26T00:58:15.137750933Z","target":"log","line":null,"file":null,"log.line":130,"log.module_path":"sc_informant::display","log.target":"substrate","log.file":"/home/runner/.cargo/git/checkouts/substrate-7bc20b373ca3e834/100d6c9/client/informant/src/display.rs"}
{"v":0,"name":"subspace-cli","msg":"✨ Imported #\u001b[1;37m606364\u001b[0m (0x18fb…e03e)","level":30,"hostname":"001ubuntu","pid":18226,"time":"2023-03-26T00:58:19.162908107Z","target":"log","line":null,"file":null,"log.line":139,"log.module_path":"sc_informant","log.file":"/home/runner/.cargo/git/checkouts/substrate-7bc20b373ca3e834/100d6c9/client/informant/src/lib.rs","log.target":"substrate"}
{"v":0,"name":"subspace-cli","msg":"✨ Imported #\u001b[1;37m606365\u001b[0m (0x3e01…3517)","level":30,"hostname":"001ubuntu","pid":18226,"time":"2023-03-26T00:58:19.557783951Z","target":"log","line":null,"file":null,"log.module_path":"sc_informant","log.line":139,"log.target":"substrate","log.file":"/home/runner/.cargo/git/checkouts/substrate-7bc20b373ca3e834/100d6c9/client/informant/src/lib.rs"}
{"v":0,"name":"subspace-cli","msg":"✨ Imported #\u001b[1;37m606366\u001b[0m (0x727e…ebb7)","level":30,"hostname":"001ubuntu","pid":18226,"time":"2023-03-26T00:58:19.858800161Z","target":"log","line":null,"file":null,"log.target":"substrate","log.module_path":"sc_informant","log.file":"/home/runner/.cargo/git/checkouts/substrate-7bc20b373ca3e834/100d6c9/client/informant/src/lib.rs","log.line":139}
{"v":0,"name":"subspace-cli","msg":"💤 \u001b[1;37mIdle\u001b[0m (\u001b[1;37m83\u001b[0m peers), best: #\u001b[1;37m606366\u001b[0m (0x727e…ebb7), finalized #\u001b[1;37m606266\u001b[0m (0x29fa…7120), \u001b[32m⬇ 102.5kiB/s\u001b[0m \u001b[31m⬆ 75.6kiB/s\u001b[0m","level":30,"hostname":"001ubuntu","pid":18226,"time":"2023-03-26T00:58:20.13791172Z","target":"log","line":null,"file":null,"log.file":"/home/runner/.cargo/git/checkouts/substrate-7bc20b373ca3e834/100d6c9/client/informant/src/display.rs","log.line":130,"log.target":"substrate","log.module_path":"sc_informant::display"}
{"v":0,"name":"subspace-cli","msg":"♻️  Reorg on #\u001b[1;31m606366\u001b[0m,0x727e…ebb7 to #\u001b[1;32m606366\u001b[0m,0x3959…cdfb, common ancestor #\u001b[1;37m606365\u001b[0m,0x3e01…3517","level":30,"hostname":"001ubuntu","pid":18226,"time":"2023-03-26T00:58:20.211313973Z","target":"log","line":null,"file":null,"log.module_path":"sc_informant","log.line":111,"log.target":"sc_informant","log.file":"/home/runner/.cargo/git/checkouts/substrate-7bc20b373ca3e834/100d6c9/client/informant/src/lib.rs"}
{"v":0,"name":"subspace-cli","msg":"✨ Imported #\u001b[1;37m606366\u001b[0m (0x3959…cdfb)","level":30,"hostname":"001ubuntu","pid":18226,"time":"2023-03-26T00:58:20.211431359Z","target":"log","line":null,"file":null,"log.line":139,"log.module_path":"sc_informant","log.target":"substrate","log.file":"/home/runner/.cargo/git/checkouts/substrate-7bc20b373ca3e834/100d6c9/client/informant/src/lib.rs"}
{"v":0,"name":"subspace-cli","msg":"[NEW - START]","level":30,"hostname":"001ubuntu","pid":18226,"time":"2023-03-26T00:58:23.836455113Z","target":"subspace_cli::summary","line":35,"file":"src/summary.rs"}
{"v":0,"name":"subspace-cli","msg":"[SUMMARY_PATH - START]","level":30,"hostname":"001ubuntu","pid":18226,"time":"2023-03-26T00:58:23.836499518Z","target":"subspace_cli::summary","line":142,"file":"src/summary.rs"}
{"v":0,"name":"subspace-cli","msg":"[SUMMARY_PATH - END]","level":30,"hostname":"001ubuntu","pid":18226,"time":"2023-03-26T00:58:23.836516261Z","target":"subspace_cli::summary","line":142,"file":"src/summary.rs","user_space_pledged":"Some(1000.0 MB)"}
{"v":0,"name":"subspace-cli","msg":"Initializing provider storage...","level":30,"hostname":"001ubuntu","pid":18226,"time":"2023-03-26T00:58:23.836847485Z","target":"subspace_sdk::farmer","line":491,"file":"/home/runner/.cargo/git/checkouts/subspace-sdk-cf03f5a296714cdf/a616372/src/farmer.rs","db_path":"\"/root/.local/share/subspace-cli/cache/providers_db\"","keys_limit":"655360"}
{"v":0,"name":"subspace-cli","msg":"Initializing piece cache...","level":30,"hostname":"001ubuntu","pid":18226,"time":"2023-03-26T00:58:23.837872365Z","target":"subspace_sdk::farmer","line":503,"file":"/home/runner/.cargo/git/checkouts/subspace-sdk-cf03f5a296714cdf/a616372/src/farmer.rs","size":"330","db_path":"\"/root/.local/share/subspace-cli/cache/piece_cache_db\""}
{"v":0,"name":"subspace-cli","msg":"Piece cache initialized successfully","level":30,"hostname":"001ubuntu","pid":18226,"time":"2023-03-26T00:58:23.84066145Z","target":"subspace_sdk::farmer","line":514,"file":"/home/runner/.cargo/git/checkouts/subspace-sdk-cf03f5a296714cdf/a616372/src/farmer.rs","current_size":"330"}
{"v":0,"name":"subspace-cli","msg":"[SINGLE_DISK_PLOT - START]","level":30,"hostname":"001ubuntu","pid":18226,"time":"2023-03-26T00:58:23.844806579Z","target":"subspace_farmer::single_disk_plot","line":645,"file":"/home/runner/.cargo/git/checkouts/subspace-5c1447fb849a5554/c0dbb17/crates/subspace-farmer/src/single_disk_plot.rs"}
{"v":0,"name":"subspace-cli","msg":"[SINGLE_DISK_PLOT - EVENT] Subscribing to slot info notifications","level":30,"hostname":"001ubuntu","pid":18226,"time":"2023-03-26T00:58:23.845314966Z","target":"subspace_farmer::single_disk_plot","line":791,"file":"/home/runner/.cargo/git/checkouts/subspace-5c1447fb849a5554/c0dbb17/crates/subspace-farmer/src/single_disk_plot.rs","disk_farm_index":"0"}
{"v":0,"name":"subspace-cli","msg":"[NEW - END]","level":30,"hostname":"001ubuntu","pid":18226,"time":"2023-03-26T00:58:23.845342811Z","target":"subspace_cli::summary","line":35,"file":"src/summary.rs","user_space_pledged":"Some(1000.0 MB)"}
{"v":0,"name":"subspace-cli","msg":"[SINGLE_DISK_PLOT - EVENT] Subscribing to reward signing notifications","level":30,"hostname":"001ubuntu","pid":18226,"time":"2023-03-26T00:58:23.845428201Z","target":"subspace_farmer::reward_signing","line":15,"file":"/home/runner/.cargo/git/checkouts/subspace-5c1447fb849a5554/c0dbb17/crates/subspace-farmer/src/reward_signing.rs","disk_farm_index":"0"}
{"v":0,"name":"subspace-cli","msg":"[SINGLE_DISK_PLOT - END]","level":30,"hostname":"001ubuntu","pid":18226,"time":"2023-03-26T00:58:23.88400257Z","target":"subspace_farmer::single_disk_plot","line":645,"file":"/home/runner/.cargo/git/checkouts/subspace-5c1447fb849a5554/c0dbb17/crates/subspace-farmer/src/single_disk_plot.rs","disk_farm_index":"0"}

jim-counter · March 26, 2023, 9:42am

Pinging @Support-L2 as I believe we’ve seen other cases of this.

ImmaZoni · March 31, 2023, 4:18pm

Thanks for the ping jim, are we still seeing this on v0.1.12 aswell?

jim-counter · April 1, 2023, 6:15pm

Not that I’ve seen. The release notes suggest a fix for this specifically was implemented (first note here: Release v0.1.12 · subspace/subspace-cli · GitHub).

Topic		Replies	Views
Cannot block the current thread from within a runtime Support	11	538	March 28, 2023
An error occurred when starting Subspace Node. It is associated with a file or directory Support	0	179	March 17, 2023
Failed to start Subspace Node Support	2	316	June 9, 2023
Erreur after update v0.1.12 Support	1	186	March 31, 2023
Thread 'main' panicked at 'Failed to make runtime API call during last archived block search: UnknownBlock Support nodes , cli	10	189	September 17, 2023