Log is weird: spam "Looking up qualities took too long"

[dima-stefantsov]

UPD: debug log shows that it starts with simultaneous 20x new_signage_point_harvester at the same time. I've elaborated in first comment below.

Hi. After @codinghorror post, you have added "lookup too long" in log as WARNING. It is important to keep it under control for me.

I'm sometimes getting this warnings, but what I get is weird, I don't know how to interpret it. I only have guesses how your harvester actually works. Here is what I get: (log below)

Most notable thing here is timestamp of log records - it just comes in bursts, notice all this lines being written within 50ms.
So how does your harvester and logs work, what exactly is going on?

1. just one slow plot hung for 60 seconds, essentially slowing all later plots?
2. why log output is not in order? why do I read "took 20, 20, 39, 35, 35, 19, 19, 19 seconds"?
3. are your lookups not parallel?
4. I have written an app that reads a tiny file from every chia plot folder every 1 second. I can see response time pretty much always in low ms. Very rarely jumping to 0.5s, to 2s almost never. So drives are not asleep, connectivity and responsiveness is fine.

0.12 ms |   0 ms max
0.08 ms |   1 ms max
0.06 ms |   0 ms max
0.07 ms |  62 ms max
1.06 ms | 468 ms max
4.07 ms | 558 ms max
3.91 ms | 120 ms max
4.21 ms | 116 ms max
3.89 ms | 112 ms max
3.85 ms |  53 ms max
4.38 ms |  49 ms max
4.12 ms |  23 ms max
4.00 ms |   8 ms max
3.83 ms |  11 ms max
3.92 ms |   9 ms max
3.69 ms |   8 ms max
3.77 ms |  13 ms max
0.07 ms |   0 ms max

Notice fast local drives have "less than 1ms max", yet they still managed to get onto the slowlog with up to 55 seconds lookup. Something weird is going on, it should never happen!

5. In this log it happens both to local HDDs, to local USB drives, to remote 1Gbps nas drives... While responsiveness of at least local HDD drives are always in low ms, there is no way local HDD took 55 seconds to answer. So it's really stuck once on one slow plot, and kills the rest of it?!
6. if so, then how do I debug it? I find longest time in log burst, this must be it?
7. if so, are you going to fix it to make it parallel, to make it so 1 slow plot/device doesn't kill hundred other's efforts?

