Farmer 15-feb stop plotting, farming keep on

Issue Report

Environment

ubuntu 22.04
Advanced cli 1 node and 15 farmers all feb 15 version

Problem

After some time plotting stop and farming keep going on, log1

reverted back to feb 05 version sorted it out

log2 is when that happen ctrl+c can not stop process only way it to terminate with kill -9

I have 1 node and 15 farmers only 3 had this issue now, I have no logs from node as its not logged at that time

LOG1
2024-02-18T15:16:34.699954Z  INFO {disk_farm_index=4}: subspace_farmer::single_disk_farm::plotting: Plotting sector (29.10% complete) sector_index=1087
2024-02-18T15:16:44.041969Z  INFO {disk_farm_index=3}: subspace_farmer::single_disk_farm::plotting: Plotting sector (29.15% complete) sector_index=1089
2024-02-18T15:21:41.615334Z  INFO {disk_farm_index=6}: subspace_farmer::single_disk_farm::plotting: Plotting sector (29.18% complete) sector_index=1090
2024-02-18T15:56:09.326112Z  INFO {disk_farm_index=6}: subspace_farmer::reward_signing: Successfully signed reward hash 0xe05bed06dd1f1a2c617bf64c43fcce144bcd68830f125648524e2a19774172d


LOG2 after ctrl+c
2024-02-18T13:43:05.111504Z  INFO subspace_farmer::utils: Received SIGINT, shutting down farmer...
2024-02-18T13:43:05.111536Z  INFO actix_server::server: SIGINT received; starting forced shutdown
2024-02-18T13:43:05.111569Z  INFO actix_server::worker: shutting down idle worker
2024-02-18T13:43:05.111572Z  INFO actix_server::worker: shutting down idle worker
2024-02-18T13:43:05.111589Z  INFO actix_server:🉑 accept thread stopped"
2024-02-18T14:02:47.181651Z ERROR jsonrpsee_core::client::async_client::helpers: Dropping subscription Str("UhCMU5PagdkUoxIK") error: TrySendError { kind: Full }
2024-02-18T14:02:47.182124Z ERROR jsonrpsee_core::client::async_client::helpers: Dropping subscription Str("GJ2Y8vxx6ckqIuM5") error: TrySendError { kind: Full }
2024-02-18T14:02:47.182141Z ERROR jsonrpsee_core::client::async_client::helpers: Dropping subscription Str("lnm31a79DuaGLEgu") error: TrySendError { kind: Full }
1 Like

found one more farm that finished plotting stuck at replot and farming work, what is strange that SM1 monitor that track it over RPC see it as offline so that mean farmer do not respond on query on grafana port

To note note MOST node stopped plotting when replot STARTED reploting process got stuck on most at 0% as seen on last log and farming keep going
Alos metric port RPC is not working anymore (timeout) from farmer

Also few farmers that just plot on HDD with disabled farming keep plotting so far

