Oct. 3 windows release not signing rewards

Issue Report

The Oct. 3 windows (skylake) release is not signing any rewards. After the node have sync-ed, there were no rewards for 30 minutes with a 14TB farm (split among 5 farmers).
In addition, this behavior started right after the sep 25 release as the sep 25 release does sign rewards.

Environment

  • Node/Farmer machine: Windows 11, Intel 13700K, 64GB DDR5 Memory (plus 4 other misc windows 11 machines that run farmers pointing to the Node machine)
  • Advanced CLI
4 Likes

Is it 5 farms with a single farmer application or 5 completely separate farmer applications?

It’s 5 separate farmer instances.

The main machine have one node instance running and one farmer instance running (the farmer farms multiple sata ssd drives)

The other 4 farmers (all farms multiple sata ssd drives) run on different machines and points back to the main machine running the node instance.

In previous releases (ie. oct. 1) I’ve also tried taking the other 4 farmers out of the equation by running just the main machine with one node and one farmer and saw the same result of no signing activities.

Is farmer using a lot of CPU when this happens?

Nope, everything is plotted, the main machine usually sits around 30% cpu and there is no replotting going on at that time.

Okay, would you be able to run a farmer with RUST_LOG=info,subspace_farmer=debug environment variable set for 2 minutes and provide logs to me to check what is going on there?

where do you set them? I’ve tried setting them in the windows environment variables section, rebooted, and started up the farmer again but the logs still show info

We have example of how to set environment variables in PowerShell in docs here, just replace with the variable I have provided above: Advanced CLI | Farm from Anywhere

thanks for that link! have logs, but there’s no file attachments here?

Use pastebin.com or similar and just drop the link here

there was a char limit on pastebin so I just copied the section of the logs that seem useful, the rest of the logs were repeating

As suspected and commented on Discord this seems to be related to the fact that there are fewer threads available now.

Looking at these lines:

2023-10-03T19:20:20.021291Z DEBUG single_disk_farm{disk_farm_index=0}: subspace_farmer::single_disk_farm: New slot slot_info=SlotInfo { slot_number: 1696360820, global_challenge: [103, 80, 43, 172, 189, 80, 91, 45, 9, 17, 91, 178, 115, 44, 222, 215, 226, 36, 218, 23, 149, 216, 117, 40, 127, 159, 149, 8, 230, 232, 232, 114], solution_range: 476796041, voting_solution_range: 4767960410 }
2023-10-03T19:20:20.021338Z DEBUG single_disk_farm{disk_farm_index=5}: subspace_farmer::single_disk_farm: New slot slot_info=SlotInfo { slot_number: 1696360820, global_challenge: [103, 80, 43, 172, 189, 80, 91, 45, 9, 17, 91, 178, 115, 44, 222, 215, 226, 36, 218, 23, 149, 216, 117, 40, 127, 159, 149, 8, 230, 232, 232, 114], solution_range: 476796041, voting_solution_range: 4767960410 }
2023-10-03T19:20:20.021348Z DEBUG single_disk_farm{disk_farm_index=1}: subspace_farmer::single_disk_farm: New slot slot_info=SlotInfo { slot_number: 1696360820, global_challenge: [103, 80, 43, 172, 189, 80, 91, 45, 9, 17, 91, 178, 115, 44, 222, 215, 226, 36, 218, 23, 149, 216, 117, 40, 127, 159, 149, 8, 230, 232, 232, 114], solution_range: 476796041, voting_solution_range: 4767960410 }
2023-10-03T19:20:20.021358Z DEBUG single_disk_farm{disk_farm_index=3}: subspace_farmer::single_disk_farm: New slot slot_info=SlotInfo { slot_number: 1696360820, global_challenge: [103, 80, 43, 172, 189, 80, 91, 45, 9, 17, 91, 178, 115, 44, 222, 215, 226, 36, 218, 23, 149, 216, 117, 40, 127, 159, 149, 8, 230, 232, 232, 114], solution_range: 476796041, voting_solution_range: 4767960410 }
2023-10-03T19:20:20.021366Z DEBUG single_disk_farm{disk_farm_index=2}: subspace_farmer::single_disk_farm: New slot slot_info=SlotInfo { slot_number: 1696360820, global_challenge: [103, 80, 43, 172, 189, 80, 91, 45, 9, 17, 91, 178, 115, 44, 222, 215, 226, 36, 218, 23, 149, 216, 117, 40, 127, 159, 149, 8, 230, 232, 232, 114], solution_range: 476796041, voting_solution_range: 4767960410 }
2023-10-03T19:20:20.021375Z DEBUG single_disk_farm{disk_farm_index=4}: subspace_farmer::single_disk_farm: New slot slot_info=SlotInfo { slot_number: 1696360820, global_challenge: [103, 80, 43, 172, 189, 80, 91, 45, 9, 17, 91, 178, 115, 44, 222, 215, 226, 36, 218, 23, 149, 216, 117, 40, 127, 159, 149, 8, 230, 232, 232, 114], solution_range: 476796041, voting_solution_range: 4767960410 }
2023-10-03T19:20:20.021549Z DEBUG subspace_farmer::single_disk_farm::farming: Reading sectors slot=1696360820 sector_count=1404
2023-10-03T19:20:20.237522Z DEBUG subspace_farmer::single_disk_farm::farming: Reading sectors slot=1696360820 sector_count=210
2023-10-03T19:20:20.315463Z DEBUG subspace_farmer::single_disk_farm::farming: Reading sectors slot=1696360820 sector_count=889
2023-10-03T19:20:20.461547Z DEBUG subspace_farmer::single_disk_farm::farming: Reading sectors slot=1696360820 sector_count=702
2023-10-03T19:20:20.591070Z DEBUG subspace_farmer::single_disk_farm::farming: Reading sectors slot=1696360820 sector_count=702
2023-10-03T19:20:20.720081Z DEBUG subspace_farmer::single_disk_farm::farming: Reading sectors slot=1696360820 sector_count=702

