Gemini-3h Plotting sector very very slow since Finished syncing piece cache to the latest history size

Support
,
1

Issue Report

Environment

  • Ubuntu 22.04:
  • Advanced CLI:

Problem

gemini-3h Plotting sector very very slow since Finished syncing piece cache to the latest history size

node run command is this

nohup /root/subspace-node \
          run \
          --name side-node40 \
          --base-path /root/sub \
          --chain gemini-3h \
          --farmer \
          --listen-on /ip4/0.0.0.0/tcp/30333 \
          --dsn-listen-on /ip4/0.0.0.0/tcp/30433 \
		  --rpc-methods unsafe \
		  --rpc-listen-on 0.0.0.0:9944 \
		  --rpc-cors all \
		  --rpc-max-connections 9999 >> /var/log/subspace-node.log &

node run log is this

2024-04-14T13:52:25.499854Z  INFO Consensus: substrate: ✨ Imported #1077703 (0x3e39…f2ff)
2024-04-14T13:52:26.929410Z  INFO Consensus: substrate: ✨ Imported #1077704 (0xba2d…5692)
2024-04-14T13:52:28.457623Z  INFO Consensus: substrate: 💤 Idle (4 peers), best: #1077704 (0xba2d…5692), finalized #988889 (0x01de…b547), ⬇ 18.5kiB/s ⬆ 3.2kiB/s
2024-04-14T13:52:33.463381Z  INFO Consensus: substrate: 💤 Idle (4 peers), best: #1077704 (0xba2d…5692), finalized #988889 (0x01de…b547), ⬇ 24.6kiB/s ⬆ 3.5kiB/s
2024-04-14T13:52:34.609189Z  INFO Consensus: substrate: ✨ Imported #1077705 (0x9c8a…517e)
2024-04-14T13:52:35.667641Z  INFO Consensus: substrate: ✨ Imported #1077706 (0x462b…b47e)
2024-04-14T13:52:38.465913Z  INFO Consensus: substrate: 💤 Idle (4 peers), best: #1077706 (0x462b…b47e), finalized #988889 (0x01de…b547), ⬇ 12.9kiB/s ⬆ 4.7kiB/s
2024-04-14T13:52:40.563073Z  INFO Consensus: substrate: ✨ Imported #1077707 (0x7538…40a6)
2024-04-14T13:52:41.697892Z  INFO Consensus: substrate: ✨ Imported #1077708 (0x74bc…6264)
2024-04-14T13:52:43.471576Z  INFO Consensus: substrate: 💤 Idle (4 peers), best: #1077708 (0x74bc…6264), finalized #988889 (0x01de…b547), ⬇ 9.1kiB/s ⬆ 3.8kiB/s
2024-04-14T13:52:48.478366Z  INFO Consensus: substrate: 💤 Idle (4 peers), best: #1077708 (0x74bc…6264), finalized #988889 (0x01de…b547), ⬇ 9.6kiB/s ⬆ 3.8kiB/s
2024-04-14T13:52:49.641575Z  INFO Consensus: substrate: ✨ Imported #1077709 (0x29c4…adc0)
2024-04-14T13:52:51.188015Z  INFO Consensus: substrate: ✨ Imported #1077710 (0x91de…a40a)
2024-04-14T13:52:53.486449Z  INFO Consensus: substrate: 💤 Idle (4 peers), best: #1077710 (0x91de…a40a), finalized #988889 (0x01de…b547), ⬇ 10.2kiB/s ⬆ 3.4kiB/s
2024-04-14T13:52:56.292836Z  INFO Consensus: substrate: ✨ Imported #1077711 (0xcf66…f9d2)
2024-04-14T13:52:58.489519Z  INFO Consensus: substrate: 💤 Idle (4 peers), best: #1077711 (0xcf66…f9d2), finalized #988889 (0x01de…b547), ⬇ 7.8kiB/s ⬆ 4.0kiB/s
2024-04-14T13:53:01.738630Z  INFO Consensus: substrate: ✨ Imported #1077712 (0x80c2…0648)
2024-04-14T13:53:03.492396Z  INFO Consensus: substrate: 💤 Idle (4 peers), best: #1077712 (0x80c2…0648), finalized #988889 (0x01de…b547), ⬇ 10.2kiB/s ⬆ 5.1kiB/s
2024-04-14T13:53:03.511142Z  INFO Consensus: substrate: ✨ Imported #1077713 (0x20a8…180b)
2024-04-14T13:53:03.615027Z  INFO Consensus: substrate: ✨ Imported #1077713 (0x944e…bd1e)
2024-04-14T13:53:08.496586Z  INFO Consensus: substrate: 💤 Idle (4 peers), best: #1077713 (0x20a8…180b), finalized #988889 (0x01de…b547), ⬇ 7.4kiB/s ⬆ 4.5kiB/s
2024-04-14T13:53:13.501699Z  INFO Consensus: substrate: 💤 Idle (4 peers), best: #1077713 (0x20a8…180b), finalized #988889 (0x01de…b547), ⬇ 11.5kiB/s ⬆ 5.7kiB/s
2024-04-14T13:53:13.985545Z  INFO Consensus: substrate: ✨ Imported #1077714 (0x680d…a9e1)
2024-04-14T13:53:18.504396Z  INFO Consensus: substrate: 💤 Idle (4 peers), best: #1077714 (0x680d…a9e1), finalized #988889 (0x01de…b547), ⬇ 15.3kiB/s ⬆ 5.5kiB/s
2024-04-14T13:53:19.396328Z  INFO Consensus: substrate: ✨ Imported #1077715 (0xcd04…d83a)