024-02-18T03:13:51.024841Z  INFO {disk_farm_index=0}: subspace_farmer::single_disk_farm::plotting: Replotting sector (0.00% complete) sector_index=820
2024-02-18T03:13:51.046385Z  INFO {disk_farm_index=1}: subspace_farmer::single_disk_farm::plotting: Replotting sector (0.00% complete) sector_index=331
2024-02-18T03:56:15.805576Z  INFO {disk_farm_index=1}: subspace_farmer::reward_signing: Successfully signed reward hash 0xcc7d5de47c195502227d4b7b8c9ad93831271dd527d669884fd04d5b79061db8
2024-02-18T04:20:50.438514Z  INFO {disk_farm_index=0}: subspace_farmer::reward_signing: Successfully signed reward hash 0xccf96ef25f229c73ffdf26f9247882e154f114759a190f572161080d3b98f973
2024-02-18T05:08:11.896249Z  INFO {disk_farm_index=0}: subspace_farmer::reward_signing: Successfully signed reward hash 0x710ba31807fdf2aa14f390ac66dbc722f42349b2716caea1b98ee672259d711e
2024-02-18T05:41:48.027175Z  INFO {disk_farm_index=0}: subspace_farmer::reward_signing: Successfully signed reward hash 0xb42227fc1e02e4a1a73ebc39a1c19b076669cae6deb8abab89d3eaa46d71d8a0
2024-02-18T06:12:23.545939Z  INFO {disk_farm_index=0}: subspace_farmer::reward_signing: Successfully signed reward hash 0x719e58b8cd7f235eb483bcf3500fc85df4940c5de7013ecbfec5c23627938489
2024-02-18T07:03:40.274952Z  INFO {disk_farm_index=0}: subspace_farmer::reward_signing: Successfully signed reward hash 0x270cbd8bcb44ae0c6283ea0242435ed06e21315b55528071961933f4956d02ad
2024-02-18T07:26:59.083502Z  INFO {disk_farm_index=0}: subspace_farmer::reward_signing: Successfully signed reward hash 0x3bcc572813359b0d4208fa0b2977a9e313d2eeb53bb19674525d84a97a3cec01
2024-02-18T08:24:46.029232Z  INFO {disk_farm_index=0}: subspace_farmer::reward_signing: Successfully signed reward hash 0xcd689c017d1568297246108f7abd071b8dc80869ea524997056247fa67a052e3
2024-02-18T08:27:34.995687Z  INFO {disk_farm_index=1}: subspace_farmer::reward_signing: Successfully signed reward hash 0xee400f28c8ea714b0dc929f52317bbb43bda94d30e9d7aabd6a5d907aa5acf67
2024-02-18T08:30:06.588361Z  INFO {disk_farm_index=1}: subspace_farmer::reward_signing: Successfully signed reward hash 0x6743ac365232af97f7c6345f4b8f77086a9fa9fa0d26513a8819cf137987afb3
2024-02-18T08:34:13.594059Z  INFO {disk_farm_index=0}: subspace_farmer::reward_signing: Successfully signed reward hash 0x488c1c0a6d67c1f12a2a92e6458a6f93ae0c37d338e930cbfaad7fa349f5b2e4
2024-02-18T09:12:52.463322Z  INFO {disk_farm_index=1}: subspace_farmer::reward_signing: Successfully signed reward hash 0xf0eaeb993a95c67ded4f946f4ee453aee4afa8988271feed8d563e910935628b
2024-02-18T09:42:00.569368Z  INFO {disk_farm_index=1}: subspace_farmer::reward_signing: Successfully signed reward hash 0x1bf60b1a454d45ea589a9994d9d7570205de3ada92588878b9cc7bed38e61767
2024-02-18T09:53:12.116585Z  INFO {disk_farm_index=1}: subspace_farmer::reward_signing: Successfully signed reward hash 0x885c67b2d60251acd6f87dc2971e531fb1b4dba42de4f9db5dfdbfc03af34c4e
2024-02-18T10:24:53.113113Z  INFO {disk_farm_index=1}: subspace_farmer::reward_signing: Successfully signed reward hash 0xc4df293f25c23695eeac95eeb6c947c69a3a3deadf86945c8c1955ce752eecab
2024-02-18T10:38:56.176813Z  INFO {disk_farm_index=1}: subspace_farmer::reward_signing: Successfully signed reward hash 0x9f77064a44a9ef74141957b731e4443fcf16ccce9cfa787d5fb3fe9c3a3d5b06
2024-02-18T11:10:57.589977Z  INFO {disk_farm_index=1}: subspace_farmer::reward_signing: Successfully signed reward hash 0x8d4a4d96d06c8d9a70a085f356894969423cc81431f17966780edf422932a213
2024-02-18T12:04:19.368245Z  INFO {disk_farm_index=0}: subspace_farmer::reward_signing: Successfully signed reward hash 0x5af3535db2a49d824f932372efc4fd29bfee04e32debdaac801408d4d62622c8
2024-02-18T12:42:02.890155Z  INFO {disk_farm_index=0}: subspace_farmer::reward_signing: Successfully signed reward hash 0x3ae2b9cbb70298011e44e1c46f81de6008db94708a59b57c7946d0570b186dbe
2024-02-18T13:36:35.000321Z  INFO {disk_farm_index=1}: subspace_farmer::reward_signing: Successfully signed reward hash 0x9264af328746ebddbc1ac9a7f818139895a6fb42d900fdc44c934946251d3fb1
2024-02-18T13:42:34.915215Z  INFO {disk_farm_index=2}: subspace_farmer::reward_signing: Successfully signed reward hash 0xe59619f2fb1083ba67216a248bab4bcaf64fe692be72e19526cee9f349c448fc
2024-02-18T15:41:28.496202Z  INFO {disk_farm_index=0}: subspace_farmer::reward_signing: Successfully signed reward hash 0x69b1c3918667a25c3016227fe95ab30dcabd7b5a2579c13a124e87008366652d
2024-02-18T16:36:33.011107Z  INFO {disk_farm_index=0}: subspace_farmer::reward_signing: Successfully signed reward hash 0x5b6ce4c489331903ba3b51fab1a0fe9891a2d30a23ed451a35caf5ab1139bac1
2024-02-18T17:33:23.120206Z  INFO {disk_farm_index=0}: subspace_farmer::reward_signing: Successfully signed reward hash 0x3e75c18b8f3fa6e59d3f5dd2bb457a714e4d07c73b66a3d2e17cce2b4f8a9618
2024-02-18T17:34:31.984294Z  INFO {disk_farm_index=2}: subspace_farmer::reward_signing: Successfully signed reward hash 0x5d7694d2a24f6e03666f83b6be55ddfd472d6a74679eea83b04952b249cce332
2024-02-18T17:52:05.920429Z  INFO {disk_farm_index=1}: subspace_farmer::reward_signing: Successfully signed reward hash 0x1994f364453e03b1942f6419e0c527389915c7908071ae7e300685bd2ad6f697
^C2024-02-18T19:46:27.711339Z  INFO subspace_farmer::utils: Received SIGINT, shutting down farmer...
2024-02-18T19:46:27.711339Z  INFO actix_server::server: SIGINT received; starting forced shutdown
2024-02-18T19:46:27.711390Z  INFO actix_server::accept: accept thread stopped