2021-05-13T13:02:50.722 harvester chia.harvester.harvester: WARNING  Looking up qualities on H:\different_plotname_and_path.plot took: 49.66695022583008. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.725 harvester chia.harvester.harvester: WARNING  Looking up qualities on D:\different_plotname_and_path.plot took: 57.55812954902649. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.726 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.different_ips\different_plotname_and_path.plot took: 53.707550287246704. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.727 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.different_ips\different_plotname_and_path.plot took: 52.26798939704895. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.727 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.different_ips\different_plotname_and_path.plot took: 52.26798939704895. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.728 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.different_ips\different_plotname_and_path.plot took: 52.26898765563965. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.730 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.different_ips\different_plotname_and_path.plot took: 43.686264991760254. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.730 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.different_ips\different_plotname_and_path.plot took: 43.6872615814209. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.731 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.different_ips\different_plotname_and_path.plot took: 49.675586223602295. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.732 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.different_ips\different_plotname_and_path.plot took: 57.565101861953735. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.732 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.different_ips\different_plotname_and_path.plot took: 57.565101861953735. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.733 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.different_ips\different_plotname_and_path.plot took: 41.99085092544556. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.734 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.different_ips\different_plotname_and_path.plot took: 41.99184727668762. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.734 harvester chia.harvester.harvester: WARNING  Looking up qualities on I:\different_plotname_and_path.plot took: 41.99184727668762. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.735 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.different_ips\different_plotname_and_path.plot took: 36.25646710395813. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.736 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.different_ips\different_plotname_and_path.plot took: 36.25746393203735. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.737 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.different_ips\different_plotname_and_path.plot took: 33.63897705078125. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.738 harvester chia.harvester.harvester: WARNING  Looking up qualities on D:\different_plotname_and_path.plot took: 33.63997554779053. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.739 harvester chia.harvester.harvester: WARNING  Looking up qualities on D:\different_plotname_and_path.plot took: 30.239976167678833. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.740 harvester chia.harvester.harvester: WARNING  Looking up qualities on E:\different_plotname_and_path.plot took: 30.240973711013794. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.741 harvester chia.harvester.harvester: WARNING  Looking up qualities on J:\different_plotname_and_path.plot took: 30.241970777511597. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.742 harvester chia.harvester.harvester: WARNING  Looking up qualities on K:\different_plotname_and_path.plot took: 30.24296808242798. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.743 harvester chia.harvester.harvester: WARNING  Looking up qualities on D:\different_plotname_and_path.plot took: 31.978320598602295. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.744 harvester chia.harvester.harvester: WARNING  Looking up qualities on I:\different_plotname_and_path.plot took: 31.97931718826294. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.745 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.different_ips\different_plotname_and_path.plot took: 56.32757115364075. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.746 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.different_ips\different_plotname_and_path.plot took: 56.328569650650024. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.747 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.different_ips\different_plotname_and_path.plot took: 56.328569650650024. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.747 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.different_ips\different_plotname_and_path.plot took: 56.32956600189209. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.748 harvester chia.harvester.harvester: WARNING  Looking up qualities on D:\different_plotname_and_path.plot took: 56.330562591552734. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.749 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.different_ips\different_plotname_and_path.plot took: 48.12265753746033. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.749 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.different_ips\different_plotname_and_path.plot took: 55.113946199417114. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.750 harvester chia.harvester.harvester: WARNING  Looking up qualities on D:\different_plotname_and_path.plot took: 55.114943742752075. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.751 harvester chia.harvester.harvester: WARNING  Looking up qualities on G:\different_plotname_and_path.plot took: 28.650444746017456. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.751 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.different_ips\different_plotname_and_path.plot took: 28.650444746017456. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.752 harvester chia.harvester.harvester: WARNING  Looking up qualities on I:\different_plotname_and_path.plot took: 28.65144157409668. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.753 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.different_ips\different_plotname_and_path.plot took: 46.768685817718506. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.754 harvester chia.harvester.harvester: WARNING  Looking up qualities on D:\different_plotname_and_path.plot took: 46.769683599472046. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.754 harvester chia.harvester.harvester: WARNING  Looking up qualities on D:\different_plotname_and_path.plot took: 46.769683599472046. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.755 harvester chia.harvester.harvester: WARNING  Looking up qualities on I:\different_plotname_and_path.plot took: 46.77068018913269. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.756 harvester chia.harvester.harvester: WARNING  Looking up qualities on D:\different_plotname_and_path.plot took: 59.06267428398132. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.757 harvester chia.harvester.harvester: WARNING  Looking up qualities on I:\different_plotname_and_path.plot took: 59.06367230415344. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.757 harvester chia.harvester.harvester: WARNING  Looking up qualities on D:\different_plotname_and_path.plot took: 59.06367230415344. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.758 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.different_ips0\different_plotname_and_path.plot took: 23.91584873199463. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.759 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.different_ips0\different_plotname_and_path.plot took: 23.916845560073853. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.759 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.different_ips\different_plotname_and_path.plot took: 23.916845560073853. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.760 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.different_ips\different_plotname_and_path.plot took: 23.917843341827393. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.761 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.different_ips\different_plotname_and_path.plot took: 60.252132415771484. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.762 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.different_ips\different_plotname_and_path.plot took: 22.555487155914307. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.763 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.different_ips\wd4-3\different_plotname_and_path.plot took: 22.556485176086426. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.763 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.different_ips\different_plotname_and_path.plot took: 22.556485176086426. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.764 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.different_ips\_chia\different_plotname_and_path.plot took: 25.290075302124023. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.765 harvester chia.harvester.harvester: WARNING  Looking up qualities on D:\different_plotname_and_path.plot took: 25.291071891784668. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.766 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.different_ips\different_plotname_and_path.plot took: 45.26413321495056. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.767 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.different_ips\different_plotname_and_path.plot took: 51.072001934051514. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.767 harvester chia.harvester.harvester: WARNING  Looking up qualities on D:\different_plotname_and_path.plot took: 20.831655263900757. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.767 harvester chia.harvester.harvester: WARNING  Looking up qualities on D:\different_plotname_and_path.plot took: 20.83265233039856. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.768 harvester chia.harvester.harvester: WARNING  Looking up qualities on E:\different_plotname_and_path.plot took: 39.10996866226196. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.768 harvester chia.harvester.harvester: WARNING  Looking up qualities on H:\different_plotname_and_path.plot took: 35.098488092422485. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.769 harvester chia.harvester.harvester: WARNING  Looking up qualities on K:\different_plotname_and_path.plot took: 35.09948706626892. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.770 harvester chia.harvester.harvester: WARNING  Looking up qualities on D:\different_plotname_and_path.plot took: 19.097015857696533. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.770 harvester chia.harvester.harvester: WARNING  Looking up qualities on I:\different_plotname_and_path.plot took: 19.097015857696533. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T13:02:50.771 harvester chia.harvester.harvester: WARNING  Looking up qualities on D:\different_plotname_and_path.plot took: 19.098013162612915. This should be below 5 seconds to minimize risk of losing rewards.