We can see that there is at least 700ms gap between farmer receiving the notification that it is time to farm and even starting to audit some sectors.

Given that you have 5 farms and 13700K processor, older releases would have created 5*24=120 threads for auditing purposes. Can you try to start farmer with --farming-thread-pool-size=120 and see if it makes a difference? If not proving similar logs with debug information would help.

ok, tried the ‘–farming-thread-pool-size 120’ param, waited 40 minutes but unfortunately no rewards. for this test, I only used the main machine with the node and one farmer instance on it, the other machines were all turned off to make things simpler. also, once I flipped back to the sep 25th version, it got rewards within 10 minutes

copied logs here:

1 Like

I think I know what is happening there, will try to address this in the next release, thanks for doing tests!
Would you mind if I provide some experimental builds for you to try later today?

I have the same problem, no rewards.
Advanced CLI Oct 3-23 Ubuntu and Windows.

1 Like

Try this experimental build: Snapshot build · subspace/subspace@2df4b8f · GitHub
I think it should address the root issues you both are facing and will be included in the next release.

UPD: New release includes that fix as well: Release gemini-3f-2023-oct-04 · subspace/subspace · GitHub

1 Like

just tried the oct 4 build, waited 40 minutes but no rewards
tested with one node and one farmer instance (default settings)
note: every test run consists of running both the node and farmer with the binaries from the same build (no mix-matching)

lemme know if you want logs for the node also and it would be nice if there’s another way to attach log files since pastebin’s limit of 512k is rather limiting

farmer logs:

I see your farmer did find one solution, but was only able to prove it much later, too late for it to be accepted:

2023-10-04T17:10:25.009850Z DEBUG single_disk_farm{disk_farm_index=1}: subspace_farmer::single_disk_farm: New slot slot_info=SlotInfo { slot_number: 1696439425, global_challenge: [81, 163, 73, 29, 48, 212, 73, 122, 255, 81, 228, 242, 137, 60, 118, 89, 77, 3, 20, 96, 132, 71, 70, 112, 107, 166, 165, 51, 226, 61, 40, 30], solution_range: 495076600, voting_solution_range: 4950766000 }
2023-10-04T17:10:25.009875Z DEBUG single_disk_farm{disk_farm_index=0}: subspace_farmer::single_disk_farm: New slot slot_info=SlotInfo { slot_number: 1696439425, global_challenge: [81, 163, 73, 29, 48, 212, 73, 122, 255, 81, 228, 242, 137, 60, 118, 89, 77, 3, 20, 96, 132, 71, 70, 112, 107, 166, 165, 51, 226, 61, 40, 30], solution_range: 495076600, voting_solution_range: 4950766000 }
2023-10-04T17:10:25.009881Z DEBUG single_disk_farm{disk_farm_index=5}: subspace_farmer::single_disk_farm: New slot slot_info=SlotInfo { slot_number: 1696439425, global_challenge: [81, 163, 73, 29, 48, 212, 73, 122, 255, 81, 228, 242, 137, 60, 118, 89, 77, 3, 20, 96, 132, 71, 70, 112, 107, 166, 165, 51, 226, 61, 40, 30], solution_range: 495076600, voting_solution_range: 4950766000 }
2023-10-04T17:10:25.009887Z DEBUG single_disk_farm{disk_farm_index=2}: subspace_farmer::single_disk_farm: New slot slot_info=SlotInfo { slot_number: 1696439425, global_challenge: [81, 163, 73, 29, 48, 212, 73, 122, 255, 81, 228, 242, 137, 60, 118, 89, 77, 3, 20, 96, 132, 71, 70, 112, 107, 166, 165, 51, 226, 61, 40, 30], solution_range: 495076600, voting_solution_range: 4950766000 }
2023-10-04T17:10:25.009892Z DEBUG single_disk_farm{disk_farm_index=3}: subspace_farmer::single_disk_farm: New slot slot_info=SlotInfo { slot_number: 1696439425, global_challenge: [81, 163, 73, 29, 48, 212, 73, 122, 255, 81, 228, 242, 137, 60, 118, 89, 77, 3, 20, 96, 132, 71, 70, 112, 107, 166, 165, 51, 226, 61, 40, 30], solution_range: 495076600, voting_solution_range: 4950766000 }
2023-10-04T17:10:25.009898Z DEBUG single_disk_farm{disk_farm_index=4}: subspace_farmer::single_disk_farm: New slot slot_info=SlotInfo { slot_number: 1696439425, global_challenge: [81, 163, 73, 29, 48, 212, 73, 122, 255, 81, 228, 242, 137, 60, 118, 89, 77, 3, 20, 96, 132, 71, 70, 112, 107, 166, 165, 51, 226, 61, 40, 30], solution_range: 495076600, voting_solution_range: 4950766000 }
2023-10-04T17:10:25.010002Z DEBUG subspace_farmer::single_disk_farm::farming: Reading sectors slot=1696439425 sector_count=702
2023-10-04T17:10:25.010005Z DEBUG subspace_farmer::single_disk_farm::farming: Reading sectors slot=1696439425 sector_count=889
2023-10-04T17:10:25.010128Z DEBUG subspace_farmer::single_disk_farm::farming: Reading sectors slot=1696439425 sector_count=1404
2023-10-04T17:10:25.010203Z DEBUG subspace_farmer::single_disk_farm::farming: Reading sectors slot=1696439425 sector_count=702
2023-10-04T17:10:25.010227Z DEBUG subspace_farmer::single_disk_farm::farming: Reading sectors slot=1696439425 sector_count=210
2023-10-04T17:10:25.010257Z DEBUG subspace_farmer::single_disk_farm::farming: Reading sectors slot=1696439425 sector_count=702
...
2023-10-04T17:10:28.999802Z DEBUG subspace_farmer::single_disk_farm::farming: Solution found slot=1696439425 sector_index=316

Did you observe high CPU usage with this release? What were CLI options on the farmer side?

I did not observe high cpu usage at all, it was floating from 20% to 30% (this is a dedicated subspace box, nothing else runs on it except basic os stuff and subspace). The CLI options were all defaults, copied it below. Also to note that once I flipped it back to the sep 25 build, it signed rewards within 10 minutes again.

.\subspace-farmer-windows-x86_64-skylake-gemini-3f-2023-oct-04.exe farm --reward-address XXX path=C:\subspace\farm00\s01,size=1.5T
path=C:\subspace\farm04\s01,size=950G path=C:\subspace\farm05\s01,size=750G
path=C:\subspace\farm06\s01,size=750G path=C:\subspace\farm07\s01,size=750G
path=C:\subspace\farm08\s01,size=225G

Okay, the remaining thing that is different on Windows vs Linux/macOS and what is not in latest release is advising OS that reads will be done randomly. There are special more differnet ways to do it on Windows that we didn’t do before, but it was done with memory-mapped I/O. I’ll prepare a test build with those and ask you to test once ready.

Thanks for all the feedback so far!