Slow scanning and hash rate

erroneous · January 6, 2021, 10:44am

Once the initial startup logs and first directory walk had settled down, here’s the logs from once the hashing had started. Log has been sanitised.

[IDID_0] 2021/01/06 21:32:39.992358 logfs.go:61: DEBUG: mtimefs.go:90 basic /sync/Strata/FOLDER_LABEL_1 Lstat xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx/PointClouds/201214 Hawthorn Bridge 30M.potree {0xc001039790} <nil>
[IDID_0] 2021/01/06 21:32:39.993444 logfs.go:61: DEBUG: mtimefs.go:90 basic /sync/Strata/FOLDER_LABEL_1 Lstat xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx/PointClouds/201214 Hawthorn Bridge 30M.potree/data {0xc001039a00} <nil>
[IDID_0] 2021/01/06 21:32:39.994791 logfs.go:61: DEBUG: mtimefs.go:90 basic /sync/Strata/FOLDER_LABEL_1 Lstat xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx/PointClouds/201214 Hawthorn Bridge 30M.potree/data/r {0xc001039c70} <nil>
[IDID_0] 2021/01/06 21:32:39.996183 logfs.go:61: DEBUG: mtimefs.go:90 basic /sync/Strata/FOLDER_LABEL_1 Lstat xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx/PointClouds/201214 Hawthorn Bridge 30M.potree/data/r/41075 {0xc001039ee0} <nil>
[IDID_0] 2021/01/06 21:32:39.997741 logfs.go:61: DEBUG: mtimefs.go:90 basic /sync/Strata/FOLDER_LABEL_1 Lstat xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx/PointClouds/201214 Hawthorn Bridge 30M.potree/data/r/41077/r41077.hrc {0xc00103e1a0} <nil>
[IDID_0] 2021/01/06 21:32:39.998397 logfs.go:61: DEBUG: mtimefs.go:90 basic /sync/Strata/FOLDER_LABEL_1 Lstat xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx {0xc00103e410} <nil>
[IDID_0] 2021/01/06 21:32:39.999176 logfs.go:61: DEBUG: mtimefs.go:90 basic /sync/Strata/FOLDER_LABEL_1 Lstat xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx/PointClouds {0xc00103e680} <nil>
[IDID_0] 2021/01/06 21:32:40.000139 logfs.go:61: DEBUG: mtimefs.go:90 basic /sync/Strata/FOLDER_LABEL_1 Lstat xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx/PointClouds/201214 Hawthorn Bridge 30M.potree {0xc00103e8f0} <nil>
[IDID_0] 2021/01/06 21:32:40.001126 logfs.go:61: DEBUG: mtimefs.go:90 basic /sync/Strata/FOLDER_LABEL_1 Lstat xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx/PointClouds/201214 Hawthorn Bridge 30M.potree/data {0xc00103eb60} <nil>
[IDID_0] 2021/01/06 21:32:40.002266 logfs.go:61: DEBUG: mtimefs.go:90 basic /sync/Strata/FOLDER_LABEL_1 Lstat xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx/PointClouds/201214 Hawthorn Bridge 30M.potree/data/r {0xc00103edd0} <nil>
[IDID_0] 2021/01/06 21:32:40.004179 logfs.go:61: DEBUG: mtimefs.go:90 basic /sync/Strata/FOLDER_LABEL_1 Lstat xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx/PointClouds/201214 Hawthorn Bridge 30M.potree/data/r/41077 {0xc00103f040} <nil>
[IDID_0] 2021/01/06 21:32:40.004320 set.go:376: DEBUG: FOLDER_ID_1 WithBlocksHash("c7267123c3a183c22a8b1c5e8f0ebd5730146dc1f1179f1735bd438fd1f1b207")
[IDID_0] 2021/01/06 21:32:40.004568 walk.go:187: DEBUG: real to hash: SD340 GSSC Handrails & Balustrades/PointClouds/201229 A3 Wing 3 25M.potree/data/r/07612/r07612.bin
[IDID_0] 2021/01/06 21:32:40.005156 set.go:376: DEBUG: FOLDER_ID_1 WithBlocksHash("edd41546f80c33eb286bf6a624f043227f499bf1fae5dd83430a4cc5528b3ff6")
[IDID_0] 2021/01/06 21:32:40.005255 walk.go:187: DEBUG: real to hash: SD340 GSSC Handrails & Balustrades/PointClouds/201229 A3 Wing 3 25M.potree/data/r/07612/r07612.hrc
[IDID_0] 2021/01/06 21:32:40.005856 logfs.go:79: DEBUG: mtimefs.go:137 basic /sync/Strata/FOLDER_LABEL_1 Open SD340 GSSC Handrails & Balustrades/PointClouds/201229 A3 Wing 3 25M.potree/data/r/07611/r07611.hrc {0xc0143cc000 SD340 GSSC Handrails & Balustrades/PointClouds/201229 A3 Wing 3 25M.potree/data/r/07611/r07611.hrc} <nil>
[IDID_0] 2021/01/06 21:32:40.006634 set.go:376: DEBUG: FOLDER_ID_1 WithBlocksHash("afa052583465eddcbe65a75afce288204ee11e1a07ba41626457e878e6ba787b")
[IDID_0] 2021/01/06 21:32:40.006868 walk.go:187: DEBUG: real to hash: SD340 GSSC Handrails & Balustrades/PointClouds/201229 A3 Wing 3 25M.potree/data/r/07614/r07614.bin
[IDID_0] 2021/01/06 21:32:40.006956 logfs.go:79: DEBUG: mtimefs.go:137 basic /sync/Strata/FOLDER_LABEL_1 Open SD340 GSSC Handrails & Balustrades/PointClouds/201229 A3 Wing 3 25M.potree/data/r/07612/r07612.bin {0xc00a360038 SD340 GSSC Handrails & Balustrades/PointClouds/201229 A3 Wing 3 25M.potree/data/r/07612/r07612.bin} <nil>
[IDID_0] 2021/01/06 21:32:40.008259 logfs.go:79: DEBUG: mtimefs.go:137 basic /sync/Strata/FOLDER_LABEL_1 Open SD340 GSSC Handrails & Balustrades/PointClouds/201229 A3 Wing 3 25M.potree/data/r/07612/r07612.hrc {0xc0143cc048 SD340 GSSC Handrails & Balustrades/PointClouds/201229 A3 Wing 3 25M.potree/data/r/07612/r07612.hrc} <nil>
[IDID_0] 2021/01/06 21:32:40.008827 logfs.go:61: DEBUG: mtimefs.go:90 basic /sync/Strata/FOLDER_LABEL_1 Lstat yyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyy/PointClouds/191023 Combined.potree/data/r/00050/r00050.hrc {0xc00103f520} <nil>
[IDID_0] 2021/01/06 21:32:40.009499 logfs.go:61: DEBUG: mtimefs.go:90 basic /sync/Strata/FOLDER_LABEL_1 Lstat yyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyy {0xc00103f790} <nil>
[IDID_0] 2021/01/06 21:32:40.010306 logfs.go:61: DEBUG: mtimefs.go:90 basic /sync/Strata/FOLDER_LABEL_1 Lstat yyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyy/PointClouds {0xc00103fa00} <nil>
[IDID_0] 2021/01/06 21:32:40.011229 logfs.go:61: DEBUG: mtimefs.go:90 basic /sync/Strata/FOLDER_LABEL_1 Lstat yyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyy/PointClouds/191023 Combined.potree {0xc00103fc70} <nil>
[IDID_0] 2021/01/06 21:32:40.015318 logfs.go:61: DEBUG: mtimefs.go:90 basic /sync/Strata/FOLDER_LABEL_1 Lstat yyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyy/PointClouds/191023 Combined.potree/data {0xc00103fee0} <nil>
[IDID_0] 2021/01/06 21:32:40.016438 logfs.go:61: DEBUG: mtimefs.go:90 basic /sync/Strata/FOLDER_LABEL_1 Lstat yyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyy/PointClouds/191023 Combined.potree/data/r {0xc0010461a0} <nil>
[IDID_0] 2021/01/06 21:32:40.017687 logfs.go:61: DEBUG: mtimefs.go:90 basic /sync/Strata/FOLDER_LABEL_1 Lstat yyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyy/PointClouds/191023 Combined.potree/data/r/00050 {0xc001046410} <nil>
[IDID_0] 2021/01/06 21:32:40.019464 logfs.go:61: DEBUG: mtimefs.go:90 basic /sync/Strata/FOLDER_LABEL_1 Lstat yyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyy/PointClouds/191023 Combined.potree/data/r/00051/r00051.hrc {0xc001046680} <nil>
[IDID_0] 2021/01/06 21:32:40.020088 logfs.go:61: DEBUG: mtimefs.go:90 basic /sync/Strata/FOLDER_LABEL_1 Lstat yyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyy {0xc0010468f0} <nil>
[IDID_0] 2021/01/06 21:32:40.020711 logfs.go:61: DEBUG: mtimefs.go:90 basic /sync/Strata/FOLDER_LABEL_1 Lstat yyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyy/PointClouds {0xc001046b60} <nil>
[IDID_0] 2021/01/06 21:32:40.021482 logfs.go:61: DEBUG: mtimefs.go:90 basic /sync/Strata/FOLDER_LABEL_1 Lstat yyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyy/PointClouds/191023 Combined.potree {0xc001046dd0} <nil>
[IDID_0] 2021/01/06 21:32:40.022343 logfs.go:61: DEBUG: mtimefs.go:90 basic /sync/Strata/FOLDER_LABEL_1 Lstat yyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyy/PointClouds/191023 Combined.potree/data {0xc001047040} <nil>
[IDID_0] 2021/01/06 21:32:40.023335 logfs.go:61: DEBUG: mtimefs.go:90 basic /sync/Strata/FOLDER_LABEL_1 Lstat yyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyy/PointClouds/191023 Combined.potree/data/r {0xc0010472b0} <nil>
[IDID_0] 2021/01/06 21:32:40.024643 logfs.go:61: DEBUG: mtimefs.go:90 basic /sync/Strata/FOLDER_LABEL_1 Lstat yyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyy/PointClouds/191023 Combined.potree/data/r/00051 {0xc001047520} <nil>
[IDID_0] 2021/01/06 21:32:40.026069 logfs.go:61: DEBUG: mtimefs.go:90 basic /sync/Strata/FOLDER_LABEL_1 Lstat yyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyy/PointClouds/191023 Combined.potree/data/r/00052/r00052.hrc {0xc001047790} <nil>
[IDID_0] 2021/01/06 21:32:40.026782 logfs.go:61: DEBUG: mtimefs.go:90 basic /sync/Strata/FOLDER_LABEL_1 Lstat yyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyy {0xc001047a00} <nil>
[IDID_0] 2021/01/06 21:32:40.027454 logfs.go:61: DEBUG: mtimefs.go:90 basic /sync/Strata/FOLDER_LABEL_1 Lstat yyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyy/PointClouds {0xc001047c70} <nil>
[IDID_0] 2021/01/06 21:32:40.028246 logfs.go:61: DEBUG: mtimefs.go:90 basic /sync/Strata/FOLDER_LABEL_1 Lstat yyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyy/PointClouds/191023 Combined.potree {0xc001047ee0} <nil>

Watching the log scroll past, there are a ludicrous number of mtimefs.go lines and it seems to continually loop through the entire folder.