I'm on Windows 10
Using GUI app 1.1.5

[dima-stefantsov]

I have enabled debug logging mode and investigated further. Looks like my usual lookups are 0-3 seconds, like

2021-05-13T19:58:14.922 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-13T19:58:16.601 harvester chia.harvester.harvester: INFO     4 plots were eligible for farming a_part_of_hash_or_key... Found 0 proofs. Time: 1.67828 s. Total xxx plots
2021-05-13T19:58:16.602 harvester harvester_server        : INFO     -> farming_info to peer 127.0.0.1 some_hash_or_key
2021-05-13T19:58:16.603 harvester harvester_server        : DEBUG    Time taken to process new_signage_point_harvester from some_hash_or_key is 1.6812713146209717 seconds

so it should be fine.

But I was able to catch the issue, and it looks like this (log below).
Looks like problem is not in my disk hardware and lookups, but in simultaneous 20x new_signage_point_harvester at the same time. Each of it is taking ~1.5 seconds, and it leads to ~35 seconds overall.
Can you please tell me what is going on? Why my full node (or farmer? or what?) is sending this points in batch sometimes? Maybe my network peers are bad? I have open 8444 port, ~60 full peers, ~1Gbit internet connection, pings to europe ~20ms.

Can you please help? Where do I look further to eliminate this? Is this maybe a bug?
Farming on single windows 10 GUI Chia 1.1.5

