aboutsummaryrefslogtreecommitdiffstats
path: root/notes/import_timing_20180815.txt
diff options
context:
space:
mode:
Diffstat (limited to 'notes/import_timing_20180815.txt')
-rw-r--r--notes/import_timing_20180815.txt292
1 files changed, 0 insertions, 292 deletions
diff --git a/notes/import_timing_20180815.txt b/notes/import_timing_20180815.txt
deleted file mode 100644
index 1206cc41..00000000
--- a/notes/import_timing_20180815.txt
+++ /dev/null
@@ -1,292 +0,0 @@
-
-Schema changes since previous imports:
-- more fields (identifiers+indexes)
-- timestamps
-- UUIDs more places
-- fixed some crossref import bugs?
-- abstracts
-- file_urls as table (not single value)
-- timestamps
-- TEXT -> CHAR in a few places
-- removed many work fields
-
-## Containers
-
-(python)webcrawl@wbgrp-svc500:/srv/fatcat/src/python$ time ./fatcat_import.py import-issn /srv/datasets/journal_extra_metadata.csv
-
-real 1m25.292s
-user 0m12.640s
-sys 0m0.412s
-
-## Creators
-
-time parallel --bar --pipepart -j8 -a /srv/datasets/public_profiles_1_2_json.all.json ./fatcat_import.py import-orcid -
-
-(times very invalid due to hangs; got 3537837 creators, which is most of the way, so *shrug*)
-real 22m2.465s
-user 26m41.924s
-sys 1m33.844s
-
-## Releases
-
-xzcat /srv/datasets/crossref-works.2018-01-21.json.xz | time parallel -j20 --round-robin --pipe ./fatcat_import.py import-crossref - /srv/datasets/20180216.ISSN-to-ISSN-L.txt
-
- 128516.30 user
- 3905.14 system
- 44:17:05 elapsed
- 83% CPU
-
-Almost 44 hours... I think I remember more like 36 hours last time? Things
-slowed down a lot towards the end, many more ORCID cross-references?
-
-looking in htop, postgres seems to be primary bottleneck. At something like 12
-hours in, had 44 million release_ident rows, which is 1000/second.
-
-Note: seems like the more frequently `count(*)` is run, the more performant.
-Because in-memory?
-
- 2018-08-16 16:54:16.977 UTC [17996] postgres@fatcat_prod LOG: duration: 42949.549 ms statement: select count(id) from release_ident;
-
- fatcat_prod=# select count(*) from release_ident;
- count
- ----------
- 44185608
- (1 row)
-
- Time: 2753.916 ms (00:02.754)
- fatcat_prod=# select count(*) from release_ident;
- count
- ----------
- 44187937
- (1 row)
-
- Time: 2711.670 ms (00:02.712)
-
-As expected, autovacuum very busy. Only ~150 TPS; but that includes batch
-writes? 75061172 rows.
-
-## Files
-
- time ./fatcat_import.py import-manifest /srv/datasets/idents_files_urls.sqlite
-
- Done! Inserted 6607075
-
- real 2152m28.822s => 36 hours (!)
- user 401m46.464s
- sys 21m45.724s
-
-
-Going pretty slow, < 100 transactions/sec. Lots of SELECTs, which seem slow, on the abstract table?
-
- SELECT "release_rev_abstract"."id", "release_rev_abstract"."release_rev", "release_rev_abstract"."abstract_sha1", "release_rev_abstract"."mimetype", "release_rev_abstract"."lang", "abstracts"."sha1", "abstracts"."content" FROM ("release_rev_abstract" INNER JOIN "abstracts" ON "release_rev_abstract"."abstract_sha1" = "abstracts"."sha1") WHERE "release_rev_abstract"."release_rev" = 'ffffffc0-4dd2-47ce-a51d-44051f3699ce';
-
-Created index:
-
- CREATE INDEX release_rev_abstract_rev_idx ON release_rev_abstract(release_rev);
-
-... and things sped way up. Re-ran some crossref imports to EXPLAIN and didn't
-see non-indexed queries. Maybe an ANALYZE does need to happen?
-
-This being single-threaded is going to be a problem in the future. ~50 million
-files would be ~2 weeks.
-
-## Post-Import Status
-
- Size: 358.89G (postgres self-reported)
- Mem.: 57.10% - 16.85G/49.14G
-
-Was 184G last time in late June; doubled in size (!).
-
- bnewbold@wbgrp-svc500$ df -h /
- Filesystem Size Used Avail Use% Mounted on
- /dev/vda1 858G 529G 286G 65% /
-
- bnewbold@wbgrp-svc500$ sudo du -sh /var/lib/postgresql/ /srv/datasets/ /srv/elastic-blah/
- 361G /var/lib/postgresql/
- 83G /srv/datasets/
- 77G /srv/elastic-blah/
-
- fatcat_prod=# select count(*) from changelog; => 2,085,067
-
- SELECT
- table_name,
- pg_size_pretty(table_size) AS table_size,
- pg_size_pretty(indexes_size) AS indexes_size,
- pg_size_pretty(total_size) AS total_size
- FROM (
- SELECT
- table_name,
- pg_table_size(table_name) AS table_size,
- pg_indexes_size(table_name) AS indexes_size,
- pg_total_relation_size(table_name) AS total_size
- FROM (
- SELECT ('"' || table_schema || '"."' || table_name || '"') AS table_name
- FROM information_schema.tables
- ) AS all_tables
- ORDER BY total_size DESC
- ) AS pretty_sizes;
-
- table_name | table_size | indexes_size | total_size
---------------------------------------------------------------+------------+--------------+------------
- "public"."release_ref" | 159 GB | 47 GB | 206 GB
- "public"."release_rev" | 40 GB | 10 GB | 51 GB
- "public"."release_contrib" | 19 GB | 20 GB | 39 GB
- "public"."release_ident" | 5797 MB | 6597 MB | 12 GB
- "public"."work_ident" | 5787 MB | 6394 MB | 12 GB
- "public"."release_edit" | 6674 MB | 4646 MB | 11 GB
- "public"."work_edit" | 6674 MB | 4646 MB | 11 GB
- "public"."work_rev" | 3175 MB | 2939 MB | 6114 MB
- "public"."file_rev_url" | 1995 MB | 275 MB | 2270 MB
- "public"."abstracts" | 1665 MB | 135 MB | 1800 MB
- "public"."file_rev" | 829 MB | 954 MB | 1783 MB
- "public"."file_ident" | 498 MB | 532 MB | 1030 MB
- "public"."file_release" | 369 MB | 642 MB | 1011 MB
- "public"."file_edit" | 591 MB | 410 MB | 1002 MB
- "public"."creator_rev" | 337 MB | 318 MB | 655 MB
- "public"."creator_ident" | 280 MB | 297 MB | 577 MB
- "public"."creator_edit" | 316 MB | 220 MB | 536 MB
- "public"."release_rev_abstract" | 183 MB | 84 MB | 267 MB
- "public"."changelog" | 123 MB | 125 MB | 249 MB
- "public"."editgroup" | 139 MB | 81 MB | 220 MB
- "public"."container_rev" | 19 MB | 6912 kB | 26 MB
- "public"."container_ident" | 6896 kB | 7016 kB | 14 MB
- "public"."container_edit" | 8056 kB | 5240 kB | 13 MB
-
-In context, the full uncompressed crossref 2018-01-21 dump is about 285 GB.
-
-For many of these indexes, and the _ident tables, switching from UUID to
-BIGSERIAL would half the size.
-
-## Exports
-
- time ./fatcat_export.py changelog - | pv -l | wc
-
- As of:
-
- 159k 1:17:35 [34.3 /s]
- 159,740 lines
- 2,427,277,881 chars (bytes; 2.4GB)
-
- real 77m35.183s
- user 15m36.208s
- sys 0m31.484s
-
-Running at about 100/sec; estimate 6 hours for completion. Could shard using
-start/end flags, but am not here.
-
-Running `quick_dump.sql` (identifier tables, in a transaction):
-
- 251M Aug 19 23:08 fatcat_ident_creators.tsv
- 5.9M Aug 19 23:08 fatcat_ident_containers.tsv
- 467M Aug 19 23:08 fatcat_ident_files.tsv
- 5.2G Aug 19 23:10 fatcat_ident_releases.tsv
- 5.2G Aug 19 23:11 fatcat_ident_works.tsv
- 12K Aug 19 23:11 .
- 1.8G Aug 19 23:12 fatcat_abstracts.json
-
-Work and Release tables in under 2 minutes each; say 5 minutes total.
-
- time ./fatcat_export.py releases /tmp/fatcat_ident_releases.tsv - | pv -l | wc
-
- 172k 1:07:08 [42.7 /s]
- 172181 lines
- 1,118,166,293 chars (bytes; 1.1 GB)
-
- real 67m8.340s
- user 10m21.988s
- sys 0m34.612s
-
-Running at only 10/sec or so, this would take forever even if sharded. :(
-
-Both exports/dumps are running in parallel. "Expand" queries might help with speed?
-
-## Postgres Analysis
-
-SELECT *
-FROM
- pg_stat_statements
-ORDER BY
- total_time DESC LIMIT 5;
-
-Summary:
-
- SELECT "creator_ident" by ORCID
- 1,295,864 calls
- 930,305,208 total time
- 717.9 mean time <= this should be less than a ms!
-
- INSERT INTO release_rev
- 75144055 calls
- 111470961 total time
- 1.483 mean time
-
- INSERT INTO work_rev
- 75,144,055 calls
- 82693994 total time
- 1.1 mean time
-
- INSERT INTO release_contrib (creator_ident_id = DEFAULT) RETURNING *
- 26,008,280 calls <= why so few? different query depending on number
- of rows inserted
- 18955782 total time
- 0.728 mean time
-
- SELECT container_ident
- 78,4143 calls
- 17683156 total time
- 22.55 mean time <= why so slow?
-
- INSERT INTO release_contrib
- 15,072,820 calls
-
- INSERT INTO "release_contrib
-
-
- relname | too_much_seq | case | rel_size | seq_scan | idx_scan
-----------------------+--------------+----------------+--------------+----------+-----------
- file_rev_url | 2391 | Missing Index? | 2091147264 | 2391 | 0
- file_release | -30670 | OK | 386899968 | 2 | 30672
- container_rev | -979948 | OK | 20242432 | 784146 | 1764094
- file_edit | -2206807 | OK | 619896832 | 6 | 2206813
- creator_edit | -2206810 | OK | 331079680 | 11 | 2206821
- work_edit | -2206811 | OK | 6996566016 | 14 | 2206825
- release_edit | -2206811 | OK | 6996582400 | 14 | 2206825
- container_edit | -2206816 | OK | 8216576 | 5 | 2206821
- changelog | -2209659 | OK | 129286144 | 10 | 2209669
- abstracts | -3486466 | OK | 1706237952 | 8 | 3486474
- release_rev_abstract | -4975493 | OK | 191602688 | 42919 | 5018412
- release_ref | -5032717 | OK | 170494861312 | 3 | 5032720
- release_contrib | -5032744 | OK | 20370251776 | 3 | 5032747
- creator_rev | -8400410 | OK | 353583104 | 1296507 | 9696917
- file_ident | -13483224 | OK | 522190848 | 7 | 13483231
- creator_ident | -16686744 | OK | 293625856 | 3 | 16686747
- file_rev | -32405557 | OK | 868515840 | 4 | 32405561
- container_ident | -69162337 | OK | 7028736 | 3 | 69162340
- work_rev | -150288161 | OK | 3328589824 | 1 | 150288162
- editgroup | -162783807 | OK | 146112512 | 9 | 162783816
- release_ident | -165676917 | OK | 6076841984 | 52 | 165676969
- work_ident | -229439828 | OK | 6066814976 | 3 | 229439831
- release_rev | -930140217 | OK | 43360542720 | 9 | 930140226
-
-TODO changes:
-- don't return all as often; in particular, inserting release_contrib, release_ref
-x missing an index somewhere on file_rev_url, release_rev_abstract
-x why so many seq_scan on container_rev, creator_rev
- => running/EXPLAIN same query on psql hits index, not seq_scan
- => seemed to be an issue with VALUE params getting sent separately; query
- planner only looked at query and wasn't using index on ORCID/ISSN-L because
- it didn't know those values were not-NULL?
- => adding NOT NULL to query seems to have sped up case of there being a
- "hit", but no hit still slow. might need to change indices or something for
- the (perhaps common in future) case of DOI lookups with invalid DOIs (eg,
- CORE import)
-
-random DEBUG queries:
-
- EXPLAIN ANALYSE SELECT "creator_ident"."id", "creator_ident"."is_live", "creator_ident"."rev_id", "creator_ident"."redirect_id", "creator_rev"."id", "creator_rev"."extra_json", "creator_rev"."display_name", "creator_rev"."given_name", "creator_rev"."surname", "creator_rev"."orcid", "creator_rev"."wikidata_qid" FROM ("creator_ident" INNER JOIN "creator_rev" ON "creator_ident"."rev_id" = "creator_rev"."id") WHERE "creator_rev"."orcid" = '0000-0002-8867-1663' AND "creator_ident"."is_live" = true AND "creator_ident"."redirect_id" IS NULL LIMIT 1;
-
- EXPLAIN VERBOSE SELECT "creator_ident"."id", "creator_ident"."is_live", "creator_ident"."rev_id", "creator_ident"."redirect_id", "creator_rev"."id", "creator_rev"."extra_json", "creator_rev"."display_name", "creator_rev"."given_name", "creator_rev"."surname", "creator_rev"."orcid", "creator_rev"."wikidata_qid" FROM ("creator_ident" INNER JOIN "creator_rev" ON "creator_ident"."rev_id" = "creator_rev"."id") WHERE "creator_rev"."orcid" = $1 AND "creator_ident"."is_live" = true AND "creator_ident"."redirect_id" IS NULL VALUES ('0000-0002-8867-1669') LIMIT 1;
-
- EXPLAIN SELECT "container_ident"."id", "container_ident"."is_live", "container_ident"."rev_id", "container_ident"."redirect_id", "container_rev"."id", "container_rev"."extra_json", "container_rev"."name", "container_rev"."publisher", "container_rev"."issnl", "container_rev"."wikidata_qid", "container_rev"."abbrev", "container_rev"."coden" FROM ("container_ident" INNER JOIN "container_rev" ON "container_ident"."rev_id" = "container_rev"."id") WHERE "container_rev"."issnl" = '0001-0782' AND "container_ident"."is_live" = true AND "container_ident"."redirect_id" IS NULL LIMIT 1;
-
- SELECT "creator_ident"."id", "creator_ident"."is_live", "creator_ident"."rev_id", "creator_ident"."redirect_id", "creator_rev"."id", "creator_rev"."extra_json", "creator_rev"."display_name", "creator_rev"."given_name", "creator_rev"."surname", "creator_rev"."orcid", "creator_rev"."wikidata_qid" FROM ("creator_ident" INNER JOIN "creator_rev" ON "creator_ident"."rev_id" = "creator_rev"."id") WHERE "creator_rev"."orcid" = '0000-0002-8867-1663' AND "creator_ident"."is_live" = 't' AND "creator_ident"."redirect_id" IS NULL LIMIT 1;