Hi Linus, I now created four profiles, one for the CSV import and three for the trust calculation. They are generated with: guile -L . > (import (wispwot wispwot)) > ,profile (define changed-and-state (import-trust-csv "trust-anonymized-2020-11-01-under-attack-sorted.csv")) > ,profile ((@@(wispwot wispwot)import-trust-value) (cdr changed-and-state) "OBSERVER" "OBSERVER" "15363" 100) > ,profile ((@@(wispwot wispwot)import-trust-value) (cdr changed-and-state) "OBSERVER" "OBSERVER" "242" 100) > ,profile ((@@(wispwot wispwot)import-trust-value) (cdr changed-and-state) "OBSERVER" "OBSERVER" "853" 100) % cumulative self time seconds seconds procedure 21.92 286.68 286.68 wispwot/wispwot.scm:456:18 21.14 276.46 276.46 wispwot/wispwot.scm:449:18 20.86 292.23 272.82 vector->list 13.26 2124682.83 173.39 srfi/srfi-1.scm:600:7:map2 6.46 84.52 84.52 %after-gc-thunk 4.04 55.03 52.83 wispwot/wispwot.scm:457:17 3.96 54.41 51.81 wispwot/wispwot.scm:450:17 2.27 29.69 29.63 make-srfi-4-vector 2.25 29.43 29.43 length+ 1.01 16.43 13.24 wispwot/wispwot.scm:276:0:calculate-scores 0.93 12.19 12.19 list-tail 0.53 6.92 6.92 display 0.23 3.10 3.01 write 0.16 1295.52 2.12 wispwot/wispwot.scm:375:0:import-trust-value 0.07 0.95 0.95 object->string 0.06 1309.39 0.80 srfi/srfi-1.scm:452:2:fold 0.06 0.78 0.78 srfi/srfi-4.scm:85:20:u16vector-set! 0.06 0.98 0.75 ice-9/pretty-print.scm:273:0:pretty-print 0.05 11.09 0.69 wispwot/wispwot.scm:513:8 0.05 4.98 0.66 ice-9/pretty-print.scm:258:2:rev-string-append 0.05 0.66 0.66 srfi/srfi-4.scm:85:20:s8vector-ref 0.05 0.63 0.63 vector-move-left! 0.03 16.75 0.45 ice-9/pretty-print.scm:37:0:generic-write 0.03 4.38 0.45 wispwot/wispwot.scm:349:0:vector-append! 0.03 0.45 0.45 srfi/srfi-4.scm:85:20:s8vector-set! 0.03 0.39 0.39 srfi/srfi-4.scm:85:20:u16vector-ref 0.03 29.90 0.33 srfi/srfi-1.scm:580:2:map 0.03 9.09 0.33 ice-9/pretty-print.scm:62:4:loop 0.03 0.66 0.33 make-vector 0.02 32.59 0.27 wispwot/wispwot.scm:194:0:calculate-ranks 0.02 0.92 0.27 wispwot/wispwot.scm:415:2:find-index-record-if-needed 0.02 0.27 0.27 procedure? 0.02 0.24 0.24 ice-9/boot-9.scm:1345:3 0.02 0.24 0.24 make-string 0.01 0.18 0.18 ice-9/pretty-print.scm:100:12 0.01 0.18 0.18 min 0.01 6.14 0.15 ice-9/pretty-print.scm:293:17 0.01 0.21 0.15 ice-9/pretty-print.scm:72:22 0.01 0.15 0.15 srfi/srfi-4.scm:85:20:u16vector->list 0.01 0.15 0.15 remove 0.01 0.12 0.12 length 0.01 0.12 0.12 srfi/srfi-4.scm:76:2:make-u8vector 0.01 0.12 0.12 random 0.01 0.12 0.12 srfi/srfi-4.scm:85:20:s8vector-length 0.01 0.15 0.09 srfi/srfi-4.scm:85:20:u16vector-length 0.01 0.12 0.09 %read-line 0.01 0.09 0.09 srfi/srfi-4.scm:85:20:list->u8vector 0.01 0.09 0.09 srfi/srfi-4.scm:85:20:u8vector-set! 0.01 0.09 0.09 hash-ref 0.01 0.09 0.09 ice-9/pretty-print.scm:61:2:wr 0.01 0.09 0.09 cdr 0.00 1.40 0.06 ice-9/pretty-print.scm:58:2:out 0.00 0.39 0.06 wispwot/wispwot.scm:504:4 0.00 0.06 0.06 integer? 0.00 0.06 0.06 ice-9/boot-9.scm:806:0:and=> 0.00 8.08 0.03 ice-9/pretty-print.scm:95:4:pr 0.00 0.24 0.03 srfi/srfi-4.scm:85:20:list->u8vector 0.00 0.09 0.03 string-split 0.00 0.03 0.03 srfi/srfi-4.scm:85:20:make-u16vector 0.00 0.03 0.03 car 0.00 0.03 0.03 srfi/srfi-4.scm:85:20:make-s8vector 0.00 0.03 0.03 eof-object? 0.00 0.03 0.03 srfi/srfi-4.scm:85:20:s8vector->list 0.00 0.03 0.03 ice-9/pretty-print.scm:256:0:reverse-string-append 0.00 0.03 0.03 list? 0.00 0.03 0.03 ice-9/boot-9.scm:888:0:iota 0.00 0.03 0.03 reverse! 0.00 0.03 0.03 append 0.00 0.03 0.03 list-head 0.00 0.03 0.03 srfi/srfi-1.scm:584:5:map1 0.00 1307.69 0.00 ice-9/ports.scm:428:0:call-with-input-file 0.00 1307.69 0.00 :2:9 0.00 1307.69 0.00 ice-9/ports.scm:492:3 0.00 563.14 0.00 remove 0.00 84.52 0.00 anon #x7a24b0 0.00 54.83 0.00 gc 0.00 3.10 0.00 object->string 0.00 0.12 0.00 ice-9/rdelim.scm:193:0:read-line 0.00 0.03 0.00 inexact->exact --- Sample count: 43863 Total time: 1307.687229447 seconds (726.756595442 seconds in GC) % cumulative self time seconds seconds procedure 57.35 21.72 21.56 wispwot/wispwot.scm:194:0:calculate-ranks 11.35 4.27 4.27 wispwot/wispwot.scm:324:10:discard 4.91 3.43 1.85 wispwot/wispwot.scm:313:10:add-to-score 4.17 1.59 1.57 truncate/ 2.96 1.11 1.11 ice-9/boot-9.scm:888:0:iota 2.57 15.87 0.96 wispwot/wispwot.scm:276:0:calculate-scores 2.43 226.03 0.92 srfi/srfi-1.scm:600:7:map2 2.13 0.90 0.80 srfi/srfi-4.scm:85:20:u16vector->list 1.74 0.65 0.65 srfi/srfi-4.scm:85:20:u8vector-set! 1.65 0.67 0.62 srfi/srfi-4.scm:85:20:s8vector->list 0.96 0.85 0.36 srfi/srfi-1.scm:580:2:map 0.91 0.34 0.34 make-srfi-4-vector 0.87 0.33 0.33 append 0.74 1.34 0.28 srfi/srfi-4.scm:85:20:list->u8vector 0.70 0.31 0.26 srfi/srfi-4.scm:85:20:s8vector-length 0.70 0.26 0.26 remove 0.61 0.23 0.23 length+ 0.48 0.18 0.18 integer? 0.39 21.17 0.15 srfi/srfi-1.scm:584:5:map1 0.39 0.15 0.15 reverse! 0.35 0.13 0.13 car 0.30 0.11 0.11 wispwot/wispwot.scm:338:19 0.26 0.10 0.10 procedure? 0.26 0.10 0.10 min 0.17 0.07 0.07 %after-gc-thunk 0.17 0.07 0.07 list? 0.17 0.07 0.07 length 0.13 0.05 0.05 srfi/srfi-4.scm:85:20:list->u8vector 0.09 0.03 0.03 delete-duplicates 0.09 0.03 0.03 wispwot/wispwot.scm:236:10:discard 0.00 37.59 0.00 wispwot/wispwot.scm:375:0:import-trust-value 0.00 4.30 0.00 remove 0.00 0.07 0.00 anon #x7a24b0 --- Sample count: 2300 Total time: 37.593051451 seconds (0.998694416 seconds in GC) % cumulative self time seconds seconds procedure 69.60 47.03 46.98 wispwot/wispwot.scm:194:0:calculate-ranks 9.26 6.25 6.25 wispwot/wispwot.scm:324:10:discard 3.14 2.12 2.12 truncate/ 3.11 4.22 2.10 wispwot/wispwot.scm:313:10:add-to-score 2.36 241.68 1.60 srfi/srfi-1.scm:600:7:map2 1.91 1.38 1.29 ice-9/boot-9.scm:888:0:iota 1.62 20.47 1.09 wispwot/wispwot.scm:276:0:calculate-scores 1.30 0.93 0.88 srfi/srfi-4.scm:85:20:u16vector->list 1.18 0.81 0.80 srfi/srfi-4.scm:85:20:s8vector->list 1.06 0.72 0.72 srfi/srfi-4.scm:85:20:u8vector-set! 0.63 0.54 0.42 srfi/srfi-4.scm:85:20:s8vector-length 0.58 0.39 0.39 remove 0.53 0.36 0.36 append 0.46 0.31 0.31 make-srfi-4-vector 0.46 0.31 0.31 length+ 0.41 0.28 0.28 integer? 0.39 0.98 0.26 srfi/srfi-1.scm:580:2:map 0.36 0.24 0.24 procedure? 0.34 1.35 0.23 srfi/srfi-4.scm:85:20:list->u8vector 0.31 0.21 0.21 reverse! 0.22 16.14 0.15 srfi/srfi-1.scm:584:5:map1 0.19 0.13 0.13 car 0.17 0.11 0.11 wispwot/wispwot.scm:338:19 0.14 0.10 0.10 min 0.14 0.10 0.10 length 0.10 0.07 0.07 list? 0.02 0.02 0.02 srfi/srfi-4.scm:85:20:list->u8vector 0.00 67.50 0.00 wispwot/wispwot.scm:375:0:import-trust-value 0.00 6.25 0.00 remove --- Sample count: 4145 Total time: 67.498343877 seconds (1.476365885 seconds in GC) % cumulative self time seconds seconds procedure 57.04 35.87 35.81 wispwot/wispwot.scm:194:0:calculate-ranks 12.43 7.81 7.81 wispwot/wispwot.scm:324:10:discard 4.84 5.95 3.04 wispwot/wispwot.scm:313:10:add-to-score 4.61 2.91 2.89 truncate/ 3.30 367.72 2.07 srfi/srfi-1.scm:600:7:map2 2.96 26.90 1.86 wispwot/wispwot.scm:276:0:calculate-scores 2.72 1.73 1.71 ice-9/boot-9.scm:888:0:iota 1.81 1.13 1.13 srfi/srfi-4.scm:85:20:u8vector-set! 1.60 1.04 1.00 srfi/srfi-4.scm:85:20:u16vector->list 1.13 0.74 0.71 srfi/srfi-4.scm:85:20:s8vector->list 0.99 0.62 0.62 make-srfi-4-vector 0.84 2.35 0.53 srfi/srfi-4.scm:85:20:list->u8vector 0.73 1.46 0.46 srfi/srfi-1.scm:580:2:map 0.68 0.43 0.43 length+ 0.68 0.43 0.43 remove 0.60 0.51 0.38 srfi/srfi-4.scm:85:20:s8vector-length 0.58 0.36 0.36 append 0.50 0.31 0.31 procedure? 0.42 0.26 0.26 reverse! 0.34 0.21 0.21 integer? 0.29 0.18 0.18 list? 0.24 0.15 0.15 wispwot/wispwot.scm:338:19 0.18 0.12 0.12 car 0.13 0.08 0.08 min 0.10 22.56 0.07 srfi/srfi-1.scm:584:5:map1 0.10 0.07 0.07 srfi/srfi-4.scm:85:20:list->u8vector 0.10 0.07 0.07 length 0.03 0.02 0.02 %after-gc-thunk 0.03 0.02 0.02 wispwot/wispwot.scm:236:10:discard 0.00 62.77 0.00 wispwot/wispwot.scm:375:0:import-trust-value 0.00 7.82 0.00 remove 0.00 0.02 0.00 anon #x7a24b0 --- Sample count: 3820 Total time: 62.773351245 seconds (2.013414284 seconds in GC) (I see here that the GC time during actual trust calculation is much lower than I had expected) I hope they help! (you’ll have to pull again — with `hg pull -u` — to get import-trust-csv exported) Best wishes, Arne Dr. Arne Babenhauserheide writes: > PS: Still it is important to get this code fast, because it is the > fallback for all situations where I cannot cheat and only calculate > a subset of the trust, and it is required at startup. > > Dr. Arne Babenhauserheide writes: > >> Hi Linus, >> >> Linus Björnstam writes: >>> I had a look and there is quite a lot you can do. Just out of >>> curiosity: how much is GC time? You are generating a lot of >>> intermediate data. Instead of vector-append! maybe use something like >>> the new vectorlist srfi? If you show me a flame graph and give me some >>> test data I can have a go! >> >> Thank you! >> >> I expect GC time to be roughly half during the trust calculation (much >> more during import), because this fills up two cores. >> >> I can’t easily give you a flame graph (except if you can tell me how to >> generate it), but I now pushed a version in pure Scheme (instead of >> wisp) that runs a huge test: >> >> hg clone https://hg.sr.ht/~arnebab/wispwot >> cd wispwot >> ./run-wispwot.scm --test >> >> This imports 200k trust edges (which takes a lot of time) and then does >> three full trust calculations (which each take around 70s). >> >> The most important limitation for optimization is that the memory use >> must stay reasonable with 64k IDs which each have 1000 trust edges. This >> memory use is what the current code is optimized for (that’s why there >> are all those u8vectors and u16vectors). >> >> For the math: at 64 million trust edges, this should currently require >> (in theory) less than 200MiB of memory for the actual trust structure (2 >> byte for the id, 1 byte for the trust). >> >> Going up to 300MiB for time-optimization would still be viable, but it >> shouldn’t go beyond that (there are algorithmic options to reduce the >> amount of work done per update, so the runtime of the current code is >> important but it is not a life-and-death situation). >> >> Best wishes, >> Arne -- Unpolitisch sein heißt politisch sein ohne es zu merken