farmer run command is this

nohup /root/subspace-farmer \
          farm \
          --reward-address st6mZM5p7pt3kTcPN6ETimNwTLXqT3BioFS5f6UWFcEtRj4PT \
          --listen-on /ip4/0.0.0.0/tcp/30533 \
          --node-rpc-url ws://172.16.21.40:9944 \
          path=/data/subspace-farmer/data01,size=1024G >> /var/log/subspace-farmer.log &

farmer run log is this

2024-04-13T12:54:58.640370Z  INFO {farm_index=0}: subspace_farmer::single_disk_farm::plotting: Plotting sector (0.31% complete) sector_index=3
2024-04-13T13:27:29.948880Z  INFO subspace_farmer::farmer_cache: Piece cache sync 99.70% complete
2024-04-13T13:38:44.114221Z  INFO subspace_farmer::farmer_cache: Finished piece cache synchronization
2024-04-13T13:38:44.118927Z  INFO subspace_farmer::farmer_cache: Syncing piece cache to the latest history size, this may pause block production if takes too long
2024-04-13T13:58:51.079919Z  INFO {farm_index=0}: subspace_farmer::single_disk_farm::plotting: Plotting sector (0.42% complete) sector_index=4
2024-04-13T14:37:33.850856Z ERROR {farm_index=0}: subspace_farmer::utils::piece_validator: Failed tor retrieve segment headers from node piece_index=61771 error=RequestTimeout
2024-04-13T14:37:33.854745Z ERROR {farm_index=0}: subspace_farmer::utils::piece_validator: Failed tor retrieve segment headers from node piece_index=31182 error=RequestTimeout
2024-04-13T14:53:28.892550Z  INFO {farm_index=0}: subspace_farmer::single_disk_farm::plotting: Plotting sector (0.52% complete) sector_index=5
2024-04-13T15:30:12.395156Z  INFO subspace_farmer::farmer_cache: Finished syncing piece cache to the latest history size
2024-04-13T16:03:52.516997Z  INFO {farm_index=0}: subspace_farmer::single_disk_farm::plotting: Plotting sector (0.63% complete) sector_index=6
2024-04-13T17:01:33.171735Z  INFO {farm_index=0}: subspace_farmer::single_disk_farm::plotting: Plotting sector (0.73% complete) sector_index=7
2024-04-13T17:41:54.464957Z  INFO {farm_index=0}: subspace_farmer::single_disk_farm::plotting: Plotting sector (0.83% complete) sector_index=8
2024-04-13T18:14:41.057257Z  INFO {farm_index=0}: subspace_farmer::single_disk_farm::plotting: Plotting sector (0.94% complete) sector_index=9
2024-04-13T18:40:11.423350Z  INFO {farm_index=0}: subspace_farmer::single_disk_farm::plotting: Plotting sector (1.04% complete) sector_index=10
2024-04-13T18:52:55.947659Z  INFO {farm_index=0}: subspace_farmer::single_disk_farm::plotting: Plotting sector (1.15% complete) sector_index=11
2024-04-13T19:05:38.311653Z  INFO {farm_index=0}: subspace_farmer::single_disk_farm::plotting: Plotting sector (1.25% complete) sector_index=12
2024-04-13T19:21:15.943268Z  INFO {farm_index=0}: subspace_farmer::single_disk_farm::plotting: Plotting sector (1.36% complete) sector_index=13
2024-04-13T19:36:03.273069Z  INFO {farm_index=0}: subspace_farmer::single_disk_farm::plotting: Plotting sector (1.46% complete) sector_index=14
2024-04-13T20:20:57.727390Z  INFO {farm_index=0}: subspace_farmer::single_disk_farm::plotting: Plotting sector (1.56% complete) sector_index=15
2024-04-13T21:22:41.679271Z  INFO {farm_index=0}: subspace_farmer::single_disk_farm::plotting: Plotting sector (1.67% complete) sector_index=16
2024-04-13T22:17:47.709205Z  INFO {farm_index=0}: subspace_farmer::single_disk_farm::plotting: Plotting sector (1.77% complete) sector_index=17
2024-04-13T23:02:28.866582Z  INFO {farm_index=0}: subspace_farmer::single_disk_farm::plotting: Plotting sector (1.88% complete) sector_index=18
2024-04-14T00:10:03.632872Z  INFO {farm_index=0}: subspace_farmer::single_disk_farm::plotting: Plotting sector (1.98% complete) sector_index=19
2024-04-14T01:16:41.433833Z  INFO {farm_index=0}: subspace_farmer::single_disk_farm::plotting: Plotting sector (2.09% complete) sector_index=20
2024-04-14T02:11:47.277568Z  INFO {farm_index=0}: subspace_farmer::single_disk_farm::plotting: Plotting sector (2.19% complete) sector_index=21
2024-04-14T02:56:01.507007Z  INFO {farm_index=0}: subspace_farmer::single_disk_farm::plotting: Plotting sector (2.29% complete) sector_index=22
2024-04-14T03:54:49.647175Z  INFO {farm_index=0}: subspace_farmer::single_disk_farm::plotting: Plotting sector (2.40% complete) sector_index=23
2024-04-14T04:42:44.013368Z  INFO {farm_index=0}: subspace_farmer::single_disk_farm::plotting: Plotting sector (2.50% complete) sector_index=24
2024-04-14T05:19:43.746979Z  INFO {farm_index=0}: subspace_farmer::single_disk_farm::plotting: Plotting sector (2.61% complete) sector_index=25
2024-04-14T05:58:23.746287Z  INFO {farm_index=0}: subspace_farmer::single_disk_farm::plotting: Plotting sector (2.71% complete) sector_index=26
2024-04-14T06:27:48.327983Z  INFO {farm_index=0}: subspace_farmer::single_disk_farm::plotting: Plotting sector (2.82% complete) sector_index=27
2024-04-14T06:57:51.054410Z  INFO {farm_index=0}: subspace_farmer::single_disk_farm::plotting: Plotting sector (2.92% complete) sector_index=28
2024-04-14T07:41:57.886040Z  INFO {farm_index=0}: subspace_farmer::single_disk_farm::plotting: Plotting sector (3.02% complete) sector_index=29
2024-04-14T08:16:28.381185Z  INFO {farm_index=0}: subspace_farmer::single_disk_farm::plotting: Plotting sector (3.13% complete) sector_index=30
2024-04-14T08:39:11.026937Z  INFO {farm_index=0}: subspace_farmer::single_disk_farm::plotting: Plotting sector (3.23% complete) sector_index=31
2024-04-14T09:43:25.316787Z  INFO {farm_index=0}: subspace_farmer::single_disk_farm::plotting: Plotting sector (3.34% complete) sector_index=32
2024-04-14T10:21:33.479438Z  INFO {farm_index=0}: subspace_farmer::single_disk_farm::plotting: Plotting sector (3.44% complete) sector_index=33
2024-04-14T10:51:40.961347Z  INFO {farm_index=0}: subspace_farmer::single_disk_farm::plotting: Plotting sector (3.55% complete) sector_index=34
2024-04-14T11:29:26.004239Z  INFO {farm_index=0}: subspace_farmer::single_disk_farm::plotting: Plotting sector (3.65% complete) sector_index=35
2024-04-14T12:21:48.480729Z  INFO {farm_index=0}: subspace_farmer::single_disk_farm::plotting: Plotting sector (3.75% complete) sector_index=36
2024-04-14T12:55:23.455409Z  INFO {farm_index=0}: subspace_farmer::single_disk_farm::plotting: Plotting sector (3.86% complete) sector_index=37
2024-04-14T13:18:31.811374Z  INFO {farm_index=0}: subspace_farmer::single_disk_farm::plotting: Plotting sector (3.96% complete) sector_index=38
2024-04-14T13:44:21.153301Z  INFO {farm_index=0}: subspace_farmer::single_disk_farm::plotting: Plotting sector (4.07% complete) sector_index=39
2