2021-05-13T20:02:15.054 harvester harvester_server        : DEBUG    Time taken to process new_signage_point_harvester from some_hash_or_key is 1.0531833171844482 seconds
2021-05-13T20:02:23.239 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-13T20:02:25.571 harvester chia.harvester.harvester: INFO     0 plots were eligible for farming a_part_of_hash_or_key... Found 0 proofs. Time: 1.31948 s. Total xxx plots
2021-05-13T20:02:25.572 harvester harvester_server        : INFO     -> farming_info to peer 127.0.0.1 some_hash_or_key
2021-05-13T20:02:25.573 harvester harvester_server        : DEBUG    Time taken to process new_signage_point_harvester from some_hash_or_key is 2.333763599395752 seconds
2021-05-13T20:02:34.225 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-13T20:02:35.790 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-13T20:02:35.791 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-13T20:02:35.792 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-13T20:02:35.793 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-13T20:02:35.793 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-13T20:02:35.794 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-13T20:02:35.795 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-13T20:02:35.796 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-13T20:02:35.797 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-13T20:02:35.797 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-13T20:02:35.798 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-13T20:02:35.799 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-13T20:02:35.799 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-13T20:02:35.800 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-13T20:02:35.801 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-13T20:02:35.802 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-13T20:02:35.802 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-13T20:02:35.803 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-13T20:02:35.804 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-13T20:02:39.204 harvester chia.harvester.harvester: INFO     0 plots were eligible for farming a_part_of_hash_or_key... Found 0 proofs. Time: 3.39792 s. Total xxx plots
2021-05-13T20:02:48.756 harvester chia.harvester.harvester: INFO     0 plots were eligible for farming a_part_of_hash_or_key... Found 0 proofs. Time: 1.20278 s. Total xxx plots
2021-05-13T20:02:50.956 harvester chia.harvester.harvester: INFO     0 plots were eligible for farming a_part_of_hash_or_key... Found 0 proofs. Time: 1.18783 s. Total xxx plots
2021-05-13T20:02:59.050 harvester chia.harvester.harvester: INFO     0 plots were eligible for farming a_part_of_hash_or_key... Found 0 proofs. Time: 1.11302 s. Total xxx plots
2021-05-13T20:03:02.373 harvester harvester_server        : INFO     -> farming_info to peer 127.0.0.1 some_hash_or_key
2021-05-13T20:03:02.374 harvester harvester_server        : INFO     -> farming_info to peer 127.0.0.1 some_hash_or_key
2021-05-13T20:03:02.375 harvester harvester_server        : INFO     -> farming_info to peer 127.0.0.1 some_hash_or_key
2021-05-13T20:03:02.376 harvester harvester_server        : INFO     -> farming_info to peer 127.0.0.1 some_hash_or_key
2021-05-13T20:03:02.378 harvester harvester_server        : DEBUG    Time taken to process new_signage_point_harvester from some_hash_or_key is 26.587876081466675 seconds
2021-05-13T20:03:02.380 harvester harvester_server        : DEBUG    Time taken to process new_signage_point_harvester from some_hash_or_key is 26.58388876914978 seconds
2021-05-13T20:03:02.381 harvester harvester_server        : DEBUG    Time taken to process new_signage_point_harvester from some_hash_or_key is 26.584885597229004 seconds
2021-05-13T20:03:02.381 harvester harvester_server        : DEBUG    Time taken to process new_signage_point_harvester from some_hash_or_key is 26.57990050315857 seconds
2021-05-13T20:03:02.382 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.some_ips\different_paths_and_plots.plot took: 27.147380590438843. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T20:03:02.383 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.some_ips\different_paths_and_plots.plot took: 27.148377895355225. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T20:03:02.383 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.some_ips\different_paths_and_plots.plot took: 27.148377895355225. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T20:03:02.384 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.some_ips\different_paths_and_plots.plot took: 27.14937472343445. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T20:03:02.385 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.some_ips\different_paths_and_plots.plot took: 27.150370836257935. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T20:03:02.385 harvester chia.harvester.harvester: INFO     5 plots were eligible for farming a_part_of_hash_or_key... Found 0 proofs. Time: 27.15037 s. Total xxx plots
2021-05-13T20:03:02.386 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-13T20:03:02.387 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-13T20:03:02.388 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-13T20:03:02.389 harvester harvester_server        : INFO     -> farming_info to peer 127.0.0.1 some_hash_or_key
2021-05-13T20:03:08.400 harvester harvester_server        : DEBUG    Time taken to process new_signage_point_harvester from some_hash_or_key is 34.175588846206665 seconds
2021-05-13T20:03:08.403 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.some_ips\different_paths_and_plots.plot took: 29.19889736175537. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T20:03:08.404 harvester chia.harvester.harvester: WARNING  Looking up qualities on D:\different_paths_and_plots.plot took: 29.199894905090332. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T20:03:08.405 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.some_ips1\different_paths_and_plots.plot took: 29.20089292526245. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T20:03:08.406 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.some_ips\different_paths_and_plots.plot took: 29.201890468597412. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T20:03:08.407 harvester chia.harvester.harvester: INFO     4 plots were eligible for farming a_part_of_hash_or_key... Found 0 proofs. Time: 29.20289 s. Total xxx plots
2021-05-13T20:03:08.408 harvester chia.harvester.harvester: WARNING  Looking up qualities on D:\different_paths_and_plots.plot took: 16.215630531311035. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T20:03:08.409 harvester chia.harvester.harvester: WARNING  Looking up qualities on D:\different_paths_and_plots.plot took: 16.217626810073853. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T20:03:08.409 harvester chia.harvester.harvester: WARNING  Looking up qualities on I:\different_paths_and_plots.plot took: 16.217626810073853. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T20:03:08.410 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.some_ips\different_paths_and_plots.plot took: 16.218623161315918. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T20:03:08.411 harvester chia.harvester.harvester: INFO     4 plots were eligible for farming a_part_of_hash_or_key... Found 0 proofs. Time: 16.21962 s. Total xxx plots
2021-05-13T20:03:08.411 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.some_ips\different_paths_and_plots.plot took: 17.45431637763977. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T20:03:08.412 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.some_ips\different_paths_and_plots.plot took: 17.455314874649048. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T20:03:08.413 harvester chia.harvester.harvester: INFO     2 plots were eligible for farming a_part_of_hash_or_key... Found 0 proofs. Time: 17.45631 s. Total xxx plots
2021-05-13T20:03:08.414 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.some_ips\different_paths_and_plots.plot took: 24.661038398742676. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T20:03:08.414 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.some_ips\different_paths_and_plots.plot took: 24.661038398742676. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T20:03:08.415 harvester chia.harvester.harvester: INFO     2 plots were eligible for farming a_part_of_hash_or_key... Found 0 proofs. Time: 24.66204 s. Total xxx plots
2021-05-13T20:03:08.416 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.some_ips\different_paths_and_plots.plot took: 22.461920499801636. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T20:03:08.416 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.some_ips\different_paths_and_plots.plot took: 22.461920499801636. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T20:03:08.417 harvester chia.harvester.harvester: INFO     2 plots were eligible for farming a_part_of_hash_or_key... Found 0 proofs. Time: 22.46292 s. Total xxx plots
2021-05-13T20:03:08.418 harvester chia.harvester.harvester: WARNING  Looking up qualities on D:\different_paths_and_plots.plot took: 28.34717559814453. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T20:03:08.418 harvester chia.harvester.harvester: WARNING  Looking up qualities on D:\different_paths_and_plots.plot took: 28.34717559814453. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T20:03:08.419 harvester chia.harvester.harvester: INFO     2 plots were eligible for farming a_part_of_hash_or_key... Found 0 proofs. Time: 28.34817 s. Total xxx plots
2021-05-13T20:03:08.420 harvester chia.harvester.harvester: WARNING  Looking up qualities on D:\different_paths_and_plots.plot took: 8.202068090438843. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T20:03:08.420 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.some_ips\different_paths_and_plots.plot took: 8.202068090438843. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T20:03:08.421 harvester chia.harvester.harvester: INFO     2 plots were eligible for farming a_part_of_hash_or_key... Found 0 proofs. Time: 8.20307 s. Total xxx plots
2021-05-13T20:03:08.421 harvester chia.harvester.harvester: WARNING  Looking up qualities on D:\different_paths_and_plots.plot took: 26.055309772491455. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T20:03:08.422 harvester chia.harvester.harvester: WARNING  Looking up qualities on G:\different_paths_and_plots.plot took: 26.05630373954773. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T20:03:08.423 harvester chia.harvester.harvester: WARNING  Looking up qualities on D:\different_paths_and_plots.plot took: 26.057304620742798. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T20:03:08.424 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.some_ips\different_paths_and_plots.plot took: 26.058300495147705. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T20:03:08.425 harvester chia.harvester.harvester: INFO     4 plots were eligible for farming a_part_of_hash_or_key... Found 0 proofs. Time: 26.05930 s. Total xxx plots
2021-05-13T20:03:08.426 harvester chia.harvester.harvester: WARNING  Looking up qualities on D:\different_paths_and_plots.plot took: 15.124549150466919. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T20:03:08.426 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.some_ips\different_paths_and_plots.plot took: 15.125550270080566. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T20:03:08.427 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.some_ips1\different_paths_and_plots.plot took: 15.12654447555542. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T20:03:08.428 harvester chia.harvester.harvester: INFO     3 plots were eligible for farming a_part_of_hash_or_key... Found 0 proofs. Time: 15.12754 s. Total xxx plots
2021-05-13T20:03:08.428 harvester chia.harvester.harvester: WARNING  Looking up qualities on G:\different_paths_and_plots.plot took: 13.993575096130371. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T20:03:08.429 harvester chia.harvester.harvester: INFO     1 plots were eligible for farming a_part_of_hash_or_key... Found 0 proofs. Time: 13.99457 s. Total xxx plots
2021-05-13T20:03:08.429 harvester chia.harvester.harvester: WARNING  Looking up qualities on D:\different_paths_and_plots.plot took: 9.37792444229126. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T20:03:08.430 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.some_ips\different_paths_and_plots.plot took: 9.378920078277588. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T20:03:08.431 harvester chia.harvester.harvester: INFO     2 plots were eligible for farming a_part_of_hash_or_key... Found 0 proofs. Time: 9.37992 s. Total xxx plots
2021-05-13T20:03:08.431 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.some_ips\different_paths_and_plots.plot took: 12.794783592224121. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T20:03:08.432 harvester chia.harvester.harvester: INFO     1 plots were eligible for farming a_part_of_hash_or_key... Found 0 proofs. Time: 12.79578 s. Total xxx plots
2021-05-13T20:03:08.433 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.some_ips\different_paths_and_plots.plot took: 11.621920824050903. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T20:03:08.433 harvester chia.harvester.harvester: INFO     1 plots were eligible for farming a_part_of_hash_or_key... Found 0 proofs. Time: 11.62192 s. Total xxx plots
2021-05-13T20:03:08.434 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.some_ips\different_paths_and_plots.plot took: 27.189271211624146. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T20:03:08.435 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.some_ips\different_paths_and_plots.plot took: 27.19027042388916. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T20:03:08.435 harvester chia.harvester.harvester: INFO     2 plots were eligible for farming a_part_of_hash_or_key... Found 0 proofs. Time: 27.19027 s. Total xxx plots
2021-05-13T20:03:08.436 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.some_ips\different_paths_and_plots.plot took: 7.1438984870910645. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T20:03:08.437 harvester chia.harvester.harvester: WARNING  Looking up qualities on \\192.168.some_ips\different_paths_and_plots.plot took: 7.144893646240234. This should be below 5 seconds to minimize risk of losing rewards.
2021-05-13T20:03:08.438 harvester chia.harvester.harvester: INFO     2 plots were eligible for farming a_part_of_hash_or_key... Found 0 proofs. Time: 7.14589 s. Total xxx plots
2021-05-13T20:03:08.438 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-13T20:03:08.439 harvester harvester_server        : INFO     -> farming_info to peer 127.0.0.1 some_hash_or_key
2021-05-13T20:03:08.440 harvester harvester_server        : INFO     -> farming_info to peer 127.0.0.1 some_hash_or_key
2021-05-13T20:03:08.442 harvester harvester_server        : INFO     -> farming_info to peer 127.0.0.1 some_hash_or_key
2021-05-13T20:03:08.443 harvester harvester_server        : INFO     -> farming_info to peer 127.0.0.1 some_hash_or_key
2021-05-13T20:03:08.443 harvester harvester_server        : INFO     -> farming_info to peer 127.0.0.1 some_hash_or_key
2021-05-13T20:03:08.444 harvester harvester_server        : INFO     -> farming_info to peer 127.0.0.1 some_hash_or_key
2021-05-13T20:03:08.445 harvester harvester_server        : INFO     -> farming_info to peer 127.0.0.1 some_hash_or_key
2021-05-13T20:03:08.445 harvester harvester_server        : INFO     -> farming_info to peer 127.0.0.1 some_hash_or_key
2021-05-13T20:03:08.446 harvester harvester_server        : INFO     -> farming_info to peer 127.0.0.1 some_hash_or_key
2021-05-13T20:03:08.447 harvester harvester_server        : INFO     -> farming_info to peer 127.0.0.1 some_hash_or_key
2021-05-13T20:03:08.448 harvester harvester_server        : INFO     -> farming_info to peer 127.0.0.1 some_hash_or_key
2021-05-13T20:03:08.448 harvester harvester_server        : INFO     -> farming_info to peer 127.0.0.1 some_hash_or_key
2021-05-13T20:03:08.449 harvester harvester_server        : INFO     -> farming_info to peer 127.0.0.1 some_hash_or_key
2021-05-13T20:03:08.450 harvester harvester_server        : INFO     -> farming_info to peer 127.0.0.1 some_hash_or_key
2021-05-13T20:03:08.451 harvester harvester_server        : INFO     -> farming_info to peer 127.0.0.1 some_hash_or_key
2021-05-13T20:03:11.306 harvester harvester_server        : DEBUG    Time taken to process new_signage_point_harvester from some_hash_or_key is 35.515013456344604 seconds
2021-05-13T20:03:11.307 harvester harvester_server        : DEBUG    Time taken to process new_signage_point_harvester from some_hash_or_key is 35.50902795791626 seconds
2021-05-13T20:03:11.309 harvester harvester_server        : DEBUG    Time taken to process new_signage_point_harvester from some_hash_or_key is 35.512019634246826 seconds
2021-05-13T20:03:11.310 harvester harvester_server        : DEBUG    Time taken to process new_signage_point_harvester from some_hash_or_key is 35.51600885391235 seconds
2021-05-13T20:03:11.311 harvester harvester_server        : DEBUG    Time taken to process new_signage_point_harvester from some_hash_or_key is 35.51600933074951 seconds
2021-05-13T20:03:11.311 harvester harvester_server        : DEBUG    Time taken to process new_signage_point_harvester from some_hash_or_key is 35.51900339126587 seconds
2021-05-13T20:03:11.312 harvester harvester_server        : DEBUG    Time taken to process new_signage_point_harvester from some_hash_or_key is 35.509029150009155 seconds
2021-05-13T20:03:11.313 harvester harvester_server        : DEBUG    Time taken to process new_signage_point_harvester from some_hash_or_key is 35.519999742507935 seconds
2021-05-13T20:03:11.313 harvester harvester_server        : DEBUG    Time taken to process new_signage_point_harvester from some_hash_or_key is 35.514017820358276 seconds
2021-05-13T20:03:11.314 harvester harvester_server        : DEBUG    Time taken to process new_signage_point_harvester from some_hash_or_key is 35.515013217926025 seconds
2021-05-13T20:03:11.315 harvester harvester_server        : DEBUG    Time taken to process new_signage_point_harvester from some_hash_or_key is 35.51301908493042 seconds
2021-05-13T20:03:11.315 harvester harvester_server        : DEBUG    Time taken to process new_signage_point_harvester from some_hash_or_key is 35.515013456344604 seconds
2021-05-13T20:03:11.316 harvester harvester_server        : DEBUG    Time taken to process new_signage_point_harvester from some_hash_or_key is 35.51500988006592 seconds
2021-05-13T20:03:11.317 harvester harvester_server        : DEBUG    Time taken to process new_signage_point_harvester from some_hash_or_key is 35.52398657798767 seconds
2021-05-13T20:03:11.317 harvester harvester_server        : DEBUG    Time taken to process new_signage_point_harvester from some_hash_or_key is 35.51301550865173 seconds