This is log from node but you can see only break in connection when I did kill the farmer process as it refusing to exit nacely

2024-02-18T19:49:02.707664Z  INFO Consensus: substrate: 💤 Idle (40 peers), best: #271980 (0x8938…5d8e), finalized #171258 (0x1e72…cb2f), ⬇ 55.4kiB/s ⬆ 53.5kiB/s
2024-02-18T19:49:07.708059Z  INFO Consensus: substrate: 💤 Idle (40 peers), best: #271980 (0x8938…5d8e), finalized #171258 (0x1e72…cb2f), ⬇ 31.9kiB/s ⬆ 46.0kiB/s
2024-02-18T19:49:12.708437Z  INFO Consensus: substrate: 💤 Idle (40 peers), best: #271980 (0x8938…5d8e), finalized #171258 (0x1e72…cb2f), ⬇ 34.1kiB/s ⬆ 44.0kiB/s
2024-02-18T19:49:17.003564Z  INFO Consensus: substrate: ✨ Imported #271981 (0x6b2b…7cc7)
2024-02-18T19:49:17.708927Z  INFO Consensus: substrate: 💤 Idle (40 peers), best: #271981 (0x6b2b…7cc7), finalized #171258 (0x1e72…cb2f), ⬇ 30.5kiB/s ⬆ 60.2kiB/s
2024-02-18T19:49:19.778771Z ERROR connection{remote_addr=192.168.5.12:46122 conn_id=3}: jsonrpsee_server::transport::ws: WS transport error: i/o error: Connection reset by peer (os error 104); terminate connection: 3
2024-02-18T19:49:19.779009Z ERROR connection{remote_addr=192.168.5.12:46106 conn_id=2}: jsonrpsee_server::transport::ws: WS transport error: i/o error: Connection reset by peer (os error 104); terminate connection: 2

As I already mentioned in discord TWICE I would need full log from node and farmer since when they started, not just selective last lines that you decided to share.

Also check per-core CPU usage of farmer, see if there is any thread that uses 100% of CPU.

I have no full log I can enable loging and keep full log and post later when it happen again

I’m specifically interested in node logs here.

Also full command used to run farmer would help. I just tried to reproduce with 1 sector that is immediately replotted and didn’t see such an issue.

Does farmer exit eventually or gets stuck for more than a few minutes on Ctrl+C? Significant CPU usage in the process?

Its does not exit at all, I waited 40min, there was some CPU use but I am not sure if one core was constant 100% or not, farming keep working, node log showed nothing then, only forced farmer disconnect
Node errors where just on forced farmer kill which shoved as losing connection to farmer, new logs only when next time issue start as I now have logs enabled for node

Reproduced, working on a fix

1 Like

My farmer stopped today with 2024-02-19T12:56:53.622148Z ERROR jsonrpsee_core::client::async_client::helpers: Dropping subscription Str(“fPkE9sYEXIwyW6Fx”) error: TrySendError { kind: Full } error. There was no log of this event in the node and it kept working . The farmer was farming fully plotted plots.

I wanted to add this info here as the error I noticed today could be related to this post

I have seen the same issue on windows, only happens where there are disks fully plotted and when replotting starts. Also the metrics endpoint stops working too

Should be fixed in Release gemini-3h-2024-feb-19 · subspace/subspace · GitHub and Release 0.1.3 · subspace/space-acres · GitHub

1 Like

same error here with mar-04

This error was fixed and should not be reproducible on mar-04. If you see an issue that looks similar, please create a separate topic and provide corresponding details there.