21 Apr 2021 02:02:06,471 INFO : Starting to run task 'org.labkey.study.pipeline.StudyReloadSourceTask' at location 'webserver'
21 Apr 2021 02:02:06,471 INFO : Starting REDCap export
21 Apr 2021 02:02:08,684 INFO : Creating study archive
21 Apr 2021 02:02:08,694 INFO : Writing dataset metadata
21 Apr 2021 02:02:08,769 INFO : Creating column lookups
21 Apr 2021 02:02:09,527 WARN : Unable to locate subject id field: first_name for dataset: demographics row ignored.
21 Apr 2021 02:02:09,527 WARN : Unable to locate subject id field: first_name for dataset: demographics row ignored.
21 Apr 2021 02:02:09,527 WARN : Unable to locate subject id field: first_name for dataset: demographics row ignored.
21 Apr 2021 02:02:09,527 WARN : Unable to locate subject id field: first_name for dataset: demographics row ignored.
21 Apr 2021 02:02:09,527 WARN : Unable to locate subject id field: first_name for dataset: demographics row ignored.
21 Apr 2021 02:02:09,527 WARN : Unable to locate subject id field: first_name for dataset: demographics row ignored.
21 Apr 2021 02:02:09,527 WARN : Unable to locate subject id field: first_name for dataset: demographics row ignored.
21 Apr 2021 02:02:09,527 WARN : Unable to locate subject id field: first_name for dataset: demographics row ignored.
21 Apr 2021 02:02:09,527 WARN : Unable to locate subject id field: first_name for dataset: demographics row ignored.
21 Apr 2021 02:02:09,527 WARN : Unable to locate subject id field: first_name for dataset: demographics row ignored.
21 Apr 2021 02:02:09,527 WARN : Unable to locate subject id field: first_name for dataset: demographics row ignored.
21 Apr 2021 02:02:09,527 WARN : Unable to locate subject id field: first_name for dataset: demographics row ignored.
21 Apr 2021 02:02:09,527 WARN : Unable to locate subject id field: first_name for dataset: demographics row ignored.
21 Apr 2021 02:02:09,528 WARN : Unable to locate subject id field: first_name for dataset: demographics row ignored.
21 Apr 2021 02:02:09,528 WARN : Unable to locate subject id field: first_name for dataset: demographics row ignored.
21 Apr 2021 02:02:09,528 WARN : Unable to locate subject id field: first_name for dataset: demographics row ignored.
21 Apr 2021 02:02:09,528 WARN : Unable to locate subject id field: first_name for dataset: demographics row ignored.
21 Apr 2021 02:02:09,528 WARN : Unable to locate subject id field: first_name for dataset: demographics row ignored.
21 Apr 2021 02:02:09,528 WARN : Unable to locate subject id field: first_name for dataset: demographics row ignored.
21 Apr 2021 02:02:09,528 WARN : Unable to locate subject id field: first_name for dataset: emergency_contact_info row ignored.
21 Apr 2021 02:02:09,528 WARN : Unable to locate subject id field: first_name for dataset: emergency_contact_info row ignored.
21 Apr 2021 02:02:09,528 WARN : Unable to locate subject id field: first_name for dataset: emergency_contact_info row ignored.
21 Apr 2021 02:02:09,528 WARN : Unable to locate subject id field: first_name for dataset: emergency_contact_info row ignored.
21 Apr 2021 02:02:09,528 WARN : Unable to locate subject id field: first_name for dataset: emergency_contact_info row ignored.
21 Apr 2021 02:02:09,528 WARN : Unable to locate subject id field: first_name for dataset: emergency_contact_info row ignored.
21 Apr 2021 02:02:09,528 WARN : Unable to locate subject id field: first_name for dataset: emergency_contact_info row ignored.
21 Apr 2021 02:02:09,528 WARN : Unable to locate subject id field: first_name for dataset: emergency_contact_info row ignored.
21 Apr 2021 02:02:09,528 WARN : Unable to locate subject id field: first_name for dataset: emergency_contact_info row ignored.
21 Apr 2021 02:02:09,528 WARN : Unable to locate subject id field: first_name for dataset: emergency_contact_info row ignored.
21 Apr 2021 02:02:09,528 WARN : Unable to locate subject id field: first_name for dataset: emergency_contact_info row ignored.
21 Apr 2021 02:02:09,528 WARN : Unable to locate subject id field: first_name for dataset: emergency_contact_info row ignored.
21 Apr 2021 02:02:09,528 WARN : Unable to locate subject id field: first_name for dataset: emergency_contact_info row ignored.
21 Apr 2021 02:02:09,528 WARN : Unable to locate subject id field: first_name for dataset: emergency_contact_info row ignored.
21 Apr 2021 02:02:09,528 WARN : Unable to locate subject id field: first_name for dataset: emergency_contact_info row ignored.
21 Apr 2021 02:02:09,528 WARN : Unable to locate subject id field: first_name for dataset: emergency_contact_info row ignored.
21 Apr 2021 02:02:09,529 WARN : Unable to locate subject id field: first_name for dataset: emergency_contact_info row ignored.
21 Apr 2021 02:02:09,529 WARN : Unable to locate subject id field: first_name for dataset: emergency_contact_info row ignored.
21 Apr 2021 02:02:09,529 WARN : Unable to locate subject id field: first_name for dataset: emergency_contact_info row ignored.
21 Apr 2021 02:02:09,529 WARN : Unable to locate subject id field: first_name for dataset: baseline_lab_data row ignored.
21 Apr 2021 02:02:09,529 WARN : Unable to locate subject id field: first_name for dataset: baseline_lab_data row ignored.
21 Apr 2021 02:02:09,529 WARN : Unable to locate subject id field: first_name for dataset: baseline_lab_data row ignored.
21 Apr 2021 02:02:09,529 WARN : Unable to locate subject id field: first_name for dataset: baseline_lab_data row ignored.
21 Apr 2021 02:02:09,529 WARN : Unable to locate subject id field: first_name for dataset: baseline_lab_data row ignored.
21 Apr 2021 02:02:09,529 WARN : Unable to locate subject id field: first_name for dataset: baseline_lab_data row ignored.
21 Apr 2021 02:02:09,529 WARN : Unable to locate subject id field: first_name for dataset: baseline_lab_data row ignored.
21 Apr 2021 02:02:09,529 WARN : Unable to locate subject id field: first_name for dataset: baseline_lab_data row ignored.
21 Apr 2021 02:02:09,529 WARN : Unable to locate subject id field: first_name for dataset: baseline_lab_data row ignored.
21 Apr 2021 02:02:09,529 WARN : Unable to locate subject id field: first_name for dataset: baseline_lab_data row ignored.
21 Apr 2021 02:02:09,529 WARN : Unable to locate subject id field: first_name for dataset: baseline_lab_data row ignored.
21 Apr 2021 02:02:09,529 WARN : Unable to locate subject id field: first_name for dataset: baseline_lab_data row ignored.
21 Apr 2021 02:02:09,529 WARN : Unable to locate subject id field: first_name for dataset: baseline_lab_data row ignored.
21 Apr 2021 02:02:09,529 WARN : Unable to locate subject id field: first_name for dataset: baseline_lab_data row ignored.
21 Apr 2021 02:02:09,529 WARN : Unable to locate subject id field: first_name for dataset: baseline_lab_data row ignored.
21 Apr 2021 02:02:09,529 WARN : Unable to locate subject id field: first_name for dataset: baseline_lab_data row ignored.
21 Apr 2021 02:02:09,529 WARN : Unable to locate subject id field: first_name for dataset: baseline_lab_data row ignored.
21 Apr 2021 02:02:09,529 WARN : Unable to locate subject id field: first_name for dataset: baseline_lab_data row ignored.
21 Apr 2021 02:02:09,529 WARN : Unable to locate subject id field: first_name for dataset: baseline_lab_data row ignored.
21 Apr 2021 02:02:09,529 WARN : Unable to locate subject id field: first_name for dataset: visit_blood_workup row ignored.
21 Apr 2021 02:02:09,529 WARN : Unable to locate subject id field: first_name for dataset: visit_blood_workup row ignored.
21 Apr 2021 02:02:09,530 WARN : Unable to locate subject id field: first_name for dataset: visit_blood_workup row ignored.
21 Apr 2021 02:02:09,530 WARN : Unable to locate subject id field: first_name for dataset: visit_blood_workup row ignored.
21 Apr 2021 02:02:09,530 WARN : Unable to locate subject id field: first_name for dataset: visit_blood_workup row ignored.
21 Apr 2021 02:02:09,530 WARN : Unable to locate subject id field: first_name for dataset: visit_blood_workup row ignored.
21 Apr 2021 02:02:09,530 WARN : Unable to locate subject id field: first_name for dataset: visit_blood_workup row ignored.
21 Apr 2021 02:02:09,530 WARN : Unable to locate subject id field: first_name for dataset: visit_blood_workup row ignored.
21 Apr 2021 02:02:09,530 WARN : Unable to locate subject id field: first_name for dataset: visit_blood_workup row ignored.
21 Apr 2021 02:02:09,530 WARN : Unable to locate subject id field: first_name for dataset: visit_blood_workup row ignored.
21 Apr 2021 02:02:09,530 WARN : Unable to locate subject id field: first_name for dataset: visit_blood_workup row ignored.
21 Apr 2021 02:02:09,530 WARN : Unable to locate subject id field: first_name for dataset: visit_blood_workup row ignored.
21 Apr 2021 02:02:09,530 WARN : Unable to locate subject id field: first_name for dataset: visit_blood_workup row ignored.
21 Apr 2021 02:02:09,530 WARN : Unable to locate subject id field: first_name for dataset: visit_blood_workup row ignored.
21 Apr 2021 02:02:09,530 WARN : Unable to locate subject id field: first_name for dataset: visit_blood_workup row ignored.
21 Apr 2021 02:02:09,530 WARN : Unable to locate subject id field: first_name for dataset: visit_blood_workup row ignored.
21 Apr 2021 02:02:09,530 WARN : Unable to locate subject id field: first_name for dataset: visit_blood_workup row ignored.
21 Apr 2021 02:02:09,530 WARN : Unable to locate subject id field: first_name for dataset: visit_blood_workup row ignored.
21 Apr 2021 02:02:09,530 WARN : Unable to locate subject id field: first_name for dataset: completion_data row ignored.
21 Apr 2021 02:02:09,530 WARN : Unable to locate subject id field: first_name for dataset: completion_data row ignored.
21 Apr 2021 02:02:09,530 WARN : Unable to locate subject id field: first_name for dataset: completion_data row ignored.
21 Apr 2021 02:02:09,530 WARN : Unable to locate subject id field: first_name for dataset: completion_data row ignored.
21 Apr 2021 02:02:09,530 WARN : Unable to locate subject id field: first_name for dataset: completion_data row ignored.
21 Apr 2021 02:02:09,530 WARN : Unable to locate subject id field: first_name for dataset: completion_data row ignored.
21 Apr 2021 02:02:09,530 WARN : Unable to locate subject id field: first_name for dataset: completion_data row ignored.
21 Apr 2021 02:02:09,530 WARN : Unable to locate subject id field: first_name for dataset: completion_data row ignored.
21 Apr 2021 02:02:09,530 WARN : Unable to locate subject id field: first_name for dataset: completion_data row ignored.
21 Apr 2021 02:02:09,531 WARN : Unable to locate subject id field: first_name for dataset: completion_data row ignored.
21 Apr 2021 02:02:09,531 WARN : Unable to locate subject id field: first_name for dataset: completion_data row ignored.
21 Apr 2021 02:02:09,531 WARN : Unable to locate subject id field: first_name for dataset: completion_data row ignored.
21 Apr 2021 02:02:09,531 WARN : Unable to locate subject id field: first_name for dataset: completion_data row ignored.
21 Apr 2021 02:02:09,531 WARN : Unable to locate subject id field: first_name for dataset: completion_data row ignored.
21 Apr 2021 02:02:09,531 WARN : Unable to locate subject id field: first_name for dataset: completion_data row ignored.
21 Apr 2021 02:02:09,531 WARN : Unable to locate subject id field: first_name for dataset: completion_data row ignored.
21 Apr 2021 02:02:09,531 WARN : Unable to locate subject id field: first_name for dataset: completion_data row ignored.
21 Apr 2021 02:02:09,531 WARN : Unable to locate subject id field: first_name for dataset: completion_data row ignored.
21 Apr 2021 02:02:09,531 WARN : Unable to locate subject id field: first_name for dataset: completion_data row ignored.
21 Apr 2021 02:02:09,531 WARN : Unable to locate subject id field: first_name for dataset: completion_project_questionnaire row ignored.
21 Apr 2021 02:02:09,531 WARN : Unable to locate subject id field: first_name for dataset: completion_project_questionnaire row ignored.
21 Apr 2021 02:02:09,531 WARN : Unable to locate subject id field: first_name for dataset: completion_project_questionnaire row ignored.
21 Apr 2021 02:02:09,531 WARN : Unable to locate subject id field: first_name for dataset: completion_project_questionnaire row ignored.
21 Apr 2021 02:02:09,531 WARN : Unable to locate subject id field: first_name for dataset: completion_project_questionnaire row ignored.
21 Apr 2021 02:02:09,531 WARN : Unable to locate subject id field: first_name for dataset: completion_project_questionnaire row ignored.
21 Apr 2021 02:02:09,531 WARN : Unable to locate subject id field: first_name for dataset: completion_project_questionnaire row ignored.
21 Apr 2021 02:02:09,531 WARN : Unable to locate subject id field: first_name for dataset: completion_project_questionnaire row ignored.
21 Apr 2021 02:02:09,531 WARN : Unable to locate subject id field: first_name for dataset: completion_project_questionnaire row ignored.
21 Apr 2021 02:02:09,531 WARN : Unable to locate subject id field: first_name for dataset: completion_project_questionnaire row ignored.
21 Apr 2021 02:02:09,531 WARN : Unable to locate subject id field: first_name for dataset: completion_project_questionnaire row ignored.
21 Apr 2021 02:02:09,531 WARN : Unable to locate subject id field: first_name for dataset: completion_project_questionnaire row ignored.
21 Apr 2021 02:02:09,531 WARN : Unable to locate subject id field: first_name for dataset: completion_project_questionnaire row ignored.
21 Apr 2021 02:02:09,531 WARN : Unable to locate subject id field: first_name for dataset: completion_project_questionnaire row ignored.
21 Apr 2021 02:02:09,531 WARN : Unable to locate subject id field: first_name for dataset: completion_project_questionnaire row ignored.
21 Apr 2021 02:02:09,531 WARN : Unable to locate subject id field: first_name for dataset: completion_project_questionnaire row ignored.
21 Apr 2021 02:02:09,531 WARN : Unable to locate subject id field: first_name for dataset: completion_project_questionnaire row ignored.
21 Apr 2021 02:02:09,531 WARN : Unable to locate subject id field: first_name for dataset: completion_project_questionnaire row ignored.
21 Apr 2021 02:02:09,532 WARN : Unable to locate subject id field: first_name for dataset: completion_project_questionnaire row ignored.
21 Apr 2021 02:02:09,532 INFO : Finished creating study archive
21 Apr 2021 02:02:09,533 INFO : Successfully completed task 'org.labkey.study.pipeline.StudyReloadSourceTask'
21 Apr 2021 02:02:09,636 INFO : Starting to run task 'org.labkey.study.importer.StudyImportInitialTask' at location 'webserver'
21 Apr 2021 02:02:09,638 INFO : Reloading study from study.xml
21 Apr 2021 02:02:09,647 INFO : Loading top-level study properties (label, start/end date, description, etc.)
21 Apr 2021 02:02:10,017 INFO : Done importing top-level study properties (label, start/end date, description, etc.)
21 Apr 2021 02:02:10,060 INFO : Loading datasets manifest from datasets_manifest.xml
21 Apr 2021 02:02:10,062 INFO : Loading dataset schema from datasets_metadata.xml
21 Apr 2021 02:02:10,919 INFO : Successfully completed task 'org.labkey.study.importer.StudyImportInitialTask'
21 Apr 2021 02:02:10,956 INFO : Starting to run task 'org.labkey.study.pipeline.StudyImportDatasetTask' at location 'webserver'
21 Apr 2021 02:02:10,957 INFO : Start batch RedCap Integration.dataset
21 Apr 2021 02:02:11,006 INFO : demographics: Starting import from dataset001.tsv
21 Apr 2021 02:02:11,406 DEBUG: <next>
21 Apr 2021 02:02:11,407 DEBUG: <clear and set parameters on org.labkey.api.data.ParameterMapStatement@21260746>
21 Apr 2021 02:02:11,407 DEBUG: </clear and set parameters on org.labkey.api.data.ParameterMapStatement@21260746>
21 Apr 2021 02:02:11,407 DEBUG: </next>
21 Apr 2021 02:02:11,407 DEBUG: <next>
21 Apr 2021 02:02:11,407 DEBUG: <clear and set parameters on org.labkey.api.data.ParameterMapStatement@21260746>
21 Apr 2021 02:02:11,408 DEBUG: </clear and set parameters on org.labkey.api.data.ParameterMapStatement@21260746>
21 Apr 2021 02:02:11,408 DEBUG: </next>
21 Apr 2021 02:02:11,408 DEBUG: <next>
21 Apr 2021 02:02:11,408 DEBUG: <clear and set parameters on org.labkey.api.data.ParameterMapStatement@21260746>
21 Apr 2021 02:02:11,408 DEBUG: </clear and set parameters on org.labkey.api.data.ParameterMapStatement@21260746>
21 Apr 2021 02:02:11,408 DEBUG: </next>
21 Apr 2021 02:02:11,408 DEBUG: <next>
21 Apr 2021 02:02:11,408 DEBUG: <clear and set parameters on org.labkey.api.data.ParameterMapStatement@21260746>
21 Apr 2021 02:02:11,408 DEBUG: </clear and set parameters on org.labkey.api.data.ParameterMapStatement@21260746>
21 Apr 2021 02:02:11,408 DEBUG: </next>
21 Apr 2021 02:02:11,408 DEBUG: <next>
21 Apr 2021 02:02:11,409 DEBUG: <clear and set parameters on org.labkey.api.data.ParameterMapStatement@21260746>
21 Apr 2021 02:02:11,409 DEBUG: </clear and set parameters on org.labkey.api.data.ParameterMapStatement@21260746>
21 Apr 2021 02:02:11,409 DEBUG: </next>
21 Apr 2021 02:02:11,409 DEBUG: <next>
21 Apr 2021 02:02:11,409 DEBUG: <swap() - old: org.labkey.api.data.ParameterMapStatement@21260746>
21 Apr 2021 02:02:11,409 DEBUG: </swap() - new: org.labkey.api.data.ParameterMapStatement@1406d8e3>
21 Apr 2021 02:02:11,409 DEBUG: <close() on _queue>
21 Apr 2021 02:02:11,409 DEBUG: <close() on _queue>
21 Apr 2021 02:02:11,409 DEBUG: <executeBatch() on org.labkey.api.data.ParameterMapStatement@21260746>
21 Apr 2021 02:02:11,409 DEBUG: </close() on _queue>
21 Apr 2021 02:02:11,409 DEBUG: <join() on _asyncThread>
21 Apr 2021 02:02:11,419 DEBUG: </executeBatch() on org.labkey.api.data.ParameterMapStatement@21260746>
21 Apr 2021 02:02:11,419 DEBUG: exit background thread
21 Apr 2021 02:02:11,420 DEBUG: </join() on _asyncThread>
21 Apr 2021 02:02:11,420 DEBUG: </next>
21 Apr 2021 02:02:11,420 DEBUG: <close()>
21 Apr 2021 02:02:11,420 DEBUG: <close() on _data>
21 Apr 2021 02:02:11,420 DEBUG: </close() on _data>
21 Apr 2021 02:02:11,420 DEBUG: <close() on _queue>
21 Apr 2021 02:02:11,420 DEBUG: </close() on _queue>
21 Apr 2021 02:02:11,420 DEBUG: <join() on _asyncThread>
21 Apr 2021 02:02:11,420 DEBUG: </join() on _asyncThread>
21 Apr 2021 02:02:11,420 DEBUG: <close() on org.labkey.api.data.ParameterMapStatement@21260746>
21 Apr 2021 02:02:11,420 DEBUG: </close() on org.labkey.api.data.ParameterMapStatement@21260746>
21 Apr 2021 02:02:11,420 DEBUG: <close() on org.labkey.api.data.ParameterMapStatement@1406d8e3>
21 Apr 2021 02:02:11,420 DEBUG: </close() on org.labkey.api.data.ParameterMapStatement@1406d8e3>
21 Apr 2021 02:02:11,421 DEBUG: </close()>
21 Apr 2021 02:02:11,449 INFO : demographics: Processed 5 rows from dataset001.tsv
21 Apr 2021 02:02:11,449 INFO : demographics: Deleted 5 rows
21 Apr 2021 02:02:11,449 INFO : demographics: Merged 5 rows
21 Apr 2021 02:02:11,476 INFO : emergency_contact_info: Starting import from dataset002.tsv
21 Apr 2021 02:02:11,726 DEBUG: <next>
21 Apr 2021 02:02:11,727 DEBUG: <clear and set parameters on org.labkey.api.data.ParameterMapStatement@1d96ffb1>
21 Apr 2021 02:02:11,727 DEBUG: </clear and set parameters on org.labkey.api.data.ParameterMapStatement@1d96ffb1>
21 Apr 2021 02:02:11,727 DEBUG: </next>
21 Apr 2021 02:02:11,727 DEBUG: <next>
21 Apr 2021 02:02:11,727 DEBUG: <clear and set parameters on org.labkey.api.data.ParameterMapStatement@1d96ffb1>
21 Apr 2021 02:02:11,727 DEBUG: </clear and set parameters on org.labkey.api.data.ParameterMapStatement@1d96ffb1>
21 Apr 2021 02:02:11,727 DEBUG: </next>
21 Apr 2021 02:02:11,727 DEBUG: <next>
21 Apr 2021 02:02:11,727 DEBUG: <clear and set parameters on org.labkey.api.data.ParameterMapStatement@1d96ffb1>
21 Apr 2021 02:02:11,727 DEBUG: </clear and set parameters on org.labkey.api.data.ParameterMapStatement@1d96ffb1>
21 Apr 2021 02:02:11,727 DEBUG: </next>
21 Apr 2021 02:02:11,727 DEBUG: <next>
21 Apr 2021 02:02:11,727 DEBUG: <clear and set parameters on org.labkey.api.data.ParameterMapStatement@1d96ffb1>
21 Apr 2021 02:02:11,728 DEBUG: </clear and set parameters on org.labkey.api.data.ParameterMapStatement@1d96ffb1>
21 Apr 2021 02:02:11,728 DEBUG: </next>
21 Apr 2021 02:02:11,728 DEBUG: <next>
21 Apr 2021 02:02:11,728 DEBUG: <clear and set parameters on org.labkey.api.data.ParameterMapStatement@1d96ffb1>
21 Apr 2021 02:02:11,728 DEBUG: </clear and set parameters on org.labkey.api.data.ParameterMapStatement@1d96ffb1>
21 Apr 2021 02:02:11,728 DEBUG: </next>
21 Apr 2021 02:02:11,728 DEBUG: <next>
21 Apr 2021 02:02:11,728 DEBUG: <swap() - old: org.labkey.api.data.ParameterMapStatement@1d96ffb1>
21 Apr 2021 02:02:11,728 DEBUG: </swap() - new: org.labkey.api.data.ParameterMapStatement@59b7ffe2>
21 Apr 2021 02:02:11,728 DEBUG: <close() on _queue>
21 Apr 2021 02:02:11,728 DEBUG: <close() on _queue>
21 Apr 2021 02:02:11,728 DEBUG: <executeBatch() on org.labkey.api.data.ParameterMapStatement@1d96ffb1>
21 Apr 2021 02:02:11,728 DEBUG: </close() on _queue>
21 Apr 2021 02:02:11,728 DEBUG: <join() on _asyncThread>
21 Apr 2021 02:02:11,738 DEBUG: </executeBatch() on org.labkey.api.data.ParameterMapStatement@1d96ffb1>
21 Apr 2021 02:02:11,738 DEBUG: exit background thread
21 Apr 2021 02:02:11,738 DEBUG: </join() on _asyncThread>
21 Apr 2021 02:02:11,738 DEBUG: </next>
21 Apr 2021 02:02:11,738 DEBUG: <close()>
21 Apr 2021 02:02:11,738 DEBUG: <close() on _data>
21 Apr 2021 02:02:11,738 DEBUG: </close() on _data>
21 Apr 2021 02:02:11,738 DEBUG: <close() on _queue>
21 Apr 2021 02:02:11,738 DEBUG: </close() on _queue>
21 Apr 2021 02:02:11,738 DEBUG: <join() on _asyncThread>
21 Apr 2021 02:02:11,738 DEBUG: </join() on _asyncThread>
21 Apr 2021 02:02:11,738 DEBUG: <close() on org.labkey.api.data.ParameterMapStatement@1d96ffb1>
21 Apr 2021 02:02:11,739 DEBUG: </close() on org.labkey.api.data.ParameterMapStatement@1d96ffb1>
21 Apr 2021 02:02:11,739 DEBUG: <close() on org.labkey.api.data.ParameterMapStatement@59b7ffe2>
21 Apr 2021 02:02:11,739 DEBUG: </close() on org.labkey.api.data.ParameterMapStatement@59b7ffe2>
21 Apr 2021 02:02:11,739 DEBUG: </close()>
21 Apr 2021 02:02:11,766 INFO : emergency_contact_info: Processed 5 rows from dataset002.tsv
21 Apr 2021 02:02:11,766 INFO : emergency_contact_info: Deleted 5 rows
21 Apr 2021 02:02:11,766 INFO : emergency_contact_info: Merged 5 rows
21 Apr 2021 02:02:11,793 INFO : baseline_lab_data: Starting import from dataset003.tsv
21 Apr 2021 02:02:12,030 DEBUG: <next>
21 Apr 2021 02:02:12,031 DEBUG: <clear and set parameters on org.labkey.api.data.ParameterMapStatement@7ff7fbfd>
21 Apr 2021 02:02:12,031 DEBUG: </clear and set parameters on org.labkey.api.data.ParameterMapStatement@7ff7fbfd>
21 Apr 2021 02:02:12,031 DEBUG: </next>
21 Apr 2021 02:02:12,031 DEBUG: <next>
21 Apr 2021 02:02:12,031 DEBUG: <clear and set parameters on org.labkey.api.data.ParameterMapStatement@7ff7fbfd>
21 Apr 2021 02:02:12,031 DEBUG: </clear and set parameters on org.labkey.api.data.ParameterMapStatement@7ff7fbfd>
21 Apr 2021 02:02:12,031 DEBUG: </next>
21 Apr 2021 02:02:12,031 DEBUG: <next>
21 Apr 2021 02:02:12,032 DEBUG: <clear and set parameters on org.labkey.api.data.ParameterMapStatement@7ff7fbfd>
21 Apr 2021 02:02:12,032 DEBUG: </clear and set parameters on org.labkey.api.data.ParameterMapStatement@7ff7fbfd>
21 Apr 2021 02:02:12,032 DEBUG: </next>
21 Apr 2021 02:02:12,032 DEBUG: <next>
21 Apr 2021 02:02:12,032 DEBUG: <clear and set parameters on org.labkey.api.data.ParameterMapStatement@7ff7fbfd>
21 Apr 2021 02:02:12,032 DEBUG: </clear and set parameters on org.labkey.api.data.ParameterMapStatement@7ff7fbfd>
21 Apr 2021 02:02:12,032 DEBUG: </next>
21 Apr 2021 02:02:12,032 DEBUG: <next>
21 Apr 2021 02:02:12,032 DEBUG: <clear and set parameters on org.labkey.api.data.ParameterMapStatement@7ff7fbfd>
21 Apr 2021 02:02:12,032 DEBUG: </clear and set parameters on org.labkey.api.data.ParameterMapStatement@7ff7fbfd>
21 Apr 2021 02:02:12,032 DEBUG: </next>
21 Apr 2021 02:02:12,032 DEBUG: <next>
21 Apr 2021 02:02:12,032 DEBUG: <swap() - old: org.labkey.api.data.ParameterMapStatement@7ff7fbfd>
21 Apr 2021 02:02:12,032 DEBUG: </swap() - new: org.labkey.api.data.ParameterMapStatement@193f99e6>
21 Apr 2021 02:02:12,032 DEBUG: <close() on _queue>
21 Apr 2021 02:02:12,032 DEBUG: <executeBatch() on org.labkey.api.data.ParameterMapStatement@7ff7fbfd>
21 Apr 2021 02:02:12,032 DEBUG: <close() on _queue>
21 Apr 2021 02:02:12,033 DEBUG: </close() on _queue>
21 Apr 2021 02:02:12,033 DEBUG: <join() on _asyncThread>
21 Apr 2021 02:02:12,041 DEBUG: </executeBatch() on org.labkey.api.data.ParameterMapStatement@7ff7fbfd>
21 Apr 2021 02:02:12,042 DEBUG: exit background thread
21 Apr 2021 02:02:12,042 DEBUG: </join() on _asyncThread>
21 Apr 2021 02:02:12,042 DEBUG: </next>
21 Apr 2021 02:02:12,042 DEBUG: <close()>
21 Apr 2021 02:02:12,042 DEBUG: <close() on _data>
21 Apr 2021 02:02:12,042 DEBUG: </close() on _data>
21 Apr 2021 02:02:12,042 DEBUG: <close() on _queue>
21 Apr 2021 02:02:12,042 DEBUG: </close() on _queue>
21 Apr 2021 02:02:12,042 DEBUG: <join() on _asyncThread>
21 Apr 2021 02:02:12,042 DEBUG: </join() on _asyncThread>
21 Apr 2021 02:02:12,042 DEBUG: <close() on org.labkey.api.data.ParameterMapStatement@7ff7fbfd>
21 Apr 2021 02:02:12,042 DEBUG: </close() on org.labkey.api.data.ParameterMapStatement@7ff7fbfd>
21 Apr 2021 02:02:12,042 DEBUG: <close() on org.labkey.api.data.ParameterMapStatement@193f99e6>
21 Apr 2021 02:02:12,042 DEBUG: </close() on org.labkey.api.data.ParameterMapStatement@193f99e6>
21 Apr 2021 02:02:12,042 DEBUG: </close()>
21 Apr 2021 02:02:12,064 INFO : baseline_lab_data: Processed 5 rows from dataset003.tsv
21 Apr 2021 02:02:12,064 INFO : baseline_lab_data: Deleted 5 rows
21 Apr 2021 02:02:12,064 INFO : baseline_lab_data: Merged 5 rows
21 Apr 2021 02:02:12,105 INFO : visit_blood_workup: Starting import from dataset004.tsv
21 Apr 2021 02:02:12,170 DEBUG: <next>
21 Apr 2021 02:02:12,170 DEBUG: <close() on _queue>
21 Apr 2021 02:02:12,170 DEBUG: <close() on _queue>
21 Apr 2021 02:02:12,170 DEBUG: </close() on _queue>
21 Apr 2021 02:02:12,170 DEBUG: <join() on _asyncThread>
21 Apr 2021 02:02:12,171 DEBUG: exit background thread
21 Apr 2021 02:02:12,171 DEBUG: </join() on _asyncThread>
21 Apr 2021 02:02:12,171 DEBUG: </next>
21 Apr 2021 02:02:12,171 DEBUG: <close()>
21 Apr 2021 02:02:12,171 DEBUG: <close() on _data>
21 Apr 2021 02:02:12,171 DEBUG: </close() on _data>
21 Apr 2021 02:02:12,171 DEBUG: <close() on _queue>
21 Apr 2021 02:02:12,171 DEBUG: </close() on _queue>
21 Apr 2021 02:02:12,171 DEBUG: <join() on _asyncThread>
21 Apr 2021 02:02:12,171 DEBUG: </join() on _asyncThread>
21 Apr 2021 02:02:12,171 DEBUG: <close() on org.labkey.api.data.ParameterMapStatement@1ac2d1b6>
21 Apr 2021 02:02:12,171 DEBUG: </close() on org.labkey.api.data.ParameterMapStatement@1ac2d1b6>
21 Apr 2021 02:02:12,171 DEBUG: <close() on org.labkey.api.data.ParameterMapStatement@4441a72a>
21 Apr 2021 02:02:12,171 DEBUG: </close() on org.labkey.api.data.ParameterMapStatement@4441a72a>
21 Apr 2021 02:02:12,171 DEBUG: </close()>
21 Apr 2021 02:02:12,205 INFO : completion_data: Starting import from dataset005.tsv
21 Apr 2021 02:02:12,240 DEBUG: <next>
21 Apr 2021 02:02:12,240 DEBUG: <close() on _queue>
21 Apr 2021 02:02:12,240 DEBUG: <close() on _queue>
21 Apr 2021 02:02:12,240 DEBUG: </close() on _queue>
21 Apr 2021 02:02:12,240 DEBUG: <join() on _asyncThread>
21 Apr 2021 02:02:12,240 DEBUG: exit background thread
21 Apr 2021 02:02:12,240 DEBUG: </join() on _asyncThread>
21 Apr 2021 02:02:12,240 DEBUG: </next>
21 Apr 2021 02:02:12,240 DEBUG: <close()>
21 Apr 2021 02:02:12,240 DEBUG: <close() on _data>
21 Apr 2021 02:02:12,240 DEBUG: </close() on _data>
21 Apr 2021 02:02:12,240 DEBUG: <close() on _queue>
21 Apr 2021 02:02:12,240 DEBUG: </close() on _queue>
21 Apr 2021 02:02:12,240 DEBUG: <join() on _asyncThread>
21 Apr 2021 02:02:12,240 DEBUG: </join() on _asyncThread>
21 Apr 2021 02:02:12,241 DEBUG: <close() on org.labkey.api.data.ParameterMapStatement@43b1002e>
21 Apr 2021 02:02:12,241 DEBUG: </close() on org.labkey.api.data.ParameterMapStatement@43b1002e>
21 Apr 2021 02:02:12,241 DEBUG: <close() on org.labkey.api.data.ParameterMapStatement@89b8820>
21 Apr 2021 02:02:12,241 DEBUG: </close() on org.labkey.api.data.ParameterMapStatement@89b8820>
21 Apr 2021 02:02:12,241 DEBUG: </close()>
21 Apr 2021 02:02:12,282 INFO : completion_project_questionnaire: Starting import from dataset006.tsv
21 Apr 2021 02:02:12,362 DEBUG: <next>
21 Apr 2021 02:02:12,362 DEBUG: <close() on _queue>
21 Apr 2021 02:02:12,362 DEBUG: <close() on _queue>
21 Apr 2021 02:02:12,362 DEBUG: </close() on _queue>
21 Apr 2021 02:02:12,362 DEBUG: <join() on _asyncThread>
21 Apr 2021 02:02:12,362 DEBUG: exit background thread
21 Apr 2021 02:02:12,362 DEBUG: </join() on _asyncThread>
21 Apr 2021 02:02:12,362 DEBUG: </next>
21 Apr 2021 02:02:12,363 DEBUG: <close()>
21 Apr 2021 02:02:12,363 DEBUG: <close() on _data>
21 Apr 2021 02:02:12,363 DEBUG: </close() on _data>
21 Apr 2021 02:02:12,363 DEBUG: <close() on _queue>
21 Apr 2021 02:02:12,363 DEBUG: </close() on _queue>
21 Apr 2021 02:02:12,363 DEBUG: <join() on _asyncThread>
21 Apr 2021 02:02:12,363 DEBUG: </join() on _asyncThread>
21 Apr 2021 02:02:12,363 DEBUG: <close() on org.labkey.api.data.ParameterMapStatement@7eea8f60>
21 Apr 2021 02:02:12,363 DEBUG: </close() on org.labkey.api.data.ParameterMapStatement@7eea8f60>
21 Apr 2021 02:02:12,363 DEBUG: <close() on org.labkey.api.data.ParameterMapStatement@76eaf867>
21 Apr 2021 02:02:12,363 DEBUG: </close() on org.labkey.api.data.ParameterMapStatement@76eaf867>
21 Apr 2021 02:02:12,363 DEBUG: </close()>
21 Apr 2021 02:02:12,369 INFO : Finish batch RedCap Integration.dataset
21 Apr 2021 02:02:12,374 INFO : Updating participant visits
21 Apr 2021 02:02:12,374 INFO : Updating participants
21 Apr 2021 02:02:12,380 INFO : Updating participant visit table
21 Apr 2021 02:02:12,461 INFO : Updating visit table
21 Apr 2021 02:02:12,464 INFO : Updating cohorts
21 Apr 2021 02:02:12,464 INFO : Clearing participant visit caches
21 Apr 2021 02:02:12,466 INFO : Finished updating participants
21 Apr 2021 02:02:12,467 INFO : Successfully completed task 'org.labkey.study.pipeline.StudyImportDatasetTask'
21 Apr 2021 02:02:12,521 INFO : Starting to run task 'org.labkey.api.specimen.pipeline.StudyImportSpecimenTask' at location 'webserver'
21 Apr 2021 02:02:12,521 INFO : Successfully completed task 'org.labkey.api.specimen.pipeline.StudyImportSpecimenTask'
21 Apr 2021 02:02:12,567 INFO : Starting to run task 'org.labkey.study.importer.StudyImportFinalTask' at location 'webserver'
21 Apr 2021 02:02:12,587 INFO : Loading dataset cohort assignments
21 Apr 2021 02:02:12,587 INFO : Done importing dataset cohort assignments
21 Apr 2021 02:02:12,628 INFO : Loading lists
21 Apr 2021 02:02:12,630 INFO : Truncating list: vbw8
21 Apr 2021 02:24:05,610 INFO : Recreating list: vbw8
21 Apr 2021 02:24:05,809 INFO : Truncating list: cpq13
21 Apr 2021 02:24:05,975 INFO : Recreating list: cpq13
21 Apr 2021 02:24:06,098 INFO : Truncating list: sex
21 Apr 2021 02:24:06,240 INFO : Recreating list: sex
21 Apr 2021 02:24:06,374 INFO : Truncating list: withdraw_reason
21 Apr 2021 02:24:06,572 INFO : Recreating list: withdraw_reason
21 Apr 2021 02:24:06,701 INFO : Truncating list: cpq6
21 Apr 2021 02:24:06,865 INFO : Recreating list: cpq6
21 Apr 2021 02:24:07,012 INFO : Truncating list: vbw9
21 Apr 2021 02:24:07,131 INFO : Recreating list: vbw9
21 Apr 2021 02:24:07,236 INFO : Truncating list: cpq8
21 Apr 2021 02:24:07,342 INFO : Recreating list: cpq8
21 Apr 2021 02:24:07,435 INFO : Truncating list: cpq10
21 Apr 2021 02:24:07,539 INFO : Recreating list: cpq10
21 Apr 2021 02:24:07,635 INFO : Truncating list: vbw6
21 Apr 2021 02:24:07,729 INFO : Recreating list: vbw6
21 Apr 2021 02:24:07,822 INFO : Truncating list: cpq11
21 Apr 2021 02:24:07,920 INFO : Recreating list: cpq11
21 Apr 2021 02:24:08,013 INFO : Truncating list: vbw7
21 Apr 2021 02:24:08,112 INFO : Recreating list: vbw7
21 Apr 2021 02:24:08,280 INFO : Merged 5 row(s) into list: withdraw_reason
21 Apr 2021 02:24:08,349 INFO : Merged 3 row(s) into list: cpq13
21 Apr 2021 02:24:08,407 INFO : Merged 6 row(s) into list: cpq11
21 Apr 2021 02:24:08,455 INFO : Merged 4 row(s) into list: cpq10
21 Apr 2021 02:24:08,504 INFO : Merged 2 row(s) into list: sex
21 Apr 2021 02:24:08,555 INFO : Merged 2 row(s) into list: vbw9
21 Apr 2021 02:24:08,603 INFO : Merged 3 row(s) into list: vbw8
21 Apr 2021 02:24:08,657 INFO : Merged 3 row(s) into list: cpq8
21 Apr 2021 02:24:08,732 INFO : Merged 4 row(s) into list: vbw7
21 Apr 2021 02:24:08,784 INFO : Merged 2 row(s) into list: vbw6
21 Apr 2021 02:24:08,856 INFO : Merged 5 row(s) into list: cpq6
21 Apr 2021 02:24:08,862 INFO : 11 lists imported successfully
21 Apr 2021 02:24:08,863 INFO : Done importing lists
21 Apr 2021 02:24:08,873 INFO : Post-processing queries
21 Apr 2021 02:24:08,873 INFO : Skipping query validation.
21 Apr 2021 02:24:08,873 INFO : Done post-processing queries
21 Apr 2021 02:24:08,889 INFO : Successfully completed task 'org.labkey.study.importer.StudyImportFinalTask'