Harvest for Kazilas et al 2018 Created 19 Apr 15:52

Harvesting Log

# Logfile created on 2020-08-27 15:47:56 -0400 by logger.rb/v1.4.2
[START] [2020-08-27 15:47:56] logged process
[START] [2020-08-27 15:47:56] Creating resource from OpenData
[START] [2020-08-27 15:47:56] logged process
[START] [2020-08-27 15:47:56] Parse meta.xml file and create formats with fields
[STOP] [2020-08-27 15:47:56] Parse meta.xml file and create formats with fields
[STOP] [2020-08-27 15:47:56] Creating resource from OpenData
[INFO] [2020-12-03 12:03:32] ## HARVEST: type = -harvest
[START] [2020-12-03 12:03:49] logged process: 58bbc42b01abb4c1b2698de049792ffb4b63b979

[START] [2020-12-03 12:03:49] create_harvest_instance
[STOP] [2020-12-03 12:03:50] create_harvest_instance
[START] [2020-12-03 12:03:50] fetch_files
[STOP] [2020-12-03 12:03:50] fetch_files
[START] [2020-12-03 12:03:50] validate_each_file
[STOP] [2020-12-03 12:03:50] validate_each_file
[START] [2020-12-03 12:03:51] convert_to_csv
[CMD] [2020-12-03 12:03:51] /usr/bin/sort /app/public/converted_csv/kazilas_et_al_ka_refs_24864.csv > /app/public/converted_csv/kazilas_et_al_ka_refs_24864.csv_sorted
[CMD] [2020-12-03 12:03:51] /usr/bin/sort /app/public/converted_csv/kazilas_et_al_ka_nodes_24865.csv > /app/public/converted_csv/kazilas_et_al_ka_nodes_24865.csv_sorted
[CMD] [2020-12-03 12:03:51] /usr/bin/sort /app/public/converted_csv/kazilas_et_al_ka_occurrences_24866.csv > /app/public/converted_csv/kazilas_et_al_ka_occurrences_24866.csv_sorted
[CMD] [2020-12-03 12:03:51] /usr/bin/sort /app/public/converted_csv/kazilas_et_al_ka_measurements_24867.csv > /app/public/converted_csv/kazilas_et_al_ka_measurements_24867.csv_sorted
[STOP] [2020-12-03 12:03:51] convert_to_csv
[START] [2020-12-03 12:03:51] calculate_delta
[CMD] [2020-12-03 12:03:51] echo "0a" > /app/public/diff/kazilas_et_al_ka_refs_24864.diff
[CMD] [2020-12-03 12:03:51] tail -n +1 /app/public/converted_csv/kazilas_et_al_ka_refs_24864.csv >> /app/public/diff/kazilas_et_al_ka_refs_24864.diff
[CMD] [2020-12-03 12:03:51] echo "." >> /app/public/diff/kazilas_et_al_ka_refs_24864.diff
[CMD] [2020-12-03 12:03:51] echo "0a" > /app/public/diff/kazilas_et_al_ka_nodes_24865.diff
[CMD] [2020-12-03 12:03:51] tail -n +1 /app/public/converted_csv/kazilas_et_al_ka_nodes_24865.csv >> /app/public/diff/kazilas_et_al_ka_nodes_24865.diff
[CMD] [2020-12-03 12:03:51] echo "." >> /app/public/diff/kazilas_et_al_ka_nodes_24865.diff
[CMD] [2020-12-03 12:03:51] echo "0a" > /app/public/diff/kazilas_et_al_ka_occurrences_24866.diff
[CMD] [2020-12-03 12:03:51] tail -n +1 /app/public/converted_csv/kazilas_et_al_ka_occurrences_24866.csv >> /app/public/diff/kazilas_et_al_ka_occurrences_24866.diff
[CMD] [2020-12-03 12:03:51] echo "." >> /app/public/diff/kazilas_et_al_ka_occurrences_24866.diff
[CMD] [2020-12-03 12:03:51] echo "0a" > /app/public/diff/kazilas_et_al_ka_measurements_24867.diff
[CMD] [2020-12-03 12:03:51] tail -n +1 /app/public/converted_csv/kazilas_et_al_ka_measurements_24867.csv >> /app/public/diff/kazilas_et_al_ka_measurements_24867.diff
[CMD] [2020-12-03 12:03:51] echo "." >> /app/public/diff/kazilas_et_al_ka_measurements_24867.diff
[STOP] [2020-12-03 12:03:51] calculate_delta
[START] [2020-12-03 12:03:51] parse_diff_and_store
[INFO] [2020-12-03 12:03:51] Loading refs diff file into memory (true lines)...
[INFO] [2020-12-03 12:03:51] Loading nodes diff file into memory (true lines)...
[INFO] [2020-12-03 12:03:51] Loading occurrences diff file into memory (true lines)...
[INFO] [2020-12-03 12:03:51] Loading measurements diff file into memory (true lines)...
[INFO] [2020-12-03 12:03:51] Storing 1 ScientificNames
[INFO] [2020-12-03 12:03:51] Processing group of 1 in 1 groups of 1000
[INFO] [2020-12-03 12:03:51] Average Time: 0.0
[INFO] [2020-12-03 12:03:51] Total Time: 1s
[INFO] [2020-12-03 12:03:51] Storing 1 Nodes
[INFO] [2020-12-03 12:03:51] Processing group of 1 in 1 groups of 1000
[INFO] [2020-12-03 12:03:51] Average Time: 0.0
[INFO] [2020-12-03 12:03:51] Total Time: 1s
[INFO] [2020-12-03 12:03:51] Storing 1 Occurrences
[INFO] [2020-12-03 12:03:51] Processing group of 1 in 1 groups of 1000
[INFO] [2020-12-03 12:03:51] Average Time: 0.0
[INFO] [2020-12-03 12:03:51] Total Time: 1s
[INFO] [2020-12-03 12:03:51] Storing 2 Traits
[INFO] [2020-12-03 12:03:51] Processing group of 2 in 1 groups of 1000
[INFO] [2020-12-03 12:03:51] Average Time: 0.01
[INFO] [2020-12-03 12:03:51] Total Time: 1s
[INFO] [2020-12-03 12:03:51] Storing 1 MetaTraits
[INFO] [2020-12-03 12:03:51] Processing group of 1 in 1 groups of 1000
[INFO] [2020-12-03 12:03:51] Average Time: 0.0
[INFO] [2020-12-03 12:03:51] Total Time: 1s
[STOP] [2020-12-03 12:03:51] parse_diff_and_store
[START] [2020-12-03 12:03:51] resolve_keys
[STOP] [2020-12-03 12:03:52] resolve_keys
[ERR] [2020-12-03 12:03:52] ActiveRecord::StatementInvalid
[ERR] [2020-12-03 12:03:52] Lockfile::StolenLockError: Lockfile::StolenLockError: SELECT MIN(`articles_sections`.`id`) FROM `articles_sections` WHERE (1=1) AND `articles_sections`.`harvest_id` = 3272
[ERR] [2020-12-03 12:03:52] ./config/initializers/core_extensions.rb:14:in `propagate_id'
[ERR] [2020-12-03 12:03:52] ../models/resource_harvester.rb:593:in `propagate_id'
[ERR] [2020-12-03 12:03:52] ../models/resource_harvester.rb:488:in `resolve_article_keys'
[ERR] [2020-12-03 12:03:52] ../models/resource_harvester.rb:446:in `resolve_keys'
[ERR] [2020-12-03 12:03:52] ../models/resource_harvester.rb:85:in `block (3 levels) in start'
[ERR] [2020-12-03 12:03:52] ../models/logged_process.rb:19:in `run_step'
[ERR] [2020-12-03 12:03:52] ../models/resource_harvester.rb:85:in `block (2 levels) in start'
[ERR] [2020-12-03 12:03:52] ../models/resource_harvester.rb:74:in `each_key'
[ERR] [2020-12-03 12:03:52] ../models/resource_harvester.rb:74:in `block in start'
[ERR] [2020-12-03 12:03:52] ../models/resource.rb:151:in `lock'
[ERR] [2020-12-03 12:03:52] ../models/resource_harvester.rb:72:in `start'
[ERR] [2020-12-03 12:03:52] ../models/resource.rb:232:in `harvest'
[ERR] [2020-12-03 12:03:52] bin/rails:4:in `require'
[ERR] [2020-12-03 12:03:52] bin/rails:4:in `<main>'
[STOP] [2020-12-03 12:03:52] logged process, took 3.15
[INFO] [2020-12-03 12:04:09] ## HARVEST: type = re_download_opendata_-harvest
[INFO] [2020-12-03 12:04:12] ## remove_type: ScientificName
[INFO] [2020-12-03 12:04:12] ++ Calling delete_all on 1 instances...
[INFO] [2020-12-03 12:04:12] [12:04:12.161] Removed 1 Scientificnames
[INFO] [2020-12-03 12:04:12] ## remove_type: Vernacular
[INFO] [2020-12-03 12:04:12] ++ Calling delete_all on 0 instances...
[INFO] [2020-12-03 12:04:12] [12:04:12.164] Removed 0 Vernaculars
[INFO] [2020-12-03 12:04:12] ## remove_type: Article
[INFO] [2020-12-03 12:04:12] ++ Calling delete_all on 0 instances...
[INFO] [2020-12-03 12:04:12] [12:04:12.167] Removed 0 Articles
[INFO] [2020-12-03 12:04:12] ## remove_type: Medium
[INFO] [2020-12-03 12:04:12] ++ Calling delete_all on 0 instances...
[INFO] [2020-12-03 12:04:12] [12:04:12.171] Removed 0 Media
[INFO] [2020-12-03 12:04:12] ## remove_type: Trait
[INFO] [2020-12-03 12:04:12] ++ Calling delete_all on 2 instances...
[INFO] [2020-12-03 12:04:12] [12:04:12.175] Removed 2 Traits
[INFO] [2020-12-03 12:04:12] ## remove_type: MetaTrait
[INFO] [2020-12-03 12:04:12] ++ Calling delete_all on 1 instances...
[INFO] [2020-12-03 12:04:12] [12:04:12.178] Removed 1 Metatraits
[INFO] [2020-12-03 12:04:12] ## remove_type: OccurrenceMetadatum
[INFO] [2020-12-03 12:04:12] ++ Calling delete_all on 0 instances...
[INFO] [2020-12-03 12:04:12] [12:04:12.181] Removed 0 Occurrencemetadata
[INFO] [2020-12-03 12:04:12] ## remove_type: Assoc
[INFO] [2020-12-03 12:04:12] ++ Calling delete_all on 0 instances...
[INFO] [2020-12-03 12:04:12] [12:04:12.184] Removed 0 Assocs
[INFO] [2020-12-03 12:04:12] ## remove_type: MetaAssoc
[INFO] [2020-12-03 12:04:12] ++ Calling delete_all on 0 instances...
[INFO] [2020-12-03 12:04:12] [12:04:12.187] Removed 0 Metaassocs
[INFO] [2020-12-03 12:04:12] ## remove_type: Identifier
[INFO] [2020-12-03 12:04:12] ++ Calling delete_all on 0 instances...
[INFO] [2020-12-03 12:04:12] [12:04:12.190] Removed 0 Identifiers
[INFO] [2020-12-03 12:04:12] ## remove_type: Reference
[INFO] [2020-12-03 12:04:12] ++ Calling delete_all on 0 instances...
[INFO] [2020-12-03 12:04:12] [12:04:12.193] Removed 0 References
[INFO] [2020-12-03 12:04:12] ## remove_type: Node
[INFO] [2020-12-03 12:04:12] ++ Calling delete_all on 1 instances...
[INFO] [2020-12-03 12:04:12] [12:04:12.213] Removed 1 Nodes
[START] [2020-12-03 12:04:12] logged process: 58bbc42b01abb4c1b2698de049792ffb4b63b979