@nazar-pc Is this normal?How long does a 1TB Plotting sector usually take?If this is a problem, how do I fix it?

3

That’s what happened to my 100G.

4

I think you’re trying to find a rule where there is none. With smaller farm size it will start slower, become a little faster over time and slow down towards the end again as plot cache space is being plotted. Overall you will need a larger farm size to speed things up as those will have higher cache size and will speed up piece retrieval and look for newer software releases that often optimize and make things faster.

5

I’m very sorry, I don’t quite understand what you mean. I am currently using the latest software version (subspace-farmer-ubuntu-x86_64-v2-gemini-3h-2024-mar-29), but this seems to be very slow. , one sector takes nearly an hour to complete. Is this normal? How do I speed it up?

6

This is my current hardware configuration information：

root@node40:~# lscpu
Architecture:           x86_64
  CPU op-mode(s):       32-bit, 64-bit
  Address sizes:        46 bits physical, 48 bits virtual
  Byte Order:           Little Endian
CPU(s):                 32
  On-line CPU(s) list:  0-31
Vendor ID:              GenuineIntel
  Model name:           Intel(R) Xeon(R) CPU E5-2630 v3 @ 2.40GHz
    CPU family:         6
    Model:              63
    Thread(s) per core: 2
    Core(s) per socket: 8
    Socket(s):          2
    Stepping:           2
    CPU max MHz:        3200.0000
    CPU min MHz:        1200.0000
    BogoMIPS:           4788.96
    Flags:              fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx pdpe1gb rdtscp lm constant_ts
                        c arch_perfmon pebs bts rep_good nopl xtopology nonstop_tsc cpuid aperfmperf pni pclmulqdq dtes64 monitor ds_cpl smx est tm2 ssse3 sdbg fma cx16 xtpr pdcm pcid
                        dca sse4_1 sse4_2 x2apic movbe popcnt tsc_deadline_timer aes xsave avx f16c rdrand lahf_lm abm cpuid_fault epb invpcid_single pti intel_ppin ssbd ibrs ibpb stib
                        p fsgsbase tsc_adjust bmi1 avx2 smep bmi2 erms invpcid cqm xsaveopt cqm_llc cqm_occup_llc dtherm ida arat pln pts md_clear flush_l1d