[dima-stefantsov]

Signature points usually come one every ~10 seconds. But sometimes they come in bursts of 5-30+ at the same second. Here is an example (log below).

Also, this is how it looks in GUI. A lot of "last attempted proof", the same exact second, and as you can see even with different "plots passed filter", looks like this attempted proofs are not duplicates but different?

Although I've read Papers, I have no real technical understanding of Chia protocol. Can you please help, is this normal to get 30x different new_signage_point_harvester during the same second? It feels like it's not normal. I'll wait for your feedback for a day more, and elevate this to a bug. Thank you.

2021-05-14T06:03:12.507 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:03:21.918 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:03:30.564 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:03:38.667 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:03:49.111 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:04:01.362 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:04:07.321 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:04:17.502 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:04:28.052 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:04:33.419 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:04:44.099 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:04:51.622 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:05:08.584 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:05:15.129 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
!!! no ~10sec delay here
2021-05-14T06:05:17.328 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:05:17.330 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:05:17.331 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:05:17.332 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:05:17.333 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:05:17.334 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:05:17.334 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:05:17.335 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
!!! kind of good ~10sec delay, but signature points are multiplying
2021-05-14T06:05:28.113 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:05:29.124 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:05:29.125 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:05:29.126 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:05:29.127 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:05:29.128 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:05:29.129 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:05:29.131 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:05:29.132 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:05:29.133 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:05:29.133 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:05:29.134 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:05:29.135 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:05:29.136 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:05:29.137 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:05:29.138 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:05:29.139 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:05:29.140 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:05:29.141 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:05:29.142 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:05:29.143 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:05:29.144 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:05:29.144 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:05:29.145 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:05:29.147 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:05:29.148 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:05:29.149 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:05:29.150 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:05:29.150 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
!!! ~37 sec delay (probably local PC was busy processing this 29 signature points at the same time)
2021-05-14T06:06:06.151 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:06.152 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:06.153 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:06.154 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:06.155 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:06.157 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:06.158 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:13.595 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:13.597 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:13.598 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:13.599 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:13.600 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:13.601 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:14.609 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:14.611 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:14.611 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:14.612 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:14.613 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:14.614 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:14.614 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:14.615 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:14.616 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:14.617 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:14.618 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:14.619 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:14.620 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:14.620 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:14.621 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:14.622 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:14.623 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:14.623 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:14.642 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:14.643 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:14.644 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:14.645 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:14.645 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:14.646 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:14.647 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:14.648 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:14.649 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:14.650 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:14.650 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:14.651 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:14.652 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:14.653 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:14.653 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:14.654 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:14.655 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:14.656 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:14.657 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:14.658 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:14.659 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:14.660 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:14.661 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:14.662 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:14.663 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:14.664 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:14.666 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:14.669 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:14.671 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:06:14.672 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:07:16.366 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:07:16.368 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:07:16.369 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:07:32.472 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:07:32.474 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:07:32.475 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:07:32.476 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:07:32.477 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:07:32.478 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:07:32.478 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
!!! end of weird duplicating, again single ~10sec signature points
2021-05-14T06:07:41.683 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:07:47.638 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:07:54.102 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:08:06.293 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:08:15.626 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:08:24.158 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1
2021-05-14T06:08:33.968 harvester harvester_server        : INFO     <- new_signage_point_harvester from peer some_hash_or_key 127.0.0.1

[long-pham]

I'm having the same problem. Looks like the plots re-loading causes the issue. The problem goes away when I increase plot_loading_frequency_seconds: 1264000
All my USB HDDs never sleep and the looking time should be in milliseconds, not seconds. This issue could be a bug that could be fixed.

(running 5000 plots on Mac Mini M1, with FullNode v1.1.7)

[rmica]

Systems do have a limit, not only turing machines: the more you higher the average load, the less you can react to peaks. Overloading a box with storage leads to average acceptable time on average load, and to unacceptable response time on load peaks. Try to split boxes and/or to configure them to stay as much idle as possible.

[BrandtH22]

@dima-stefantsov , since this ticket was opened a number of years ago without further comments it seems this issue has been resolved.
We will be closing this ticket but if we have closed this ticket in error do not hesitate to reach out to us again with any followup questions or comments.

The best place to reach our support team is on Discord (https://discord.gg/chia) or by reopening this ticket.