[START] [2020-12-03 12:04:12] Creating resource from OpenData
[START] [2020-12-03 12:04:12] logged process: 58bbc42b01abb4c1b2698de049792ffb4b63b979

[START] [2020-12-03 12:04:12] Parse meta.xml file and create formats with fields
[STOP] [2020-12-03 12:04:12] Parse meta.xml file and create formats with fields
[STOP] [2020-12-03 12:04:12] Creating resource from OpenData
[START] [2020-12-03 12:04:12] logged process: 58bbc42b01abb4c1b2698de049792ffb4b63b979

[START] [2020-12-03 12:04:12] create_harvest_instance
[STOP] [2020-12-03 12:04:14] create_harvest_instance
[START] [2020-12-03 12:04:14] fetch_files
[STOP] [2020-12-03 12:04:14] fetch_files
[START] [2020-12-03 12:04:14] validate_each_file
[STOP] [2020-12-03 12:04:14] validate_each_file
[START] [2020-12-03 12:04:14] convert_to_csv
[CMD] [2020-12-03 12:04:14] /usr/bin/sort /app/public/converted_csv/kazilas_et_al_ka_refs_24872.csv > /app/public/converted_csv/kazilas_et_al_ka_refs_24872.csv_sorted
[CMD] [2020-12-03 12:04:14] /usr/bin/sort /app/public/converted_csv/kazilas_et_al_ka_nodes_24873.csv > /app/public/converted_csv/kazilas_et_al_ka_nodes_24873.csv_sorted
[CMD] [2020-12-03 12:04:14] /usr/bin/sort /app/public/converted_csv/kazilas_et_al_ka_occurrences_24874.csv > /app/public/converted_csv/kazilas_et_al_ka_occurrences_24874.csv_sorted
[CMD] [2020-12-03 12:04:14] /usr/bin/sort /app/public/converted_csv/kazilas_et_al_ka_measurements_24875.csv > /app/public/converted_csv/kazilas_et_al_ka_measurements_24875.csv_sorted
[STOP] [2020-12-03 12:04:14] convert_to_csv
[START] [2020-12-03 12:04:14] calculate_delta
[CMD] [2020-12-03 12:04:14] echo "0a" > /app/public/diff/kazilas_et_al_ka_refs_24872.diff
[CMD] [2020-12-03 12:04:14] tail -n +1 /app/public/converted_csv/kazilas_et_al_ka_refs_24872.csv >> /app/public/diff/kazilas_et_al_ka_refs_24872.diff
[CMD] [2020-12-03 12:04:14] echo "." >> /app/public/diff/kazilas_et_al_ka_refs_24872.diff
[CMD] [2020-12-03 12:04:14] echo "0a" > /app/public/diff/kazilas_et_al_ka_nodes_24873.diff
[CMD] [2020-12-03 12:04:14] tail -n +1 /app/public/converted_csv/kazilas_et_al_ka_nodes_24873.csv >> /app/public/diff/kazilas_et_al_ka_nodes_24873.diff
[CMD] [2020-12-03 12:04:14] echo "." >> /app/public/diff/kazilas_et_al_ka_nodes_24873.diff
[CMD] [2020-12-03 12:04:14] echo "0a" > /app/public/diff/kazilas_et_al_ka_occurrences_24874.diff
[CMD] [2020-12-03 12:04:14] tail -n +1 /app/public/converted_csv/kazilas_et_al_ka_occurrences_24874.csv >> /app/public/diff/kazilas_et_al_ka_occurrences_24874.diff
[CMD] [2020-12-03 12:04:14] echo "." >> /app/public/diff/kazilas_et_al_ka_occurrences_24874.diff
[CMD] [2020-12-03 12:04:14] echo "0a" > /app/public/diff/kazilas_et_al_ka_measurements_24875.diff
[CMD] [2020-12-03 12:04:14] tail -n +1 /app/public/converted_csv/kazilas_et_al_ka_measurements_24875.csv >> /app/public/diff/kazilas_et_al_ka_measurements_24875.diff
[CMD] [2020-12-03 12:04:14] echo "." >> /app/public/diff/kazilas_et_al_ka_measurements_24875.diff
[STOP] [2020-12-03 12:04:14] calculate_delta
[START] [2020-12-03 12:04:14] parse_diff_and_store
[INFO] [2020-12-03 12:04:14] Loading refs diff file into memory (true lines)...
[INFO] [2020-12-03 12:04:14] Loading nodes diff file into memory (true lines)...
[INFO] [2020-12-03 12:04:14] Loading occurrences diff file into memory (true lines)...
[INFO] [2020-12-03 12:04:14] Loading measurements diff file into memory (true lines)...
[INFO] [2020-12-03 12:04:15] Storing 1 ScientificNames
[INFO] [2020-12-03 12:04:15] Processing group of 1 in 1 groups of 1000
[INFO] [2020-12-03 12:04:15] Average Time: 0.0
[INFO] [2020-12-03 12:04:15] Total Time: 1s
[INFO] [2020-12-03 12:04:15] Storing 1 Nodes
[INFO] [2020-12-03 12:04:15] Processing group of 1 in 1 groups of 1000
[INFO] [2020-12-03 12:04:15] Average Time: 0.0
[INFO] [2020-12-03 12:04:15] Total Time: 1s
[INFO] [2020-12-03 12:04:15] Storing 1 Occurrences
[INFO] [2020-12-03 12:04:15] Processing group of 1 in 1 groups of 1000
[INFO] [2020-12-03 12:04:15] Average Time: 0.0
[INFO] [2020-12-03 12:04:15] Total Time: 1s
[INFO] [2020-12-03 12:04:15] Storing 2 Traits
[INFO] [2020-12-03 12:04:15] Processing group of 2 in 1 groups of 1000
[INFO] [2020-12-03 12:04:15] Average Time: 0.0
[INFO] [2020-12-03 12:04:15] Total Time: 1s
[INFO] [2020-12-03 12:04:15] Storing 1 MetaTraits
[INFO] [2020-12-03 12:04:15] Processing group of 1 in 1 groups of 1000
[INFO] [2020-12-03 12:04:15] Average Time: 0.0
[INFO] [2020-12-03 12:04:15] Total Time: 1s
[STOP] [2020-12-03 12:04:15] parse_diff_and_store
[START] [2020-12-03 12:04:15] resolve_keys
[INFO] [2020-12-03 12:04:21] Occurrences to nodes (through scientific_names)...
[INFO] [2020-12-03 12:04:21] traits to occurrences...
[INFO] [2020-12-03 12:04:21] traits to nodes (through occurrences)...
[INFO] [2020-12-03 12:04:21] Traits to sex term...
[INFO] [2020-12-03 12:04:21] Traits to lifestage term...
[INFO] [2020-12-03 12:04:21] MetaTraits to traits...
[INFO] [2020-12-03 12:04:21] MetaTraits (simple, measurement row refers to parent) to traits...
[INFO] [2020-12-03 12:04:21] Assocs to occurrences...
[INFO] [2020-12-03 12:04:21] Assocs to nodes...
[INFO] [2020-12-03 12:04:21] Assoc to sex term...
[INFO] [2020-12-03 12:04:21] Assoc to lifestage term...
[INFO] [2020-12-03 12:04:21] MetaAssoc to assocs...
[STOP] [2020-12-03 12:04:21] resolve_keys
[START] [2020-12-03 12:04:21] hold_for_later_1
[STOP] [2020-12-03 12:04:21] hold_for_later_1
[START] [2020-12-03 12:04:21] hold_for_later_2
[STOP] [2020-12-03 12:04:21] hold_for_later_2
[START] [2020-12-03 12:04:21] resolve_missing_parents
[STOP] [2020-12-03 12:04:21] resolve_missing_parents
[START] [2020-12-03 12:04:21] rebuild_nodes
[START] [2020-12-03 12:04:21] Flattener#flatten
[START] [2020-12-03 12:04:21] Flattener#study_resource
[START] [2020-12-03 12:04:21] Flattener#build_ancestry
[STOP] [2020-12-03 12:04:21] Flattener#build_ancestry
[INFO] [2020-12-03 12:04:21] 1 ancestry keys
[START] [2020-12-03 12:04:21] build_node_ancestors
[INFO] [2020-12-03 12:04:21] old ancestors deleted.
[STOP] [2020-12-03 12:04:21] build_node_ancestors
[WARN] [2020-12-03 12:04:21] Flattener: nothing to flatten! (Completely flat resource?)
[STOP] [2020-12-03 12:04:21] Flattener#flatten
[STOP] [2020-12-03 12:04:21] rebuild_nodes
[START] [2020-12-03 12:04:21] resolve_missing_media_owners
[STOP] [2020-12-03 12:04:21] resolve_missing_media_owners
[START] [2020-12-03 12:04:21] sanitize_media_verbatims
[STOP] [2020-12-03 12:04:21] sanitize_media_verbatims
[START] [2020-12-03 12:04:21] queue_downloads
[STOP] [2020-12-03 12:04:21] queue_downloads
[START] [2020-12-03 12:04:21] parse_names
[WARN] [2020-12-03 12:04:21] I see 1 names which still need to be parsed.
[STOP] [2020-12-03 12:04:22] parse_names
[START] [2020-12-03 12:04:22] denormalize_canonical_names_to_nodes
[STOP] [2020-12-03 12:04:22] denormalize_canonical_names_to_nodes
[START] [2020-12-03 12:04:22] match_nodes
[START] [2020-12-03 12:04:22] map_all_nodes_to_pages
[STOP] [2020-12-03 12:04:22] map_all_nodes_to_pages
[INFO] [2020-12-03 12:04:22] ZERO unmatched nodes (of 1)! Nicely done.
[START] [2020-12-03 12:04:22] update_nodes
[STOP] [2020-12-03 12:04:22] update_nodes
[STOP] [2020-12-03 12:04:22] match_nodes
[START] [2020-12-03 12:04:22] reindex_search
[STOP] [2020-12-03 12:04:22] reindex_search
[START] [2020-12-03 12:04:22] normalize_units
[STOP] [2020-12-03 12:04:22] normalize_units
[START] [2020-12-03 12:04:22] calculate_statistics
[2020-12-03 12:04:22] ZERO NODE ANCESTORS. Is this actually a completely flat resource?
[STOP] [2020-12-03 12:04:22] calculate_statistics
[START] [2020-12-03 12:04:22] complete_harvest_instance
[START] [2020-12-03 12:04:22] overall_tsv_creation
[INFO] [2020-12-03 12:04:22] Processing group of 1 in 1 batches of 10000
[INFO] [2020-12-03 12:05:00] 1 Traits (unfiltered)...
[INFO] [2020-12-03 12:05:36] 1 Traits (filtered)...
[INFO] [2020-12-03 12:05:36] 0 Associations (filtered)...
[INFO] [2020-12-03 12:05:36] 2 metadata added.
[INFO] [2020-12-03 12:05:36] 0 metadata added.
[INFO] [2020-12-03 12:05:36] Average Time: 51.83
[INFO] [2020-12-03 12:05:36] Total Time: 1m15s
[STOP] [2020-12-03 12:05:36] overall_tsv_creation
[INFO] [2020-12-03 12:05:36] Done. Check your files:
[INFO] [2020-12-03 12:05:36] (1 lines) /app/public/data/kazilas_et_al_ka/publish_nodes.tsv
[INFO] [2020-12-03 12:05:36] (1 lines) /app/public/data/kazilas_et_al_ka/publish_scientific_names.tsv
[INFO] [2020-12-03 12:05:36] (2 lines) /app/public/data/kazilas_et_al_ka/publish_traits.tsv
[INFO] [2020-12-03 12:05:36] (3 lines) /app/public/data/kazilas_et_al_ka/publish_metadata.tsv
[STOP] [2020-12-03 12:05:37] complete_harvest_instance
[START] [2020-12-03 12:05:37] completed
[STOP] [2020-12-03 12:05:37] completed
[STOP] [2020-12-03 12:05:37] logged process, took 84.12
[INFO] [2021-04-19 15:36:37] ## HARVEST: type = re_download_opendata_-harvest
[INFO] [2021-04-19 15:52:47] ## remove_type: ScientificName
[INFO] [2021-04-19 15:52:47] ++ Calling delete_all on 1 instances...
[INFO] [2021-04-19 15:52:47] [15:52:47.273] Removed 1 Scientificnames
[INFO] [2021-04-19 15:52:47] ## remove_type: Vernacular
[INFO] [2021-04-19 15:52:47] ++ Calling delete_all on 0 instances...
[INFO] [2021-04-19 15:52:47] [15:52:47.275] Removed 0 Vernaculars
[INFO] [2021-04-19 15:52:47] ## remove_type: Article
[INFO] [2021-04-19 15:52:47] ++ Calling delete_all on 0 instances...
[INFO] [2021-04-19 15:52:47] [15:52:47.277] Removed 0 Articles
[INFO] [2021-04-19 15:52:47] ## remove_type: Medium
[INFO] [2021-04-19 15:52:47] ++ Calling delete_all on 0 instances...
[INFO] [2021-04-19 15:52:47] [15:52:47.279] Removed 0 Media
[INFO] [2021-04-19 15:52:47] ## remove_type: Trait
[INFO] [2021-04-19 15:52:47] ++ Calling delete_all on 2 instances...
[INFO] [2021-04-19 15:52:47] [15:52:47.281] Removed 2 Traits
[INFO] [2021-04-19 15:52:47] ## remove_type: MetaTrait
[INFO] [2021-04-19 15:52:47] ++ Calling delete_all on 1 instances...
[INFO] [2021-04-19 15:52:47] [15:52:47.283] Removed 1 Metatraits
[INFO] [2021-04-19 15:52:47] ## remove_type: OccurrenceMetadatum
[INFO] [2021-04-19 15:52:47] ++ Calling delete_all on 0 instances...
[INFO] [2021-04-19 15:52:47] [15:52:47.285] Removed 0 Occurrencemetadata
[INFO] [2021-04-19 15:52:47] ## remove_type: Assoc
[INFO] [2021-04-19 15:52:47] ++ Calling delete_all on 0 instances...
[INFO] [2021-04-19 15:52:47] [15:52:47.286] Removed 0 Assocs
[INFO] [2021-04-19 15:52:47] ## remove_type: MetaAssoc
[INFO] [2021-04-19 15:52:47] ++ Calling delete_all on 0 instances...
[INFO] [2021-04-19 15:52:47] [15:52:47.288] Removed 0 Metaassocs
[INFO] [2021-04-19 15:52:47] ## remove_type: Identifier
[INFO] [2021-04-19 15:52:47] ++ Calling delete_all on 0 instances...
[INFO] [2021-04-19 15:52:47] [15:52:47.289] Removed 0 Identifiers
[INFO] [2021-04-19 15:52:47] ## remove_type: Reference
[INFO] [2021-04-19 15:52:47] ++ Calling delete_all on 0 instances...
[INFO] [2021-04-19 15:52:47] [15:52:47.290] Removed 0 References
[INFO] [2021-04-19 15:52:47] Starting batch with ID 86116211...
[INFO] [2021-04-19 15:52:47] Starting batch with ID 86116211...
[INFO] [2021-04-19 15:52:47] Starting batch with ID 86116211...
[INFO] [2021-04-19 15:52:47] Starting batch with ID 86116211...
[INFO] [2021-04-19 15:52:47] Starting batch with ID 86116211...
[INFO] [2021-04-19 15:52:47] Starting batch with ID 86116211...
[INFO] [2021-04-19 15:52:47] Starting batch with ID 86116211...
[INFO] [2021-04-19 15:52:47] Starting batch with ID 86116211...
[INFO] [2021-04-19 15:52:47] Starting batch with ID 86116211...
[INFO] [2021-04-19 15:52:47] Starting batch with ID 86116211...
[INFO] [2021-04-19 15:52:47] Starting batch with ID 86116211...
[INFO] [2021-04-19 15:52:47] Starting batch with ID 86116211...
[INFO] [2021-04-19 15:52:47] Starting batch with ID 86116211...
[INFO] [2021-04-19 15:52:47] Starting batch with ID 86116211...
[INFO] [2021-04-19 15:52:47] Starting batch with ID 86116211...
[INFO] [2021-04-19 15:52:47] Starting batch with ID 86116211...
[INFO] [2021-04-19 15:52:47] Starting batch with ID 86116211...
[INFO] [2021-04-19 15:52:47] Starting batch with ID 86116211...
[INFO] [2021-04-19 15:52:47] Starting batch with ID 86116211...
[INFO] [2021-04-19 15:52:47] Starting batch with ID 86116211...
[INFO] [2021-04-19 15:52:47] Starting batch with ID 86116211...
[INFO] [2021-04-19 15:52:47] Starting batch with ID 86116211...
[INFO] [2021-04-19 15:52:47] Starting batch with ID 86116211...
[INFO] [2021-04-19 15:52:47] Starting batch with ID 86116211...
[INFO] [2021-04-19 15:52:47] Starting batch with ID 86116211...
[INFO] [2021-04-19 15:52:47] Starting batch with ID 86116211...
[INFO] [2021-04-19 15:52:47] Starting batch with ID 86116211...
[INFO] [2021-04-19 15:52:47] Starting batch with ID 86116211...
[INFO] [2021-04-19 15:52:47] Starting batch with ID 86116211...
[INFO] [2021-04-19 15:52:47] Starting batch with ID 86116211...
[INFO] [2021-04-19 15:52:47] Starting batch with ID 86116211...
[INFO] [2021-04-19 15:52:47] Starting batch with ID 86116211...
[INFO] [2021-04-19 15:52:47] Starting batch with ID 86116211...
[INFO] [2021-04-19 15:52:47] Starting batch with ID 86116211...
[INFO] [2021-04-19 15:52:47] Starting batch with ID 86116211...
[INFO] [2021-04-19 15:52:47] Starting batch with ID 86116211...
[INFO] [2021-04-19 15:52:47] Starting batch with ID 86116211...
[INFO] [2021-04-19 15:52:47] Starting batch with ID 86116211...
[INFO] [2021-04-19 15:52:47] Starting batch with ID 86116211...
[INFO] [2021-04-19 15:52:47] Starting batch with ID 86116211...
[INFO] [2021-04-19 15:52:47] Starting batch with ID 86116211...
[INFO] [2021-04-19 15:52:47] Starting batch with ID 86116211...
[INFO] [2021-04-19 15:52:47] Starting batch with ID 86116211...
[INFO] [2021-04-19 15:52:47] Starting batch with ID 86116211...
[INFO] [2021-04-19 15:52:47] Starting batch with ID 86116211...
[INFO] [2021-04-19 15:52:47] ## remove_type: Node
[INFO] [2021-04-19 15:52:47] ++ Calling delete_all on 1 instances...
[INFO] [2021-04-19 15:52:47] [15:52:47.592] Removed 1 Nodes
[START] [2021-04-19 15:52:47] logged process: 5ecc716a6a5541910d0c854f5a0c8d1651b82ad0 Improved MetaXml.ignore and added publisher to media (ignored)
[START] [2021-04-19 15:52:47] Creating resource from OpenData
[START] [2021-04-19 15:52:47] logged process: 5ecc716a6a5541910d0c854f5a0c8d1651b82ad0 Improved MetaXml.ignore and added publisher to media (ignored)
[START] [2021-04-19 15:52:47] Parse meta.xml file and create formats with fields
[STOP] [2021-04-19 15:52:48] Parse meta.xml file and create formats with fields
[STOP] [2021-04-19 15:52:48] Creating resource from OpenData
[START] [2021-04-19 15:52:48] logged process: 5ecc716a6a5541910d0c854f5a0c8d1651b82ad0 Improved MetaXml.ignore and added publisher to media (ignored)
[START] [2021-04-19 15:52:48] create_harvest_instance
[INFO] [2021-04-19 15:52:48] Created harvest instance #3781
[STOP] [2021-04-19 15:52:48] create_harvest_instance
[START] [2021-04-19 15:52:48] fetch_files
[STOP] [2021-04-19 15:52:48] fetch_files
[START] [2021-04-19 15:52:48] validate_each_file
[INFO] [2021-04-19 15:52:48] Looping over 4 formats...
[INFO] [2021-04-19 15:52:48] ...refs (/app/public/data/kazilas_et_al_ka/references.tsv)
[INFO] [2021-04-19 15:52:48] Valid: /app/public/converted_csv/kazilas_et_al_ka_refs_3781.csv (0 lines)
[INFO] [2021-04-19 15:52:48] ...nodes (/app/public/data/kazilas_et_al_ka/taxa.txt)
[INFO] [2021-04-19 15:52:48] Valid: /app/public/converted_csv/kazilas_et_al_ka_nodes_3781.csv (1 lines)
[INFO] [2021-04-19 15:52:48] ...occurrences (/app/public/data/kazilas_et_al_ka/occurrences.txt)
[INFO] [2021-04-19 15:52:48] Valid: /app/public/converted_csv/kazilas_et_al_ka_occurrences_3781.csv (1 lines)
[INFO] [2021-04-19 15:52:48] ...measurements (/app/public/data/kazilas_et_al_ka/measurementsorfacts.txt)
[INFO] [2021-04-19 15:52:48] Valid: /app/public/converted_csv/kazilas_et_al_ka_measurements_3781.csv (2 lines)
[STOP] [2021-04-19 15:52:48] validate_each_file
[START] [2021-04-19 15:52:48] convert_to_csv
[INFO] [2021-04-19 15:52:48] Looping over 4 formats...
[INFO] [2021-04-19 15:52:48] ...refs (/app/public/data/kazilas_et_al_ka/references.tsv)
[CMD] [2021-04-19 15:52:48] /usr/bin/sort /app/public/converted_csv/kazilas_et_al_ka_refs_3781.csv > /app/public/converted_csv/kazilas_et_al_ka_refs_3781.csv_sorted
[INFO] [2021-04-19 15:52:48] Converted: /app/public/converted_csv/kazilas_et_al_ka_refs_3781.csv (0 lines)
[INFO] [2021-04-19 15:52:48] ...nodes (/app/public/data/kazilas_et_al_ka/taxa.txt)
[CMD] [2021-04-19 15:52:48] /usr/bin/sort /app/public/converted_csv/kazilas_et_al_ka_nodes_3781.csv > /app/public/converted_csv/kazilas_et_al_ka_nodes_3781.csv_sorted
[INFO] [2021-04-19 15:52:48] Converted: /app/public/converted_csv/kazilas_et_al_ka_nodes_3781.csv (1 lines)
[INFO] [2021-04-19 15:52:48] ...occurrences (/app/public/data/kazilas_et_al_ka/occurrences.txt)
[CMD] [2021-04-19 15:52:48] /usr/bin/sort /app/public/converted_csv/kazilas_et_al_ka_occurrences_3781.csv > /app/public/converted_csv/kazilas_et_al_ka_occurrences_3781.csv_sorted
[INFO] [2021-04-19 15:52:48] Converted: /app/public/converted_csv/kazilas_et_al_ka_occurrences_3781.csv (1 lines)
[INFO] [2021-04-19 15:52:48] ...measurements (/app/public/data/kazilas_et_al_ka/measurementsorfacts.txt)
[CMD] [2021-04-19 15:52:48] /usr/bin/sort /app/public/converted_csv/kazilas_et_al_ka_measurements_3781.csv > /app/public/converted_csv/kazilas_et_al_ka_measurements_3781.csv_sorted
[INFO] [2021-04-19 15:52:48] Converted: /app/public/converted_csv/kazilas_et_al_ka_measurements_3781.csv (2 lines)
[STOP] [2021-04-19 15:52:48] convert_to_csv
[START] [2021-04-19 15:52:48] calculate_delta
[INFO] [2021-04-19 15:52:48] Looping over 4 formats...
[INFO] [2021-04-19 15:52:48] ...refs (/app/public/data/kazilas_et_al_ka/references.tsv)
[CMD] [2021-04-19 15:52:48] echo "0a" > /app/public/diff/kazilas_et_al_ka_refs_3781.diff
[CMD] [2021-04-19 15:52:48] tail -n +1 /app/public/converted_csv/kazilas_et_al_ka_refs_3781.csv >> /app/public/diff/kazilas_et_al_ka_refs_3781.diff
[CMD] [2021-04-19 15:52:48] echo "." >> /app/public/diff/kazilas_et_al_ka_refs_3781.diff
[INFO] [2021-04-19 15:52:48] Created diff: /app/public/diff/kazilas_et_al_ka_refs_3781.diff (2 lines)
[INFO] [2021-04-19 15:52:48] ...nodes (/app/public/data/kazilas_et_al_ka/taxa.txt)
[CMD] [2021-04-19 15:52:48] echo "0a" > /app/public/diff/kazilas_et_al_ka_nodes_3781.diff
[CMD] [2021-04-19 15:52:48] tail -n +1 /app/public/converted_csv/kazilas_et_al_ka_nodes_3781.csv >> /app/public/diff/kazilas_et_al_ka_nodes_3781.diff
[CMD] [2021-04-19 15:52:48] echo "." >> /app/public/diff/kazilas_et_al_ka_nodes_3781.diff
[INFO] [2021-04-19 15:52:48] Created diff: /app/public/diff/kazilas_et_al_ka_nodes_3781.diff (3 lines)
[INFO] [2021-04-19 15:52:48] ...occurrences (/app/public/data/kazilas_et_al_ka/occurrences.txt)
[CMD] [2021-04-19 15:52:48] echo "0a" > /app/public/diff/kazilas_et_al_ka_occurrences_3781.diff
[CMD] [2021-04-19 15:52:48] tail -n +1 /app/public/converted_csv/kazilas_et_al_ka_occurrences_3781.csv >> /app/public/diff/kazilas_et_al_ka_occurrences_3781.diff
[CMD] [2021-04-19 15:52:48] echo "." >> /app/public/diff/kazilas_et_al_ka_occurrences_3781.diff
[INFO] [2021-04-19 15:52:48] Created diff: /app/public/diff/kazilas_et_al_ka_occurrences_3781.diff (3 lines)
[INFO] [2021-04-19 15:52:48] ...measurements (/app/public/data/kazilas_et_al_ka/measurementsorfacts.txt)
[CMD] [2021-04-19 15:52:48] echo "0a" > /app/public/diff/kazilas_et_al_ka_measurements_3781.diff
[CMD] [2021-04-19 15:52:48] tail -n +1 /app/public/converted_csv/kazilas_et_al_ka_measurements_3781.csv >> /app/public/diff/kazilas_et_al_ka_measurements_3781.diff
[CMD] [2021-04-19 15:52:48] echo "." >> /app/public/diff/kazilas_et_al_ka_measurements_3781.diff
[INFO] [2021-04-19 15:52:48] Created diff: /app/public/diff/kazilas_et_al_ka_measurements_3781.diff (4 lines)
[STOP] [2021-04-19 15:52:48] calculate_delta
[START] [2021-04-19 15:52:48] parse_diff_and_store
[INFO] [2021-04-19 15:52:48] Handling diff: /app/public/diff/kazilas_et_al_ka_refs_3781.diff (2 lines)
[INFO] [2021-04-19 15:52:48] Loading refs diff file into memory (2 /app/public/diff/kazilas_et_al_ka_refs_3781.diff lines)...
[INFO] [2021-04-19 15:52:48] Handling diff: /app/public/diff/kazilas_et_al_ka_nodes_3781.diff (3 lines)
[INFO] [2021-04-19 15:52:48] Loading nodes diff file into memory (3 /app/public/diff/kazilas_et_al_ka_nodes_3781.diff lines)...
[INFO] [2021-04-19 15:52:48] Handling diff: /app/public/diff/kazilas_et_al_ka_occurrences_3781.diff (3 lines)
[INFO] [2021-04-19 15:52:48] Loading occurrences diff file into memory (3 /app/public/diff/kazilas_et_al_ka_occurrences_3781.diff lines)...
[INFO] [2021-04-19 15:52:48] Handling diff: /app/public/diff/kazilas_et_al_ka_measurements_3781.diff (4 lines)
[INFO] [2021-04-19 15:52:48] Loading measurements diff file into memory (4 /app/public/diff/kazilas_et_al_ka_measurements_3781.diff lines)...
[INFO] [2021-04-19 15:52:48] Storing 1 ScientificNames
[INFO] [2021-04-19 15:52:48] Processing group of 1 in 1 groups of 1000
[INFO] [2021-04-19 15:52:48] Average Time: 0.0
[INFO] [2021-04-19 15:52:48] Total Time: 1s
[INFO] [2021-04-19 15:52:48] Storing 1 Nodes
[INFO] [2021-04-19 15:52:48] Processing group of 1 in 1 groups of 1000
[INFO] [2021-04-19 15:52:48] Average Time: 0.0
[INFO] [2021-04-19 15:52:48] Total Time: 1s
[INFO] [2021-04-19 15:52:48] Storing 1 Occurrences
[INFO] [2021-04-19 15:52:48] Processing group of 1 in 1 groups of 1000
[INFO] [2021-04-19 15:52:48] Average Time: 0.0
[INFO] [2021-04-19 15:52:48] Total Time: 1s
[INFO] [2021-04-19 15:52:48] Storing 2 Traits
[INFO] [2021-04-19 15:52:48] Processing group of 2 in 1 groups of 1000
[INFO] [2021-04-19 15:52:48] Average Time: 0.0
[INFO] [2021-04-19 15:52:48] Total Time: 1s
[INFO] [2021-04-19 15:52:48] Storing 1 MetaTraits
[INFO] [2021-04-19 15:52:48] Processing group of 1 in 1 groups of 1000
[INFO] [2021-04-19 15:52:48] Average Time: 0.0
[INFO] [2021-04-19 15:52:48] Total Time: 1s
[STOP] [2021-04-19 15:52:48] parse_diff_and_store
[START] [2021-04-19 15:52:48] resolve_keys
[INFO] [2021-04-19 15:52:54] Occurrences to nodes (through scientific_names)...
[INFO] [2021-04-19 15:52:54] traits to occurrences...
[INFO] [2021-04-19 15:52:54] traits to nodes (through occurrences)...
[INFO] [2021-04-19 15:52:54] Traits to sex term...
[INFO] [2021-04-19 15:52:54] Traits to lifestage term...
[INFO] [2021-04-19 15:52:54] MetaTraits to traits...
[INFO] [2021-04-19 15:52:54] MetaTraits (simple, measurement row refers to parent) to traits...
[INFO] [2021-04-19 15:52:54] Assocs to occurrences...
[INFO] [2021-04-19 15:52:54] Assocs to nodes...
[INFO] [2021-04-19 15:52:54] Assoc to sex term...
[INFO] [2021-04-19 15:52:54] Assoc to lifestage term...
[INFO] [2021-04-19 15:52:54] MetaAssoc to assocs...
[STOP] [2021-04-19 15:52:54] resolve_keys
[START] [2021-04-19 15:52:54] hold_for_later_1
[STOP] [2021-04-19 15:52:54] hold_for_later_1
[START] [2021-04-19 15:52:54] hold_for_later_2
[STOP] [2021-04-19 15:52:54] hold_for_later_2
[START] [2021-04-19 15:52:54] resolve_missing_parents
[STOP] [2021-04-19 15:52:54] resolve_missing_parents
[START] [2021-04-19 15:52:54] rebuild_nodes
[START] [2021-04-19 15:52:54] Flattener#flatten
[START] [2021-04-19 15:52:54] Flattener#study_resource
[START] [2021-04-19 15:52:54] Flattener#build_ancestry
[STOP] [2021-04-19 15:52:54] Flattener#build_ancestry
[INFO] [2021-04-19 15:52:54] 1 ancestry keys
[START] [2021-04-19 15:52:54] build_node_ancestors
[INFO] [2021-04-19 15:52:54] old ancestors deleted.
[STOP] [2021-04-19 15:52:54] build_node_ancestors
[WARN] [2021-04-19 15:52:54] Flattener: nothing to flatten! (Completely flat resource?)
[STOP] [2021-04-19 15:52:54] Flattener#flatten
[STOP] [2021-04-19 15:52:54] rebuild_nodes
[START] [2021-04-19 15:52:54] resolve_missing_media_owners
[STOP] [2021-04-19 15:52:54] resolve_missing_media_owners
[START] [2021-04-19 15:52:54] sanitize_media_verbatims
[STOP] [2021-04-19 15:52:54] sanitize_media_verbatims
[START] [2021-04-19 15:52:54] queue_downloads
[STOP] [2021-04-19 15:52:54] queue_downloads
[START] [2021-04-19 15:52:54] parse_names
[WARN] [2021-04-19 15:52:54] I see 1 names which still need to be parsed.
[STOP] [2021-04-19 15:52:55] parse_names
[START] [2021-04-19 15:52:55] denormalize_canonical_names_to_nodes
[STOP] [2021-04-19 15:52:55] denormalize_canonical_names_to_nodes
[START] [2021-04-19 15:52:55] match_nodes
[START] [2021-04-19 15:52:55] map_all_nodes_to_pages
[STOP] [2021-04-19 15:52:55] map_all_nodes_to_pages
[INFO] [2021-04-19 15:52:55] ZERO unmatched nodes (of 1)! Nicely done.
[START] [2021-04-19 15:52:55] update_nodes
[STOP] [2021-04-19 15:52:55] update_nodes
[STOP] [2021-04-19 15:52:55] match_nodes
[START] [2021-04-19 15:52:55] reindex_search
[STOP] [2021-04-19 15:52:55] reindex_search
[START] [2021-04-19 15:52:55] normalize_units
[STOP] [2021-04-19 15:52:55] normalize_units
[START] [2021-04-19 15:52:55] calculate_statistics
[2021-04-19 15:52:55] ZERO NODE ANCESTORS. Is this actually a completely flat resource?
[STOP] [2021-04-19 15:52:55] calculate_statistics
[START] [2021-04-19 15:52:55] complete_harvest_instance
[START] [2021-04-19 15:52:55] overall_tsv_creation
[INFO] [2021-04-19 15:52:55] Processing group of 1 in 1 batches of 10000
[INFO] [2021-04-19 15:53:31] 1 Traits (unfiltered)...
[INFO] [2021-04-19 15:54:03] 1 Traits (filtered)...
[INFO] [2021-04-19 15:54:03] 0 Associations (filtered)...
[INFO] [2021-04-19 15:54:03] 1 metadata added.
[INFO] [2021-04-19 15:54:03] 0 metadata added.
[INFO] [2021-04-19 15:54:29] Average Time: 70.21
[INFO] [2021-04-19 15:54:29] Total Time: 1m35s
[STOP] [2021-04-19 15:54:29] overall_tsv_creation
[INFO] [2021-04-19 15:54:29] Done. Check your files:
[INFO] [2021-04-19 15:54:29] (1 lines) /app/public/data/kazilas_et_al_ka/publish_nodes.tsv
[INFO] [2021-04-19 15:54:29] (1 lines) /app/public/data/kazilas_et_al_ka/publish_scientific_names.tsv
[INFO] [2021-04-19 15:54:29] (2 lines) /app/public/data/kazilas_et_al_ka/publish_traits.tsv
[INFO] [2021-04-19 15:54:29] (2 lines) /app/public/data/kazilas_et_al_ka/publish_metadata.tsv
[STOP] [2021-04-19 15:54:29] complete_harvest_instance
[START] [2021-04-19 15:54:29] completed
[STOP] [2021-04-19 15:54:29] completed
[STOP] [2021-04-19 15:54:29] logged process, took 101.83

Latest Process

19 Apr 15:52 EXITED currently processing 0