Caches (sum of all):
  L1d:                  512 KiB (16 instances)
  L1i:                  512 KiB (16 instances)
  L2:                   4 MiB (16 instances)
  L3:                   40 MiB (2 instances)
NUMA:
  NUMA node(s):         2
  NUMA node0 CPU(s):    0-7,16-23
  NUMA node1 CPU(s):    8-15,24-31
Vulnerabilities:
  Gather data sampling: Not affected
  Itlb multihit:        KVM: Mitigation: VMX unsupported
  L1tf:                 Mitigation; PTE Inversion
  Mds:                  Mitigation; Clear CPU buffers; SMT vulnerable
  Meltdown:             Mitigation; PTI
  Mmio stale data:      Mitigation; Clear CPU buffers; SMT vulnerable
  Retbleed:             Not affected
  Spec rstack overflow: Not affected
  Spec store bypass:    Mitigation; Speculative Store Bypass disabled via prctl and seccomp
  Spectre v1:           Mitigation; usercopy/swapgs barriers and __user pointer sanitization
  Spectre v2:           Mitigation; Retpolines, IBPB conditional, IBRS_FW, STIBP conditional, RSB filling, PBRSB-eIBRS Not affected
  Srbds:                Not affected
  Tsx async abort:      Not affected
root@node40:~#
root@node40:~# free -g
               total        used        free      shared  buff/cache   available
Mem:              31          15           0           0          14          15
Swap:              7           0           7
7

As I said above, it can be slower initially, but I see later sectors are already faster for you. Overall plotting in your case is a function of network quality it seems like.