Harvest for Poinar 2010 Created 30 Jul 12:09

Stage: completed
Fetched: 30 Jul 12:09
Validated: 30 Jul 12:09
Deltas Created 30 Jul 12:09
Units Normalized: 30 Jul 12:09
Ancestry Built: 30 Jul 12:09
Nodes Matched: 30 Jul 12:09
Names Parsed: 30 Jul 12:09
New Models Stored: 30 Jul 12:09
Indexed: 30 Jul 12:09
Completed: 30 Jul 12:11
Time to Harvest: less than a minute
Harvesting Log

(509 lines)
# Logfile created on 2020-07-30 11:56:09 -0400 by logger.rb/v1.4.2
[START] [2020-07-30 11:56:09] logged process
[START] [2020-07-30 11:56:09] Creating resource from OpenData
[START] [2020-07-30 11:56:10] logged process
[START] [2020-07-30 11:56:10] Parse meta.xml file and create formats with fields
[STOP] [2020-07-30 11:56:10] Parse meta.xml file and create formats with fields
[STOP] [2020-07-30 11:56:10] Creating resource from OpenData
[INFO] [2020-07-30 11:56:37] ## HARVEST: type = -harvest
[START] [2020-07-30 11:56:40] logged process
[START] [2020-07-30 11:56:40] create_harvest_instance
[STOP] [2020-07-30 11:56:41] create_harvest_instance
[START] [2020-07-30 11:56:41] fetch_files
[STOP] [2020-07-30 11:56:41] fetch_files
[START] [2020-07-30 11:56:41] validate_each_file
[STOP] [2020-07-30 11:56:41] validate_each_file
[ERR] [2020-07-30 11:56:41] Exceptions::ColumnUnmatched
[ERR] [2020-07-30 11:56:41] TOO MANY COLUMNS: nodes: lifeStage
[ERR] [2020-07-30 11:56:41] ../models/resource_harvester.rb:138:in `block in validate_each_file'
[ERR] [2020-07-30 11:56:41] ../models/resource_harvester.rb:665:in `block in each_format'
[ERR] [2020-07-30 11:56:41] ../models/resource_harvester.rb:650:in `each_format'
[ERR] [2020-07-30 11:56:41] ../models/resource_harvester.rb:132:in `validate_each_file'
[ERR] [2020-07-30 11:56:41] ../models/resource_harvester.rb:86:in `block (3 levels) in start'
[ERR] [2020-07-30 11:56:41] ../models/logged_process.rb:19:in `run_step'
[ERR] [2020-07-30 11:56:41] ../models/resource_harvester.rb:86:in `block (2 levels) in start'
[ERR] [2020-07-30 11:56:41] ../models/resource_harvester.rb:75:in `each_key'
[ERR] [2020-07-30 11:56:41] ../models/resource_harvester.rb:75:in `block in start'
[ERR] [2020-07-30 11:56:41] ../models/resource.rb:151:in `lock'
[ERR] [2020-07-30 11:56:41] ../models/resource_harvester.rb:72:in `start'
[ERR] [2020-07-30 11:56:41] ../models/resource.rb:232:in `harvest'
[ERR] [2020-07-30 11:56:41] bin/rails:4:in `require'
[ERR] [2020-07-30 11:56:41] bin/rails:4:in `<main>'
[STOP] [2020-07-30 11:56:41] logged process, took 1.36
[INFO] [2020-07-30 11:59:12] ## HARVEST: type = re_download_opendata_-harvest
[INFO] [2020-07-30 11:59:13] ## remove_type: ScientificName
[INFO] [2020-07-30 11:59:13] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 11:59:13] [11:59:13.117] Removed 0 Scientificnames
[INFO] [2020-07-30 11:59:13] ## remove_type: Vernacular
[INFO] [2020-07-30 11:59:13] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 11:59:13] [11:59:13.120] Removed 0 Vernaculars
[INFO] [2020-07-30 11:59:13] ## remove_type: Article
[INFO] [2020-07-30 11:59:13] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 11:59:13] [11:59:13.123] Removed 0 Articles
[INFO] [2020-07-30 11:59:13] ## remove_type: Medium
[INFO] [2020-07-30 11:59:13] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 11:59:13] [11:59:13.127] Removed 0 Media
[INFO] [2020-07-30 11:59:13] ## remove_type: Trait
[INFO] [2020-07-30 11:59:13] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 11:59:13] [11:59:13.130] Removed 0 Traits
[INFO] [2020-07-30 11:59:13] ## remove_type: MetaTrait
[INFO] [2020-07-30 11:59:13] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 11:59:13] [11:59:13.136] Removed 0 Metatraits
[INFO] [2020-07-30 11:59:13] ## remove_type: OccurrenceMetadatum
[INFO] [2020-07-30 11:59:13] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 11:59:13] [11:59:13.145] Removed 0 Occurrencemetadata
[INFO] [2020-07-30 11:59:13] ## remove_type: Assoc
[INFO] [2020-07-30 11:59:13] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 11:59:13] [11:59:13.148] Removed 0 Assocs
[INFO] [2020-07-30 11:59:13] ## remove_type: MetaAssoc
[INFO] [2020-07-30 11:59:13] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 11:59:13] [11:59:13.162] Removed 0 Metaassocs
[INFO] [2020-07-30 11:59:13] ## remove_type: Identifier
[INFO] [2020-07-30 11:59:13] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 11:59:13] [11:59:13.178] Removed 0 Identifiers
[INFO] [2020-07-30 11:59:13] ## remove_type: Reference
[INFO] [2020-07-30 11:59:13] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 11:59:13] [11:59:13.181] Removed 0 References
[INFO] [2020-07-30 11:59:13] ## remove_type: Node
[INFO] [2020-07-30 11:59:13] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 11:59:13] [11:59:13.201] Removed 0 Nodes
[START] [2020-07-30 11:59:13] logged process
[START] [2020-07-30 11:59:13] Creating resource from OpenData
[START] [2020-07-30 11:59:13] logged process
[START] [2020-07-30 11:59:13] Parse meta.xml file and create formats with fields
[STOP] [2020-07-30 11:59:13] Parse meta.xml file and create formats with fields
[STOP] [2020-07-30 11:59:13] Creating resource from OpenData
[START] [2020-07-30 11:59:13] logged process
[START] [2020-07-30 11:59:13] create_harvest_instance
[STOP] [2020-07-30 11:59:15] create_harvest_instance
[START] [2020-07-30 11:59:15] fetch_files
[STOP] [2020-07-30 11:59:15] fetch_files
[START] [2020-07-30 11:59:15] validate_each_file
[STOP] [2020-07-30 11:59:15] validate_each_file
[ERR] [2020-07-30 11:59:15] Exceptions::ColumnUnmatched
[ERR] [2020-07-30 11:59:15] TOO MANY COLUMNS: nodes: lifeStage
[ERR] [2020-07-30 11:59:15] ../models/resource_harvester.rb:138:in `block in validate_each_file'
[ERR] [2020-07-30 11:59:15] ../models/resource_harvester.rb:665:in `block in each_format'
[ERR] [2020-07-30 11:59:15] ../models/resource_harvester.rb:650:in `each_format'
[ERR] [2020-07-30 11:59:15] ../models/resource_harvester.rb:132:in `validate_each_file'
[ERR] [2020-07-30 11:59:15] ../models/resource_harvester.rb:86:in `block (3 levels) in start'
[ERR] [2020-07-30 11:59:15] ../models/logged_process.rb:19:in `run_step'
[ERR] [2020-07-30 11:59:15] ../models/resource_harvester.rb:86:in `block (2 levels) in start'
[ERR] [2020-07-30 11:59:15] ../models/resource_harvester.rb:75:in `each_key'
[ERR] [2020-07-30 11:59:15] ../models/resource_harvester.rb:75:in `block in start'
[ERR] [2020-07-30 11:59:15] ../models/resource.rb:151:in `lock'
[ERR] [2020-07-30 11:59:15] ../models/resource_harvester.rb:72:in `start'
[ERR] [2020-07-30 11:59:15] ../models/resource.rb:232:in `harvest'
[ERR] [2020-07-30 11:59:15] ../models/resource.rb:208:in `re_download_opendata_and_harvest'
[ERR] [2020-07-30 11:59:15] bin/rails:4:in `require'
[ERR] [2020-07-30 11:59:15] bin/rails:4:in `<main>'
[STOP] [2020-07-30 11:59:15] logged process, took 1.35
[START] [2020-07-30 11:59:46] logged process
[START] [2020-07-30 11:59:46] overall_tsv_creation
[INFO] [2020-07-30 11:59:46] Processing group of 0 in 0 batches of 10000
[INFO] [2020-07-30 11:59:46] Average Time: NaN
[INFO] [2020-07-30 11:59:46] Total Time: 1s
[STOP] [2020-07-30 11:59:46] overall_tsv_creation
[INFO] [2020-07-30 11:59:46] Done. Check your files:
[INFO] [2020-07-30 11:59:54] ## HARVEST: type = re_download_opendata_-harvest
[INFO] [2020-07-30 11:59:56] ## remove_type: ScientificName
[INFO] [2020-07-30 11:59:56] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 11:59:56] [11:59:56.899] Removed 0 Scientificnames
[INFO] [2020-07-30 11:59:56] ## remove_type: Vernacular
[INFO] [2020-07-30 11:59:56] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 11:59:56] [11:59:56.903] Removed 0 Vernaculars
[INFO] [2020-07-30 11:59:56] ## remove_type: Article
[INFO] [2020-07-30 11:59:56] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 11:59:56] [11:59:56.905] Removed 0 Articles
[INFO] [2020-07-30 11:59:56] ## remove_type: Medium
[INFO] [2020-07-30 11:59:56] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 11:59:56] [11:59:56.909] Removed 0 Media
[INFO] [2020-07-30 11:59:56] ## remove_type: Trait
[INFO] [2020-07-30 11:59:56] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 11:59:56] [11:59:56.912] Removed 0 Traits
[INFO] [2020-07-30 11:59:56] ## remove_type: MetaTrait
[INFO] [2020-07-30 11:59:56] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 11:59:56] [11:59:56.915] Removed 0 Metatraits
[INFO] [2020-07-30 11:59:56] ## remove_type: OccurrenceMetadatum
[INFO] [2020-07-30 11:59:56] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 11:59:56] [11:59:56.918] Removed 0 Occurrencemetadata
[INFO] [2020-07-30 11:59:56] ## remove_type: Assoc
[INFO] [2020-07-30 11:59:56] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 11:59:56] [11:59:56.921] Removed 0 Assocs
[INFO] [2020-07-30 11:59:56] ## remove_type: MetaAssoc
[INFO] [2020-07-30 11:59:56] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 11:59:56] [11:59:56.924] Removed 0 Metaassocs
[INFO] [2020-07-30 11:59:56] ## remove_type: Identifier
[INFO] [2020-07-30 11:59:56] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 11:59:56] [11:59:56.926] Removed 0 Identifiers
[INFO] [2020-07-30 11:59:56] ## remove_type: Reference
[INFO] [2020-07-30 11:59:56] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 11:59:56] [11:59:56.929] Removed 0 References
[INFO] [2020-07-30 11:59:56] ## remove_type: Node
[INFO] [2020-07-30 11:59:56] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 11:59:56] [11:59:56.958] Removed 0 Nodes
[START] [2020-07-30 11:59:57] logged process
[START] [2020-07-30 11:59:57] Creating resource from OpenData
[START] [2020-07-30 11:59:57] logged process
[START] [2020-07-30 11:59:57] Parse meta.xml file and create formats with fields
[STOP] [2020-07-30 11:59:57] Parse meta.xml file and create formats with fields
[STOP] [2020-07-30 11:59:57] Creating resource from OpenData
[START] [2020-07-30 11:59:57] logged process
[START] [2020-07-30 11:59:57] create_harvest_instance
[STOP] [2020-07-30 11:59:58] create_harvest_instance
[START] [2020-07-30 11:59:58] fetch_files
[STOP] [2020-07-30 11:59:58] fetch_files
[START] [2020-07-30 11:59:58] validate_each_file
[STOP] [2020-07-30 11:59:58] validate_each_file
[ERR] [2020-07-30 11:59:58] Exceptions::ColumnUnmatched
[ERR] [2020-07-30 11:59:58] TOO MANY COLUMNS: nodes: lifeStage
[ERR] [2020-07-30 11:59:58] ../models/resource_harvester.rb:138:in `block in validate_each_file'
[ERR] [2020-07-30 11:59:58] ../models/resource_harvester.rb:665:in `block in each_format'
[ERR] [2020-07-30 11:59:58] ../models/resource_harvester.rb:650:in `each_format'
[ERR] [2020-07-30 11:59:58] ../models/resource_harvester.rb:132:in `validate_each_file'
[ERR] [2020-07-30 11:59:58] ../models/resource_harvester.rb:86:in `block (3 levels) in start'
[ERR] [2020-07-30 11:59:58] ../models/logged_process.rb:19:in `run_step'
[ERR] [2020-07-30 11:59:58] ../models/resource_harvester.rb:86:in `block (2 levels) in start'
[ERR] [2020-07-30 11:59:58] ../models/resource_harvester.rb:75:in `each_key'
[ERR] [2020-07-30 11:59:58] ../models/resource_harvester.rb:75:in `block in start'
[ERR] [2020-07-30 11:59:58] ../models/resource.rb:151:in `lock'
[ERR] [2020-07-30 11:59:58] ../models/resource_harvester.rb:72:in `start'
[ERR] [2020-07-30 11:59:58] ../models/resource.rb:232:in `harvest'
[ERR] [2020-07-30 11:59:58] ../models/resource.rb:208:in `re_download_opendata_and_harvest'
[ERR] [2020-07-30 11:59:58] bin/rails:4:in `require'
[ERR] [2020-07-30 11:59:58] bin/rails:4:in `<main>'
[STOP] [2020-07-30 11:59:58] logged process, took 1.32
[START] [2020-07-30 12:00:15] logged process
[START] [2020-07-30 12:00:15] overall_tsv_creation
[INFO] [2020-07-30 12:00:15] Processing group of 0 in 0 batches of 10000
[INFO] [2020-07-30 12:00:15] Average Time: NaN
[INFO] [2020-07-30 12:00:15] Total Time: 1s
[STOP] [2020-07-30 12:00:15] overall_tsv_creation
[INFO] [2020-07-30 12:00:15] Done. Check your files:
[INFO] [2020-07-30 12:02:25] ## HARVEST: type = re_download_opendata_-harvest
[INFO] [2020-07-30 12:02:25] ## remove_type: ScientificName
[INFO] [2020-07-30 12:02:25] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 12:02:25] [12:02:25.625] Removed 0 Scientificnames
[INFO] [2020-07-30 12:02:25] ## remove_type: Vernacular
[INFO] [2020-07-30 12:02:25] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 12:02:25] [12:02:25.628] Removed 0 Vernaculars
[INFO] [2020-07-30 12:02:25] ## remove_type: Article
[INFO] [2020-07-30 12:02:25] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 12:02:25] [12:02:25.631] Removed 0 Articles
[INFO] [2020-07-30 12:02:25] ## remove_type: Medium
[INFO] [2020-07-30 12:02:25] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 12:02:25] [12:02:25.635] Removed 0 Media
[INFO] [2020-07-30 12:02:25] ## remove_type: Trait
[INFO] [2020-07-30 12:02:25] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 12:02:25] [12:02:25.638] Removed 0 Traits
[INFO] [2020-07-30 12:02:25] ## remove_type: MetaTrait
[INFO] [2020-07-30 12:02:25] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 12:02:25] [12:02:25.641] Removed 0 Metatraits
[INFO] [2020-07-30 12:02:25] ## remove_type: OccurrenceMetadatum
[INFO] [2020-07-30 12:02:25] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 12:02:25] [12:02:25.643] Removed 0 Occurrencemetadata
[INFO] [2020-07-30 12:02:25] ## remove_type: Assoc
[INFO] [2020-07-30 12:02:25] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 12:02:25] [12:02:25.647] Removed 0 Assocs
[INFO] [2020-07-30 12:02:25] ## remove_type: MetaAssoc
[INFO] [2020-07-30 12:02:25] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 12:02:25] [12:02:25.650] Removed 0 Metaassocs
[INFO] [2020-07-30 12:02:25] ## remove_type: Identifier
[INFO] [2020-07-30 12:02:25] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 12:02:25] [12:02:25.652] Removed 0 Identifiers
[INFO] [2020-07-30 12:02:25] ## remove_type: Reference
[INFO] [2020-07-30 12:02:25] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 12:02:25] [12:02:25.655] Removed 0 References
[INFO] [2020-07-30 12:02:25] ## remove_type: Node
[INFO] [2020-07-30 12:02:25] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 12:02:25] [12:02:25.725] Removed 0 Nodes
[START] [2020-07-30 12:02:26] logged process
[START] [2020-07-30 12:02:26] Creating resource from OpenData
[START] [2020-07-30 12:02:26] logged process
[START] [2020-07-30 12:02:26] Parse meta.xml file and create formats with fields
[STOP] [2020-07-30 12:02:26] Parse meta.xml file and create formats with fields
[STOP] [2020-07-30 12:02:26] Creating resource from OpenData
[START] [2020-07-30 12:02:26] logged process
[START] [2020-07-30 12:02:26] create_harvest_instance
[STOP] [2020-07-30 12:02:27] create_harvest_instance
[START] [2020-07-30 12:02:27] fetch_files
[STOP] [2020-07-30 12:02:27] fetch_files
[START] [2020-07-30 12:02:27] validate_each_file
[STOP] [2020-07-30 12:02:28] validate_each_file
[ERR] [2020-07-30 12:02:28] Exceptions::ColumnUnmatched
[ERR] [2020-07-30 12:02:28] TOO MANY COLUMNS: measurements: referenceID
[ERR] [2020-07-30 12:02:28] ../models/resource_harvester.rb:138:in `block in validate_each_file'
[ERR] [2020-07-30 12:02:28] ../models/resource_harvester.rb:665:in `block in each_format'
[ERR] [2020-07-30 12:02:28] ../models/resource_harvester.rb:650:in `each_format'
[ERR] [2020-07-30 12:02:28] ../models/resource_harvester.rb:132:in `validate_each_file'
[ERR] [2020-07-30 12:02:28] ../models/resource_harvester.rb:86:in `block (3 levels) in start'
[ERR] [2020-07-30 12:02:28] ../models/logged_process.rb:19:in `run_step'
[ERR] [2020-07-30 12:02:28] ../models/resource_harvester.rb:86:in `block (2 levels) in start'
[ERR] [2020-07-30 12:02:28] ../models/resource_harvester.rb:75:in `each_key'
[ERR] [2020-07-30 12:02:28] ../models/resource_harvester.rb:75:in `block in start'
[ERR] [2020-07-30 12:02:28] ../models/resource.rb:151:in `lock'
[ERR] [2020-07-30 12:02:28] ../models/resource_harvester.rb:72:in `start'
[ERR] [2020-07-30 12:02:28] ../models/resource.rb:232:in `harvest'
[ERR] [2020-07-30 12:02:28] ../models/resource.rb:208:in `re_download_opendata_and_harvest'
[ERR] [2020-07-30 12:02:28] bin/rails:4:in `require'
[ERR] [2020-07-30 12:02:28] bin/rails:4:in `<main>'
[STOP] [2020-07-30 12:02:28] logged process, took 1.39
[START] [2020-07-30 12:02:59] logged process
[START] [2020-07-30 12:02:59] overall_tsv_creation
[INFO] [2020-07-30 12:02:59] Processing group of 0 in 0 batches of 10000
[INFO] [2020-07-30 12:02:59] Average Time: NaN
[INFO] [2020-07-30 12:02:59] Total Time: 1s
[STOP] [2020-07-30 12:02:59] overall_tsv_creation
[INFO] [2020-07-30 12:02:59] Done. Check your files:
[START] [2020-07-30 12:03:01] logged process
[START] [2020-07-30 12:03:01] Parse meta.xml file and create formats with fields
[STOP] [2020-07-30 12:03:01] Parse meta.xml file and create formats with fields
[INFO] [2020-07-30 12:03:05] ## HARVEST: type = resume_-harvest
[START] [2020-07-30 12:03:09] logged process
[ERR] [2020-07-30 12:03:09][hdls] *****
[ERR] [2020-07-30 12:03:09][hdls] ***** HARVEST ATTEMPT FAILED: This resource is locked; assuming it is already running. Remove lock if not.
[ERR] [2020-07-30 12:03:09][hdls] *****
[INFO] [2020-07-30 12:04:33] ## HARVEST: type = re_download_opendata_-harvest
[INFO] [2020-07-30 12:04:34] ## remove_type: ScientificName
[INFO] [2020-07-30 12:04:34] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 12:04:34] [12:04:34.622] Removed 0 Scientificnames
[INFO] [2020-07-30 12:04:34] ## remove_type: Vernacular
[INFO] [2020-07-30 12:04:34] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 12:04:34] [12:04:34.625] Removed 0 Vernaculars
[INFO] [2020-07-30 12:04:34] ## remove_type: Article
[INFO] [2020-07-30 12:04:34] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 12:04:34] [12:04:34.628] Removed 0 Articles
[INFO] [2020-07-30 12:04:34] ## remove_type: Medium
[INFO] [2020-07-30 12:04:34] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 12:04:34] [12:04:34.632] Removed 0 Media
[INFO] [2020-07-30 12:04:34] ## remove_type: Trait
[INFO] [2020-07-30 12:04:34] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 12:04:34] [12:04:34.635] Removed 0 Traits
[INFO] [2020-07-30 12:04:34] ## remove_type: MetaTrait
[INFO] [2020-07-30 12:04:34] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 12:04:34] [12:04:34.638] Removed 0 Metatraits
[INFO] [2020-07-30 12:04:34] ## remove_type: OccurrenceMetadatum
[INFO] [2020-07-30 12:04:34] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 12:04:34] [12:04:34.641] Removed 0 Occurrencemetadata
[INFO] [2020-07-30 12:04:34] ## remove_type: Assoc
[INFO] [2020-07-30 12:04:34] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 12:04:34] [12:04:34.644] Removed 0 Assocs
[INFO] [2020-07-30 12:04:34] ## remove_type: MetaAssoc
[INFO] [2020-07-30 12:04:34] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 12:04:34] [12:04:34.647] Removed 0 Metaassocs
[INFO] [2020-07-30 12:04:34] ## remove_type: Identifier
[INFO] [2020-07-30 12:04:34] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 12:04:34] [12:04:34.649] Removed 0 Identifiers
[INFO] [2020-07-30 12:04:34] ## remove_type: Reference
[INFO] [2020-07-30 12:04:34] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 12:04:34] [12:04:34.652] Removed 0 References
[INFO] [2020-07-30 12:04:34] ## remove_type: Node
[INFO] [2020-07-30 12:04:34] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 12:04:34] [12:04:34.671] Removed 0 Nodes
[START] [2020-07-30 12:04:35] logged process
[START] [2020-07-30 12:04:35] Creating resource from OpenData
[START] [2020-07-30 12:04:35] logged process
[START] [2020-07-30 12:04:35] Parse meta.xml file and create formats with fields
[STOP] [2020-07-30 12:04:35] Parse meta.xml file and create formats with fields
[STOP] [2020-07-30 12:04:35] Creating resource from OpenData
[START] [2020-07-30 12:04:35] logged process
[START] [2020-07-30 12:04:35] create_harvest_instance
[STOP] [2020-07-30 12:04:36] create_harvest_instance
[START] [2020-07-30 12:04:36] fetch_files
[STOP] [2020-07-30 12:04:36] fetch_files
[START] [2020-07-30 12:04:36] validate_each_file
[STOP] [2020-07-30 12:04:36] validate_each_file
[ERR] [2020-07-30 12:04:36] Exceptions::ColumnUnmatched
[ERR] [2020-07-30 12:04:36] TOO MANY COLUMNS: measurements: referenceID
[ERR] [2020-07-30 12:04:36] ../models/resource_harvester.rb:138:in `block in validate_each_file'
[ERR] [2020-07-30 12:04:36] ../models/resource_harvester.rb:665:in `block in each_format'
[ERR] [2020-07-30 12:04:36] ../models/resource_harvester.rb:650:in `each_format'
[ERR] [2020-07-30 12:04:36] ../models/resource_harvester.rb:132:in `validate_each_file'
[ERR] [2020-07-30 12:04:36] ../models/resource_harvester.rb:86:in `block (3 levels) in start'
[ERR] [2020-07-30 12:04:36] ../models/logged_process.rb:19:in `run_step'
[ERR] [2020-07-30 12:04:36] ../models/resource_harvester.rb:86:in `block (2 levels) in start'
[ERR] [2020-07-30 12:04:36] ../models/resource_harvester.rb:75:in `each_key'
[ERR] [2020-07-30 12:04:36] ../models/resource_harvester.rb:75:in `block in start'
[ERR] [2020-07-30 12:04:36] ../models/resource.rb:151:in `lock'
[ERR] [2020-07-30 12:04:36] ../models/resource_harvester.rb:72:in `start'
[ERR] [2020-07-30 12:04:36] ../models/resource.rb:232:in `harvest'
[ERR] [2020-07-30 12:04:36] ../models/resource.rb:208:in `re_download_opendata_and_harvest'
[ERR] [2020-07-30 12:04:36] bin/rails:4:in `require'
[ERR] [2020-07-30 12:04:36] bin/rails:4:in `<main>'
[STOP] [2020-07-30 12:04:36] logged process, took 1.38
[INFO] [2020-07-30 12:09:15] ## HARVEST: type = re_download_opendata_-harvest
[INFO] [2020-07-30 12:09:18] ## remove_type: ScientificName
[INFO] [2020-07-30 12:09:18] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 12:09:18] [12:09:18.403] Removed 0 Scientificnames
[INFO] [2020-07-30 12:09:18] ## remove_type: Vernacular
[INFO] [2020-07-30 12:09:18] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 12:09:18] [12:09:18.405] Removed 0 Vernaculars
[INFO] [2020-07-30 12:09:18] ## remove_type: Article
[INFO] [2020-07-30 12:09:18] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 12:09:18] [12:09:18.408] Removed 0 Articles
[INFO] [2020-07-30 12:09:18] ## remove_type: Medium
[INFO] [2020-07-30 12:09:18] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 12:09:18] [12:09:18.411] Removed 0 Media
[INFO] [2020-07-30 12:09:18] ## remove_type: Trait
[INFO] [2020-07-30 12:09:18] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 12:09:18] [12:09:18.415] Removed 0 Traits
[INFO] [2020-07-30 12:09:18] ## remove_type: MetaTrait
[INFO] [2020-07-30 12:09:18] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 12:09:18] [12:09:18.417] Removed 0 Metatraits
[INFO] [2020-07-30 12:09:18] ## remove_type: OccurrenceMetadatum
[INFO] [2020-07-30 12:09:18] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 12:09:18] [12:09:18.420] Removed 0 Occurrencemetadata
[INFO] [2020-07-30 12:09:18] ## remove_type: Assoc
[INFO] [2020-07-30 12:09:18] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 12:09:18] [12:09:18.423] Removed 0 Assocs
[INFO] [2020-07-30 12:09:18] ## remove_type: MetaAssoc
[INFO] [2020-07-30 12:09:18] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 12:09:18] [12:09:18.426] Removed 0 Metaassocs
[INFO] [2020-07-30 12:09:18] ## remove_type: Identifier
[INFO] [2020-07-30 12:09:18] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 12:09:18] [12:09:18.428] Removed 0 Identifiers
[INFO] [2020-07-30 12:09:18] ## remove_type: Reference
[INFO] [2020-07-30 12:09:18] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 12:09:18] [12:09:18.431] Removed 0 References
[INFO] [2020-07-30 12:09:18] ## remove_type: Node
[INFO] [2020-07-30 12:09:18] ++ Calling delete_all on 0 instances...
[INFO] [2020-07-30 12:09:18] [12:09:18.462] Removed 0 Nodes
[START] [2020-07-30 12:09:18] logged process
[START] [2020-07-30 12:09:18] Creating resource from OpenData
[START] [2020-07-30 12:09:19] logged process
[START] [2020-07-30 12:09:19] Parse meta.xml file and create formats with fields
[STOP] [2020-07-30 12:09:19] Parse meta.xml file and create formats with fields
[STOP] [2020-07-30 12:09:19] Creating resource from OpenData
[START] [2020-07-30 12:09:19] logged process
[START] [2020-07-30 12:09:19] create_harvest_instance
[STOP] [2020-07-30 12:09:20] create_harvest_instance
[START] [2020-07-30 12:09:20] fetch_files
[STOP] [2020-07-30 12:09:20] fetch_files
[START] [2020-07-30 12:09:20] validate_each_file
[STOP] [2020-07-30 12:09:20] validate_each_file
[START] [2020-07-30 12:09:20] convert_to_csv
[CMD] [2020-07-30 12:09:20] /usr/bin/sort /app/public/converted_csv/poinar_poinar_20_refs_22192.csv > /app/public/converted_csv/poinar_poinar_20_refs_22192.csv_sorted
[CMD] [2020-07-30 12:09:20] /usr/bin/sort /app/public/converted_csv/poinar_poinar_20_nodes_22193.csv > /app/public/converted_csv/poinar_poinar_20_nodes_22193.csv_sorted
[CMD] [2020-07-30 12:09:20] /usr/bin/sort /app/public/converted_csv/poinar_poinar_20_occurrences_22194.csv > /app/public/converted_csv/poinar_poinar_20_occurrences_22194.csv_sorted
[CMD] [2020-07-30 12:09:20] /usr/bin/sort /app/public/converted_csv/poinar_poinar_20_measurements_22195.csv > /app/public/converted_csv/poinar_poinar_20_measurements_22195.csv_sorted
[STOP] [2020-07-30 12:09:20] convert_to_csv
[START] [2020-07-30 12:09:20] calculate_delta
[CMD] [2020-07-30 12:09:20] echo "0a" > /app/public/diff/poinar_poinar_20_refs_22192.diff
[CMD] [2020-07-30 12:09:20] tail -n +1 /app/public/converted_csv/poinar_poinar_20_refs_22192.csv >> /app/public/diff/poinar_poinar_20_refs_22192.diff
[CMD] [2020-07-30 12:09:20] echo "." >> /app/public/diff/poinar_poinar_20_refs_22192.diff
[CMD] [2020-07-30 12:09:20] echo "0a" > /app/public/diff/poinar_poinar_20_nodes_22193.diff
[CMD] [2020-07-30 12:09:20] tail -n +1 /app/public/converted_csv/poinar_poinar_20_nodes_22193.csv >> /app/public/diff/poinar_poinar_20_nodes_22193.diff
[CMD] [2020-07-30 12:09:20] echo "." >> /app/public/diff/poinar_poinar_20_nodes_22193.diff
[CMD] [2020-07-30 12:09:20] echo "0a" > /app/public/diff/poinar_poinar_20_occurrences_22194.diff
[CMD] [2020-07-30 12:09:20] tail -n +1 /app/public/converted_csv/poinar_poinar_20_occurrences_22194.csv >> /app/public/diff/poinar_poinar_20_occurrences_22194.diff
[CMD] [2020-07-30 12:09:20] echo "." >> /app/public/diff/poinar_poinar_20_occurrences_22194.diff
[CMD] [2020-07-30 12:09:20] echo "0a" > /app/public/diff/poinar_poinar_20_measurements_22195.diff
[CMD] [2020-07-30 12:09:20] tail -n +1 /app/public/converted_csv/poinar_poinar_20_measurements_22195.csv >> /app/public/diff/poinar_poinar_20_measurements_22195.diff
[CMD] [2020-07-30 12:09:20] echo "." >> /app/public/diff/poinar_poinar_20_measurements_22195.diff
[STOP] [2020-07-30 12:09:20] calculate_delta
[START] [2020-07-30 12:09:20] parse_diff_and_store
[INFO] [2020-07-30 12:09:20] Loading refs diff file into memory (true lines)...
[INFO] [2020-07-30 12:09:20] Loading nodes diff file into memory (true lines)...
[INFO] [2020-07-30 12:09:20] Loading occurrences diff file into memory (true lines)...
[INFO] [2020-07-30 12:09:20] Loading measurements diff file into memory (true lines)...
[INFO] [2020-07-30 12:09:20] Storing 2 ScientificNames
[INFO] [2020-07-30 12:09:20] Processing group of 2 in 1 groups of 1000
[INFO] [2020-07-30 12:09:20] Average Time: 0.0
[INFO] [2020-07-30 12:09:20] Total Time: 1s
[INFO] [2020-07-30 12:09:20] Storing 2 Nodes
[INFO] [2020-07-30 12:09:20] Processing group of 2 in 1 groups of 1000
[INFO] [2020-07-30 12:09:21] Average Time: 0.0
[INFO] [2020-07-30 12:09:21] Total Time: 1s
[INFO] [2020-07-30 12:09:21] Storing 2 Occurrences
[INFO] [2020-07-30 12:09:21] Processing group of 2 in 1 groups of 1000
[INFO] [2020-07-30 12:09:21] Average Time: 0.0
[INFO] [2020-07-30 12:09:21] Total Time: 1s
[INFO] [2020-07-30 12:09:21] Storing 1 OccurrenceMetadata
[INFO] [2020-07-30 12:09:21] Processing group of 1 in 1 groups of 1000
[INFO] [2020-07-30 12:09:21] Average Time: 0.01
[INFO] [2020-07-30 12:09:21] Total Time: 1s
[INFO] [2020-07-30 12:09:21] Storing 4 Traits
[INFO] [2020-07-30 12:09:21] Processing group of 4 in 1 groups of 1000
[INFO] [2020-07-30 12:09:21] Average Time: 0.0
[INFO] [2020-07-30 12:09:21] Total Time: 1s
[INFO] [2020-07-30 12:09:21] Storing 4 MetaTraits
[INFO] [2020-07-30 12:09:21] Processing group of 4 in 1 groups of 1000
[INFO] [2020-07-30 12:09:21] Average Time: 0.0
[INFO] [2020-07-30 12:09:21] Total Time: 1s
[STOP] [2020-07-30 12:09:21] parse_diff_and_store
[START] [2020-07-30 12:09:21] resolve_keys
[INFO] [2020-07-30 12:09:28] Occurrences to nodes (through scientific_names)...
[INFO] [2020-07-30 12:09:28] traits to occurrences...
[INFO] [2020-07-30 12:09:28] traits to nodes (through occurrences)...
[INFO] [2020-07-30 12:09:28] Traits to sex term...
[INFO] [2020-07-30 12:09:28] Traits to lifestage term...
[INFO] [2020-07-30 12:09:28] MetaTraits to traits...
[INFO] [2020-07-30 12:09:28] MetaTraits (simple, measurement row refers to parent) to traits...
[INFO] [2020-07-30 12:09:28] Assocs to occurrences...
[INFO] [2020-07-30 12:09:28] Assocs to nodes...
[INFO] [2020-07-30 12:09:28] Assoc to sex term...
[INFO] [2020-07-30 12:09:28] Assoc to lifestage term...
[STOP] [2020-07-30 12:09:28] resolve_keys
[START] [2020-07-30 12:09:28] hold_for_later_1
[STOP] [2020-07-30 12:09:28] hold_for_later_1
[START] [2020-07-30 12:09:28] hold_for_later_2
[STOP] [2020-07-30 12:09:28] hold_for_later_2
[START] [2020-07-30 12:09:28] resolve_missing_parents
[STOP] [2020-07-30 12:09:28] resolve_missing_parents
[START] [2020-07-30 12:09:28] rebuild_nodes
[START] [2020-07-30 12:09:28] Flattener#flatten
[START] [2020-07-30 12:09:28] Flattener#study_resource
[START] [2020-07-30 12:09:28] Flattener#build_ancestry
[STOP] [2020-07-30 12:09:28] Flattener#build_ancestry
[INFO] [2020-07-30 12:09:28] 2 ancestry keys
[START] [2020-07-30 12:09:28] build_node_ancestors
[INFO] [2020-07-30 12:09:28] old ancestors deleted.
[STOP] [2020-07-30 12:09:28] build_node_ancestors
[WARN] [2020-07-30 12:09:28] Flattener: nothing to flatten! (Completely flat resource?)
[STOP] [2020-07-30 12:09:28] Flattener#flatten
[STOP] [2020-07-30 12:09:28] rebuild_nodes
[START] [2020-07-30 12:09:28] resolve_missing_media_owners
[STOP] [2020-07-30 12:09:28] resolve_missing_media_owners
[START] [2020-07-30 12:09:28] sanitize_media_verbatims
[STOP] [2020-07-30 12:09:28] sanitize_media_verbatims
[START] [2020-07-30 12:09:28] queue_downloads
[STOP] [2020-07-30 12:09:28] queue_downloads
[START] [2020-07-30 12:09:28] parse_names
[WARN] [2020-07-30 12:09:28] I see 2 names which still need to be parsed.
[STOP] [2020-07-30 12:09:30] parse_names
[START] [2020-07-30 12:09:30] denormalize_canonical_names_to_nodes
[STOP] [2020-07-30 12:09:30] denormalize_canonical_names_to_nodes
[START] [2020-07-30 12:09:30] match_nodes
[START] [2020-07-30 12:09:30] map_all_nodes_to_pages
[STOP] [2020-07-30 12:09:30] map_all_nodes_to_pages
[INFO] [2020-07-30 12:09:30] ZERO unmatched nodes (of 2)! Nicely done.
[START] [2020-07-30 12:09:30] update_nodes
[STOP] [2020-07-30 12:09:30] update_nodes
[STOP] [2020-07-30 12:09:30] match_nodes
[START] [2020-07-30 12:09:30] reindex_search
[STOP] [2020-07-30 12:09:30] reindex_search
[START] [2020-07-30 12:09:30] normalize_units
[STOP] [2020-07-30 12:09:30] normalize_units
[START] [2020-07-30 12:09:30] calculate_statistics
[2020-07-30 12:09:30] ZERO NODE ANCESTORS. Is this actually a completely flat resource?
[STOP] [2020-07-30 12:09:30] calculate_statistics
[START] [2020-07-30 12:09:30] complete_harvest_instance
[START] [2020-07-30 12:09:30] overall_tsv_creation
[INFO] [2020-07-30 12:09:30] Processing group of 2 in 1 batches of 10000
[INFO] [2020-07-30 12:11:08] 2 Traits (unfiltered)...
[INFO] [2020-07-30 12:11:45] 2 Traits (filtered)...
[INFO] [2020-07-30 12:11:45] 0 Associations (filtered)...
[INFO] [2020-07-30 12:11:45] 7 metadata added.
[INFO] [2020-07-30 12:11:45] 0 metadata added.
[INFO] [2020-07-30 12:11:45] Average Time: 58.45
[INFO] [2020-07-30 12:11:45] Total Time: 2m16s
[STOP] [2020-07-30 12:11:45] overall_tsv_creation
[INFO] [2020-07-30 12:11:45] Done. Check your files:
[INFO] [2020-07-30 12:11:45] (2 lines) /app/public/data/poinar_poinar_20/publish_nodes.tsv
[INFO] [2020-07-30 12:11:45] (2 lines) /app/public/data/poinar_poinar_20/publish_scientific_names.tsv
[INFO] [2020-07-30 12:11:45] (3 lines) /app/public/data/poinar_poinar_20/publish_traits.tsv
[INFO] [2020-07-30 12:11:45] (4 lines) /app/public/data/poinar_poinar_20/publish_metadata.tsv
[STOP] [2020-07-30 12:11:45] complete_harvest_instance
[START] [2020-07-30 12:11:45] completed
[STOP] [2020-07-30 12:11:45] completed
[STOP] [2020-07-30 12:11:45] logged process, took 146.23
Latest Process

30 Jul 12:09 EXITED currently processing 0