07 Apr 2021 02:02:34,544 INFO : Starting to run task 'org.labkey.study.pipeline.StudyReloadSourceTask' at location 'webserver'
07 Apr 2021 02:02:34,544 INFO : Starting REDCap export
07 Apr 2021 02:02:35,346 INFO : Creating study archive
07 Apr 2021 02:02:35,361 INFO : Writing dataset metadata
07 Apr 2021 02:02:35,478 INFO : Creating column lookups
07 Apr 2021 02:02:36,130 WARN : Unable to locate subject id field: first_name for dataset: demographics row ignored.
07 Apr 2021 02:02:36,130 WARN : Unable to locate subject id field: first_name for dataset: demographics row ignored.
07 Apr 2021 02:02:36,131 WARN : Unable to locate subject id field: first_name for dataset: demographics row ignored.
07 Apr 2021 02:02:36,131 WARN : Unable to locate subject id field: first_name for dataset: demographics row ignored.
07 Apr 2021 02:02:36,131 WARN : Unable to locate subject id field: first_name for dataset: demographics row ignored.
07 Apr 2021 02:02:36,131 WARN : Unable to locate subject id field: first_name for dataset: demographics row ignored.
07 Apr 2021 02:02:36,131 WARN : Unable to locate subject id field: first_name for dataset: demographics row ignored.
07 Apr 2021 02:02:36,131 WARN : Unable to locate subject id field: first_name for dataset: demographics row ignored.
07 Apr 2021 02:02:36,131 WARN : Unable to locate subject id field: first_name for dataset: demographics row ignored.
07 Apr 2021 02:02:36,131 WARN : Unable to locate subject id field: first_name for dataset: demographics row ignored.
07 Apr 2021 02:02:36,131 WARN : Unable to locate subject id field: first_name for dataset: demographics row ignored.
07 Apr 2021 02:02:36,132 WARN : Unable to locate subject id field: first_name for dataset: demographics row ignored.
07 Apr 2021 02:02:36,132 WARN : Unable to locate subject id field: first_name for dataset: demographics row ignored.
07 Apr 2021 02:02:36,132 WARN : Unable to locate subject id field: first_name for dataset: demographics row ignored.
07 Apr 2021 02:02:36,132 WARN : Unable to locate subject id field: first_name for dataset: demographics row ignored.
07 Apr 2021 02:02:36,132 WARN : Unable to locate subject id field: first_name for dataset: demographics row ignored.
07 Apr 2021 02:02:36,132 WARN : Unable to locate subject id field: first_name for dataset: demographics row ignored.
07 Apr 2021 02:02:36,132 WARN : Unable to locate subject id field: first_name for dataset: demographics row ignored.
07 Apr 2021 02:02:36,132 WARN : Unable to locate subject id field: first_name for dataset: demographics row ignored.
07 Apr 2021 02:02:36,132 WARN : Unable to locate subject id field: first_name for dataset: emergency_contact_info row ignored.
07 Apr 2021 02:02:36,132 WARN : Unable to locate subject id field: first_name for dataset: emergency_contact_info row ignored.
07 Apr 2021 02:02:36,133 WARN : Unable to locate subject id field: first_name for dataset: emergency_contact_info row ignored.
07 Apr 2021 02:02:36,133 WARN : Unable to locate subject id field: first_name for dataset: emergency_contact_info row ignored.
07 Apr 2021 02:02:36,133 WARN : Unable to locate subject id field: first_name for dataset: emergency_contact_info row ignored.
07 Apr 2021 02:02:36,133 WARN : Unable to locate subject id field: first_name for dataset: emergency_contact_info row ignored.
07 Apr 2021 02:02:36,133 WARN : Unable to locate subject id field: first_name for dataset: emergency_contact_info row ignored.
07 Apr 2021 02:02:36,133 WARN : Unable to locate subject id field: first_name for dataset: emergency_contact_info row ignored.
07 Apr 2021 02:02:36,133 WARN : Unable to locate subject id field: first_name for dataset: emergency_contact_info row ignored.
07 Apr 2021 02:02:36,133 WARN : Unable to locate subject id field: first_name for dataset: emergency_contact_info row ignored.
07 Apr 2021 02:02:36,133 WARN : Unable to locate subject id field: first_name for dataset: emergency_contact_info row ignored.
07 Apr 2021 02:02:36,133 WARN : Unable to locate subject id field: first_name for dataset: emergency_contact_info row ignored.
07 Apr 2021 02:02:36,133 WARN : Unable to locate subject id field: first_name for dataset: emergency_contact_info row ignored.
07 Apr 2021 02:02:36,134 WARN : Unable to locate subject id field: first_name for dataset: emergency_contact_info row ignored.
07 Apr 2021 02:02:36,134 WARN : Unable to locate subject id field: first_name for dataset: emergency_contact_info row ignored.
07 Apr 2021 02:02:36,134 WARN : Unable to locate subject id field: first_name for dataset: emergency_contact_info row ignored.
07 Apr 2021 02:02:36,134 WARN : Unable to locate subject id field: first_name for dataset: emergency_contact_info row ignored.
07 Apr 2021 02:02:36,134 WARN : Unable to locate subject id field: first_name for dataset: emergency_contact_info row ignored.
07 Apr 2021 02:02:36,134 WARN : Unable to locate subject id field: first_name for dataset: emergency_contact_info row ignored.
07 Apr 2021 02:02:36,134 WARN : Unable to locate subject id field: first_name for dataset: baseline_lab_data row ignored.
07 Apr 2021 02:02:36,134 WARN : Unable to locate subject id field: first_name for dataset: baseline_lab_data row ignored.
07 Apr 2021 02:02:36,134 WARN : Unable to locate subject id field: first_name for dataset: baseline_lab_data row ignored.
07 Apr 2021 02:02:36,134 WARN : Unable to locate subject id field: first_name for dataset: baseline_lab_data row ignored.
07 Apr 2021 02:02:36,134 WARN : Unable to locate subject id field: first_name for dataset: baseline_lab_data row ignored.
07 Apr 2021 02:02:36,134 WARN : Unable to locate subject id field: first_name for dataset: baseline_lab_data row ignored.
07 Apr 2021 02:02:36,134 WARN : Unable to locate subject id field: first_name for dataset: baseline_lab_data row ignored.
07 Apr 2021 02:02:36,134 WARN : Unable to locate subject id field: first_name for dataset: baseline_lab_data row ignored.
07 Apr 2021 02:02:36,135 WARN : Unable to locate subject id field: first_name for dataset: baseline_lab_data row ignored.
07 Apr 2021 02:02:36,135 WARN : Unable to locate subject id field: first_name for dataset: baseline_lab_data row ignored.
07 Apr 2021 02:02:36,135 WARN : Unable to locate subject id field: first_name for dataset: baseline_lab_data row ignored.
07 Apr 2021 02:02:36,135 WARN : Unable to locate subject id field: first_name for dataset: baseline_lab_data row ignored.
07 Apr 2021 02:02:36,135 WARN : Unable to locate subject id field: first_name for dataset: baseline_lab_data row ignored.
07 Apr 2021 02:02:36,135 WARN : Unable to locate subject id field: first_name for dataset: baseline_lab_data row ignored.
07 Apr 2021 02:02:36,135 WARN : Unable to locate subject id field: first_name for dataset: baseline_lab_data row ignored.
07 Apr 2021 02:02:36,135 WARN : Unable to locate subject id field: first_name for dataset: baseline_lab_data row ignored.
07 Apr 2021 02:02:36,135 WARN : Unable to locate subject id field: first_name for dataset: baseline_lab_data row ignored.
07 Apr 2021 02:02:36,135 WARN : Unable to locate subject id field: first_name for dataset: baseline_lab_data row ignored.
07 Apr 2021 02:02:36,135 WARN : Unable to locate subject id field: first_name for dataset: baseline_lab_data row ignored.
07 Apr 2021 02:02:36,135 WARN : Unable to locate subject id field: first_name for dataset: visit_blood_workup row ignored.
07 Apr 2021 02:02:36,135 WARN : Unable to locate subject id field: first_name for dataset: visit_blood_workup row ignored.
07 Apr 2021 02:02:36,135 WARN : Unable to locate subject id field: first_name for dataset: visit_blood_workup row ignored.
07 Apr 2021 02:02:36,136 WARN : Unable to locate subject id field: first_name for dataset: visit_blood_workup row ignored.
07 Apr 2021 02:02:36,136 WARN : Unable to locate subject id field: first_name for dataset: visit_blood_workup row ignored.
07 Apr 2021 02:02:36,136 WARN : Unable to locate subject id field: first_name for dataset: visit_blood_workup row ignored.
07 Apr 2021 02:02:36,136 WARN : Unable to locate subject id field: first_name for dataset: visit_blood_workup row ignored.
07 Apr 2021 02:02:36,136 WARN : Unable to locate subject id field: first_name for dataset: visit_blood_workup row ignored.
07 Apr 2021 02:02:36,136 WARN : Unable to locate subject id field: first_name for dataset: visit_blood_workup row ignored.
07 Apr 2021 02:02:36,136 WARN : Unable to locate subject id field: first_name for dataset: visit_blood_workup row ignored.
07 Apr 2021 02:02:36,137 WARN : Unable to locate subject id field: first_name for dataset: visit_blood_workup row ignored.
07 Apr 2021 02:02:36,138 WARN : Unable to locate subject id field: first_name for dataset: visit_blood_workup row ignored.
07 Apr 2021 02:02:36,138 WARN : Unable to locate subject id field: first_name for dataset: visit_blood_workup row ignored.
07 Apr 2021 02:02:36,138 WARN : Unable to locate subject id field: first_name for dataset: visit_blood_workup row ignored.
07 Apr 2021 02:02:36,138 WARN : Unable to locate subject id field: first_name for dataset: visit_blood_workup row ignored.
07 Apr 2021 02:02:36,138 WARN : Unable to locate subject id field: first_name for dataset: visit_blood_workup row ignored.
07 Apr 2021 02:02:36,138 WARN : Unable to locate subject id field: first_name for dataset: visit_blood_workup row ignored.
07 Apr 2021 02:02:36,138 WARN : Unable to locate subject id field: first_name for dataset: visit_blood_workup row ignored.
07 Apr 2021 02:02:36,138 WARN : Unable to locate subject id field: first_name for dataset: completion_data row ignored.
07 Apr 2021 02:02:36,138 WARN : Unable to locate subject id field: first_name for dataset: completion_data row ignored.
07 Apr 2021 02:02:36,138 WARN : Unable to locate subject id field: first_name for dataset: completion_data row ignored.
07 Apr 2021 02:02:36,138 WARN : Unable to locate subject id field: first_name for dataset: completion_data row ignored.
07 Apr 2021 02:02:36,138 WARN : Unable to locate subject id field: first_name for dataset: completion_data row ignored.
07 Apr 2021 02:02:36,139 WARN : Unable to locate subject id field: first_name for dataset: completion_data row ignored.
07 Apr 2021 02:02:36,139 WARN : Unable to locate subject id field: first_name for dataset: completion_data row ignored.
07 Apr 2021 02:02:36,139 WARN : Unable to locate subject id field: first_name for dataset: completion_data row ignored.
07 Apr 2021 02:02:36,139 WARN : Unable to locate subject id field: first_name for dataset: completion_data row ignored.
07 Apr 2021 02:02:36,139 WARN : Unable to locate subject id field: first_name for dataset: completion_data row ignored.
07 Apr 2021 02:02:36,139 WARN : Unable to locate subject id field: first_name for dataset: completion_data row ignored.
07 Apr 2021 02:02:36,139 WARN : Unable to locate subject id field: first_name for dataset: completion_data row ignored.
07 Apr 2021 02:02:36,140 WARN : Unable to locate subject id field: first_name for dataset: completion_data row ignored.
07 Apr 2021 02:02:36,140 WARN : Unable to locate subject id field: first_name for dataset: completion_data row ignored.
07 Apr 2021 02:02:36,140 WARN : Unable to locate subject id field: first_name for dataset: completion_data row ignored.
07 Apr 2021 02:02:36,140 WARN : Unable to locate subject id field: first_name for dataset: completion_data row ignored.
07 Apr 2021 02:02:36,140 WARN : Unable to locate subject id field: first_name for dataset: completion_data row ignored.
07 Apr 2021 02:02:36,140 WARN : Unable to locate subject id field: first_name for dataset: completion_data row ignored.
07 Apr 2021 02:02:36,140 WARN : Unable to locate subject id field: first_name for dataset: completion_data row ignored.
07 Apr 2021 02:02:36,140 WARN : Unable to locate subject id field: first_name for dataset: completion_project_questionnaire row ignored.
07 Apr 2021 02:02:36,140 WARN : Unable to locate subject id field: first_name for dataset: completion_project_questionnaire row ignored.
07 Apr 2021 02:02:36,141 WARN : Unable to locate subject id field: first_name for dataset: completion_project_questionnaire row ignored.
07 Apr 2021 02:02:36,141 WARN : Unable to locate subject id field: first_name for dataset: completion_project_questionnaire row ignored.
07 Apr 2021 02:02:36,141 WARN : Unable to locate subject id field: first_name for dataset: completion_project_questionnaire row ignored.
07 Apr 2021 02:02:36,141 WARN : Unable to locate subject id field: first_name for dataset: completion_project_questionnaire row ignored.
07 Apr 2021 02:02:36,141 WARN : Unable to locate subject id field: first_name for dataset: completion_project_questionnaire row ignored.
07 Apr 2021 02:02:36,141 WARN : Unable to locate subject id field: first_name for dataset: completion_project_questionnaire row ignored.
07 Apr 2021 02:02:36,141 WARN : Unable to locate subject id field: first_name for dataset: completion_project_questionnaire row ignored.
07 Apr 2021 02:02:36,141 WARN : Unable to locate subject id field: first_name for dataset: completion_project_questionnaire row ignored.
07 Apr 2021 02:02:36,141 WARN : Unable to locate subject id field: first_name for dataset: completion_project_questionnaire row ignored.
07 Apr 2021 02:02:36,141 WARN : Unable to locate subject id field: first_name for dataset: completion_project_questionnaire row ignored.
07 Apr 2021 02:02:36,141 WARN : Unable to locate subject id field: first_name for dataset: completion_project_questionnaire row ignored.
07 Apr 2021 02:02:36,141 WARN : Unable to locate subject id field: first_name for dataset: completion_project_questionnaire row ignored.
07 Apr 2021 02:02:36,141 WARN : Unable to locate subject id field: first_name for dataset: completion_project_questionnaire row ignored.
07 Apr 2021 02:02:36,142 WARN : Unable to locate subject id field: first_name for dataset: completion_project_questionnaire row ignored.
07 Apr 2021 02:02:36,142 WARN : Unable to locate subject id field: first_name for dataset: completion_project_questionnaire row ignored.
07 Apr 2021 02:02:36,142 WARN : Unable to locate subject id field: first_name for dataset: completion_project_questionnaire row ignored.
07 Apr 2021 02:02:36,142 WARN : Unable to locate subject id field: first_name for dataset: completion_project_questionnaire row ignored.
07 Apr 2021 02:02:36,146 INFO : Finished creating study archive
07 Apr 2021 02:02:36,146 INFO : Successfully completed task 'org.labkey.study.pipeline.StudyReloadSourceTask'
07 Apr 2021 02:02:36,189 INFO : Starting to run task 'org.labkey.study.importer.StudyImportInitialTask' at location 'webserver'
07 Apr 2021 02:02:36,191 INFO : Reloading study from study.xml
07 Apr 2021 02:02:36,198 INFO : Loading top-level study properties (label, start/end date, description, etc.)
07 Apr 2021 02:02:36,718 INFO : Done importing top-level study properties (label, start/end date, description, etc.)
07 Apr 2021 02:02:36,761 INFO : Loading datasets manifest from datasets_manifest.xml
07 Apr 2021 02:02:36,763 INFO : Loading dataset schema from datasets_metadata.xml
07 Apr 2021 02:02:38,014 INFO : Successfully completed task 'org.labkey.study.importer.StudyImportInitialTask'
07 Apr 2021 02:02:38,059 INFO : Starting to run task 'org.labkey.study.pipeline.StudyImportDatasetTask' at location 'webserver'
07 Apr 2021 02:02:38,060 INFO : Start batch RedCap Integration.dataset
07 Apr 2021 02:02:38,148 INFO : demographics: Starting import from dataset001.tsv
07 Apr 2021 02:02:38,737 DEBUG: <next>
07 Apr 2021 02:02:38,739 DEBUG: <clear and set parameters on org.labkey.api.data.ParameterMapStatement@276b5e7e>
07 Apr 2021 02:02:38,739 DEBUG: </clear and set parameters on org.labkey.api.data.ParameterMapStatement@276b5e7e>
07 Apr 2021 02:02:38,739 DEBUG: </next>
07 Apr 2021 02:02:38,739 DEBUG: <next>
07 Apr 2021 02:02:38,739 DEBUG: <clear and set parameters on org.labkey.api.data.ParameterMapStatement@276b5e7e>
07 Apr 2021 02:02:38,739 DEBUG: </clear and set parameters on org.labkey.api.data.ParameterMapStatement@276b5e7e>
07 Apr 2021 02:02:38,739 DEBUG: </next>
07 Apr 2021 02:02:38,740 DEBUG: <next>
07 Apr 2021 02:02:38,740 DEBUG: <clear and set parameters on org.labkey.api.data.ParameterMapStatement@276b5e7e>
07 Apr 2021 02:02:38,740 DEBUG: </clear and set parameters on org.labkey.api.data.ParameterMapStatement@276b5e7e>
07 Apr 2021 02:02:38,740 DEBUG: </next>
07 Apr 2021 02:02:38,740 DEBUG: <next>
07 Apr 2021 02:02:38,740 DEBUG: <clear and set parameters on org.labkey.api.data.ParameterMapStatement@276b5e7e>
07 Apr 2021 02:02:38,740 DEBUG: </clear and set parameters on org.labkey.api.data.ParameterMapStatement@276b5e7e>
07 Apr 2021 02:02:38,741 DEBUG: </next>
07 Apr 2021 02:02:38,741 DEBUG: <next>
07 Apr 2021 02:02:38,741 DEBUG: <clear and set parameters on org.labkey.api.data.ParameterMapStatement@276b5e7e>
07 Apr 2021 02:02:38,741 DEBUG: </clear and set parameters on org.labkey.api.data.ParameterMapStatement@276b5e7e>
07 Apr 2021 02:02:38,741 DEBUG: </next>
07 Apr 2021 02:02:38,741 DEBUG: <next>
07 Apr 2021 02:02:38,741 DEBUG: <swap() - old: org.labkey.api.data.ParameterMapStatement@276b5e7e>
07 Apr 2021 02:02:38,741 DEBUG: </swap() - new: org.labkey.api.data.ParameterMapStatement@65043f0d>
07 Apr 2021 02:02:38,741 DEBUG: <close() on _queue>
07 Apr 2021 02:02:38,741 DEBUG: <close() on _queue>
07 Apr 2021 02:02:38,741 DEBUG: </close() on _queue>
07 Apr 2021 02:02:38,741 DEBUG: <join() on _asyncThread>
07 Apr 2021 02:02:38,743 DEBUG: <executeBatch() on org.labkey.api.data.ParameterMapStatement@276b5e7e>
07 Apr 2021 02:02:38,761 DEBUG: </executeBatch() on org.labkey.api.data.ParameterMapStatement@276b5e7e>
07 Apr 2021 02:02:38,761 DEBUG: exit background thread
07 Apr 2021 02:02:38,762 DEBUG: </join() on _asyncThread>
07 Apr 2021 02:02:38,762 DEBUG: </next>
07 Apr 2021 02:02:38,762 DEBUG: <close()>
07 Apr 2021 02:02:38,762 DEBUG: <close() on _data>
07 Apr 2021 02:02:38,762 DEBUG: </close() on _data>
07 Apr 2021 02:02:38,762 DEBUG: <close() on _queue>
07 Apr 2021 02:02:38,762 DEBUG: </close() on _queue>
07 Apr 2021 02:02:38,762 DEBUG: <join() on _asyncThread>
07 Apr 2021 02:02:38,762 DEBUG: </join() on _asyncThread>
07 Apr 2021 02:02:38,762 DEBUG: <close() on org.labkey.api.data.ParameterMapStatement@276b5e7e>
07 Apr 2021 02:02:38,762 DEBUG: </close() on org.labkey.api.data.ParameterMapStatement@276b5e7e>
07 Apr 2021 02:02:38,762 DEBUG: <close() on org.labkey.api.data.ParameterMapStatement@65043f0d>
07 Apr 2021 02:02:38,763 DEBUG: </close() on org.labkey.api.data.ParameterMapStatement@65043f0d>
07 Apr 2021 02:02:38,763 DEBUG: </close()>
07 Apr 2021 02:02:38,789 INFO : demographics: Processed 5 rows from dataset001.tsv
07 Apr 2021 02:02:38,789 INFO : demographics: Deleted 5 rows
07 Apr 2021 02:02:38,789 INFO : demographics: Merged 5 rows
07 Apr 2021 02:02:38,836 INFO : emergency_contact_info: Starting import from dataset002.tsv
07 Apr 2021 02:02:39,169 DEBUG: <next>
07 Apr 2021 02:02:39,170 DEBUG: <clear and set parameters on org.labkey.api.data.ParameterMapStatement@430da1bb>
07 Apr 2021 02:02:39,170 DEBUG: </clear and set parameters on org.labkey.api.data.ParameterMapStatement@430da1bb>
07 Apr 2021 02:02:39,171 DEBUG: </next>
07 Apr 2021 02:02:39,171 DEBUG: <next>
07 Apr 2021 02:02:39,171 DEBUG: <clear and set parameters on org.labkey.api.data.ParameterMapStatement@430da1bb>
07 Apr 2021 02:02:39,171 DEBUG: </clear and set parameters on org.labkey.api.data.ParameterMapStatement@430da1bb>
07 Apr 2021 02:02:39,171 DEBUG: </next>
07 Apr 2021 02:02:39,175 DEBUG: <next>
07 Apr 2021 02:02:39,176 DEBUG: <clear and set parameters on org.labkey.api.data.ParameterMapStatement@430da1bb>
07 Apr 2021 02:02:39,176 DEBUG: </clear and set parameters on org.labkey.api.data.ParameterMapStatement@430da1bb>
07 Apr 2021 02:02:39,176 DEBUG: </next>
07 Apr 2021 02:02:39,176 DEBUG: <next>
07 Apr 2021 02:02:39,176 DEBUG: <clear and set parameters on org.labkey.api.data.ParameterMapStatement@430da1bb>
07 Apr 2021 02:02:39,176 DEBUG: </clear and set parameters on org.labkey.api.data.ParameterMapStatement@430da1bb>
07 Apr 2021 02:02:39,176 DEBUG: </next>
07 Apr 2021 02:02:39,176 DEBUG: <next>
07 Apr 2021 02:02:39,179 DEBUG: <clear and set parameters on org.labkey.api.data.ParameterMapStatement@430da1bb>
07 Apr 2021 02:02:39,179 DEBUG: </clear and set parameters on org.labkey.api.data.ParameterMapStatement@430da1bb>
07 Apr 2021 02:02:39,180 DEBUG: </next>
07 Apr 2021 02:02:39,180 DEBUG: <next>
07 Apr 2021 02:02:39,180 DEBUG: <swap() - old: org.labkey.api.data.ParameterMapStatement@430da1bb>
07 Apr 2021 02:02:39,180 DEBUG: </swap() - new: org.labkey.api.data.ParameterMapStatement@4f26033d>
07 Apr 2021 02:02:39,180 DEBUG: <close() on _queue>
07 Apr 2021 02:02:39,180 DEBUG: <close() on _queue>
07 Apr 2021 02:02:39,180 DEBUG: </close() on _queue>
07 Apr 2021 02:02:39,180 DEBUG: <join() on _asyncThread>
07 Apr 2021 02:02:39,180 DEBUG: <executeBatch() on org.labkey.api.data.ParameterMapStatement@430da1bb>
07 Apr 2021 02:02:39,189 DEBUG: </executeBatch() on org.labkey.api.data.ParameterMapStatement@430da1bb>
07 Apr 2021 02:02:39,189 DEBUG: exit background thread
07 Apr 2021 02:02:39,190 DEBUG: </join() on _asyncThread>
07 Apr 2021 02:02:39,190 DEBUG: </next>
07 Apr 2021 02:02:39,190 DEBUG: <close()>
07 Apr 2021 02:02:39,190 DEBUG: <close() on _data>
07 Apr 2021 02:02:39,190 DEBUG: </close() on _data>
07 Apr 2021 02:02:39,190 DEBUG: <close() on _queue>
07 Apr 2021 02:02:39,190 DEBUG: </close() on _queue>
07 Apr 2021 02:02:39,190 DEBUG: <join() on _asyncThread>
07 Apr 2021 02:02:39,190 DEBUG: </join() on _asyncThread>
07 Apr 2021 02:02:39,190 DEBUG: <close() on org.labkey.api.data.ParameterMapStatement@430da1bb>
07 Apr 2021 02:02:39,190 DEBUG: </close() on org.labkey.api.data.ParameterMapStatement@430da1bb>
07 Apr 2021 02:02:39,190 DEBUG: <close() on org.labkey.api.data.ParameterMapStatement@4f26033d>
07 Apr 2021 02:02:39,190 DEBUG: </close() on org.labkey.api.data.ParameterMapStatement@4f26033d>
07 Apr 2021 02:02:39,190 DEBUG: </close()>
07 Apr 2021 02:02:39,221 INFO : emergency_contact_info: Processed 5 rows from dataset002.tsv
07 Apr 2021 02:02:39,221 INFO : emergency_contact_info: Deleted 5 rows
07 Apr 2021 02:02:39,221 INFO : emergency_contact_info: Merged 5 rows
07 Apr 2021 02:02:39,264 INFO : baseline_lab_data: Starting import from dataset003.tsv
07 Apr 2021 02:02:39,521 DEBUG: <next>
07 Apr 2021 02:02:39,522 DEBUG: <clear and set parameters on org.labkey.api.data.ParameterMapStatement@79072eb2>
07 Apr 2021 02:02:39,522 DEBUG: </clear and set parameters on org.labkey.api.data.ParameterMapStatement@79072eb2>
07 Apr 2021 02:02:39,522 DEBUG: </next>
07 Apr 2021 02:02:39,522 DEBUG: <next>
07 Apr 2021 02:02:39,522 DEBUG: <clear and set parameters on org.labkey.api.data.ParameterMapStatement@79072eb2>
07 Apr 2021 02:02:39,522 DEBUG: </clear and set parameters on org.labkey.api.data.ParameterMapStatement@79072eb2>
07 Apr 2021 02:02:39,522 DEBUG: </next>
07 Apr 2021 02:02:39,522 DEBUG: <next>
07 Apr 2021 02:02:39,523 DEBUG: <clear and set parameters on org.labkey.api.data.ParameterMapStatement@79072eb2>
07 Apr 2021 02:02:39,523 DEBUG: </clear and set parameters on org.labkey.api.data.ParameterMapStatement@79072eb2>
07 Apr 2021 02:02:39,523 DEBUG: </next>
07 Apr 2021 02:02:39,523 DEBUG: <next>
07 Apr 2021 02:02:39,523 DEBUG: <clear and set parameters on org.labkey.api.data.ParameterMapStatement@79072eb2>
07 Apr 2021 02:02:39,523 DEBUG: </clear and set parameters on org.labkey.api.data.ParameterMapStatement@79072eb2>
07 Apr 2021 02:02:39,523 DEBUG: </next>
07 Apr 2021 02:02:39,523 DEBUG: <next>
07 Apr 2021 02:02:39,523 DEBUG: <clear and set parameters on org.labkey.api.data.ParameterMapStatement@79072eb2>
07 Apr 2021 02:02:39,523 DEBUG: </clear and set parameters on org.labkey.api.data.ParameterMapStatement@79072eb2>
07 Apr 2021 02:02:39,524 DEBUG: </next>
07 Apr 2021 02:02:39,524 DEBUG: <next>
07 Apr 2021 02:02:39,524 DEBUG: <swap() - old: org.labkey.api.data.ParameterMapStatement@79072eb2>
07 Apr 2021 02:02:39,524 DEBUG: </swap() - new: org.labkey.api.data.ParameterMapStatement@6fb04848>
07 Apr 2021 02:02:39,524 DEBUG: <close() on _queue>
07 Apr 2021 02:02:39,524 DEBUG: <close() on _queue>
07 Apr 2021 02:02:39,524 DEBUG: </close() on _queue>
07 Apr 2021 02:02:39,524 DEBUG: <join() on _asyncThread>
07 Apr 2021 02:02:39,526 DEBUG: <executeBatch() on org.labkey.api.data.ParameterMapStatement@79072eb2>
07 Apr 2021 02:02:39,536 DEBUG: </executeBatch() on org.labkey.api.data.ParameterMapStatement@79072eb2>
07 Apr 2021 02:02:39,536 DEBUG: exit background thread
07 Apr 2021 02:02:39,536 DEBUG: </join() on _asyncThread>
07 Apr 2021 02:02:39,536 DEBUG: </next>
07 Apr 2021 02:02:39,536 DEBUG: <close()>
07 Apr 2021 02:02:39,536 DEBUG: <close() on _data>
07 Apr 2021 02:02:39,536 DEBUG: </close() on _data>
07 Apr 2021 02:02:39,536 DEBUG: <close() on _queue>
07 Apr 2021 02:02:39,536 DEBUG: </close() on _queue>
07 Apr 2021 02:02:39,537 DEBUG: <join() on _asyncThread>
07 Apr 2021 02:02:39,537 DEBUG: </join() on _asyncThread>
07 Apr 2021 02:02:39,537 DEBUG: <close() on org.labkey.api.data.ParameterMapStatement@79072eb2>
07 Apr 2021 02:02:39,537 DEBUG: </close() on org.labkey.api.data.ParameterMapStatement@79072eb2>
07 Apr 2021 02:02:39,537 DEBUG: <close() on org.labkey.api.data.ParameterMapStatement@6fb04848>
07 Apr 2021 02:02:39,537 DEBUG: </close() on org.labkey.api.data.ParameterMapStatement@6fb04848>
07 Apr 2021 02:02:39,537 DEBUG: </close()>
07 Apr 2021 02:02:39,555 INFO : baseline_lab_data: Processed 5 rows from dataset003.tsv
07 Apr 2021 02:02:39,555 INFO : baseline_lab_data: Deleted 5 rows
07 Apr 2021 02:02:39,555 INFO : baseline_lab_data: Merged 5 rows
07 Apr 2021 02:02:39,586 INFO : visit_blood_workup: Starting import from dataset004.tsv
07 Apr 2021 02:02:39,665 DEBUG: <next>
07 Apr 2021 02:02:39,666 DEBUG: <close() on _queue>
07 Apr 2021 02:02:39,666 DEBUG: <close() on _queue>
07 Apr 2021 02:02:39,666 DEBUG: </close() on _queue>
07 Apr 2021 02:02:39,666 DEBUG: <join() on _asyncThread>
07 Apr 2021 02:02:39,666 DEBUG: exit background thread
07 Apr 2021 02:02:39,666 DEBUG: </join() on _asyncThread>
07 Apr 2021 02:02:39,666 DEBUG: </next>
07 Apr 2021 02:02:39,666 DEBUG: <close()>
07 Apr 2021 02:02:39,666 DEBUG: <close() on _data>
07 Apr 2021 02:02:39,666 DEBUG: </close() on _data>
07 Apr 2021 02:02:39,666 DEBUG: <close() on _queue>
07 Apr 2021 02:02:39,666 DEBUG: </close() on _queue>
07 Apr 2021 02:02:39,666 DEBUG: <join() on _asyncThread>
07 Apr 2021 02:02:39,666 DEBUG: </join() on _asyncThread>
07 Apr 2021 02:02:39,666 DEBUG: <close() on org.labkey.api.data.ParameterMapStatement@6c2d0c56>
07 Apr 2021 02:02:39,666 DEBUG: </close() on org.labkey.api.data.ParameterMapStatement@6c2d0c56>
07 Apr 2021 02:02:39,667 DEBUG: <close() on org.labkey.api.data.ParameterMapStatement@1d4c3715>
07 Apr 2021 02:02:39,667 DEBUG: </close() on org.labkey.api.data.ParameterMapStatement@1d4c3715>
07 Apr 2021 02:02:39,667 DEBUG: </close()>
07 Apr 2021 02:02:39,706 INFO : completion_data: Starting import from dataset005.tsv
07 Apr 2021 02:02:39,760 DEBUG: <next>
07 Apr 2021 02:02:39,760 DEBUG: <close() on _queue>
07 Apr 2021 02:02:39,761 DEBUG: <close() on _queue>
07 Apr 2021 02:02:39,761 DEBUG: </close() on _queue>
07 Apr 2021 02:02:39,761 DEBUG: <join() on _asyncThread>
07 Apr 2021 02:02:39,768 DEBUG: exit background thread
07 Apr 2021 02:02:39,768 DEBUG: </join() on _asyncThread>
07 Apr 2021 02:02:39,769 DEBUG: </next>
07 Apr 2021 02:02:39,769 DEBUG: <close()>
07 Apr 2021 02:02:39,769 DEBUG: <close() on _data>
07 Apr 2021 02:02:39,769 DEBUG: </close() on _data>
07 Apr 2021 02:02:39,769 DEBUG: <close() on _queue>
07 Apr 2021 02:02:39,769 DEBUG: </close() on _queue>
07 Apr 2021 02:02:39,769 DEBUG: <join() on _asyncThread>
07 Apr 2021 02:02:39,769 DEBUG: </join() on _asyncThread>
07 Apr 2021 02:02:39,769 DEBUG: <close() on org.labkey.api.data.ParameterMapStatement@68662533>
07 Apr 2021 02:02:39,769 DEBUG: </close() on org.labkey.api.data.ParameterMapStatement@68662533>
07 Apr 2021 02:02:39,769 DEBUG: <close() on org.labkey.api.data.ParameterMapStatement@66fcd80d>
07 Apr 2021 02:02:39,769 DEBUG: </close() on org.labkey.api.data.ParameterMapStatement@66fcd80d>
07 Apr 2021 02:02:39,769 DEBUG: </close()>
07 Apr 2021 02:02:39,830 INFO : completion_project_questionnaire: Starting import from dataset006.tsv
07 Apr 2021 02:02:39,902 DEBUG: <next>
07 Apr 2021 02:02:39,902 DEBUG: <close() on _queue>
07 Apr 2021 02:02:39,902 DEBUG: <close() on _queue>
07 Apr 2021 02:02:39,902 DEBUG: </close() on _queue>
07 Apr 2021 02:02:39,903 DEBUG: <join() on _asyncThread>
07 Apr 2021 02:02:39,903 DEBUG: exit background thread
07 Apr 2021 02:02:39,903 DEBUG: </join() on _asyncThread>
07 Apr 2021 02:02:39,903 DEBUG: </next>
07 Apr 2021 02:02:39,903 DEBUG: <close()>
07 Apr 2021 02:02:39,903 DEBUG: <close() on _data>
07 Apr 2021 02:02:39,903 DEBUG: </close() on _data>
07 Apr 2021 02:02:39,903 DEBUG: <close() on _queue>
07 Apr 2021 02:02:39,903 DEBUG: </close() on _queue>
07 Apr 2021 02:02:39,903 DEBUG: <join() on _asyncThread>
07 Apr 2021 02:02:39,903 DEBUG: </join() on _asyncThread>
07 Apr 2021 02:02:39,903 DEBUG: <close() on org.labkey.api.data.ParameterMapStatement@3826046c>
07 Apr 2021 02:02:39,903 DEBUG: </close() on org.labkey.api.data.ParameterMapStatement@3826046c>
07 Apr 2021 02:02:39,903 DEBUG: <close() on org.labkey.api.data.ParameterMapStatement@6ebfb1f2>
07 Apr 2021 02:02:39,903 DEBUG: </close() on org.labkey.api.data.ParameterMapStatement@6ebfb1f2>
07 Apr 2021 02:02:39,903 DEBUG: </close()>
07 Apr 2021 02:02:39,908 INFO : Finish batch RedCap Integration.dataset
07 Apr 2021 02:02:39,914 INFO : Updating participant visits
07 Apr 2021 02:02:39,914 INFO : Updating participants
07 Apr 2021 02:02:39,920 INFO : Updating participant visit table
07 Apr 2021 02:02:39,994 INFO : Updating visit table
07 Apr 2021 02:02:39,997 INFO : Updating cohorts
07 Apr 2021 02:02:39,998 INFO : Clearing participant visit caches
07 Apr 2021 02:02:39,999 INFO : Finished updating participants
07 Apr 2021 02:02:40,000 INFO : Successfully completed task 'org.labkey.study.pipeline.StudyImportDatasetTask'
07 Apr 2021 02:02:40,110 INFO : Starting to run task 'org.labkey.api.specimen.pipeline.StudyImportSpecimenTask' at location 'webserver'
07 Apr 2021 02:02:40,110 INFO : Successfully completed task 'org.labkey.api.specimen.pipeline.StudyImportSpecimenTask'
07 Apr 2021 02:02:40,175 INFO : Starting to run task 'org.labkey.study.importer.StudyImportFinalTask' at location 'webserver'
07 Apr 2021 02:02:40,203 INFO : Loading dataset cohort assignments
07 Apr 2021 02:02:40,204 INFO : Done importing dataset cohort assignments
07 Apr 2021 02:02:40,272 INFO : Loading lists
07 Apr 2021 02:02:40,280 INFO : Truncating list: vbw8
07 Apr 2021 02:26:26,202 INFO : Recreating list: vbw8
07 Apr 2021 02:26:26,343 INFO : Truncating list: cpq13
07 Apr 2021 02:26:26,493 INFO : Recreating list: cpq13
07 Apr 2021 02:26:26,569 INFO : Truncating list: sex
07 Apr 2021 02:26:26,702 INFO : Recreating list: sex
07 Apr 2021 02:26:26,769 INFO : Truncating list: withdraw_reason
07 Apr 2021 02:26:26,919 INFO : Recreating list: withdraw_reason
07 Apr 2021 02:26:27,001 INFO : Truncating list: cpq6
07 Apr 2021 02:26:27,085 INFO : Recreating list: cpq6
07 Apr 2021 02:26:27,150 INFO : Truncating list: vbw9
07 Apr 2021 02:26:27,244 INFO : Recreating list: vbw9
07 Apr 2021 02:26:27,304 INFO : Truncating list: cpq8
07 Apr 2021 02:26:27,393 INFO : Recreating list: cpq8
07 Apr 2021 02:26:27,453 INFO : Truncating list: cpq10
07 Apr 2021 02:26:27,539 INFO : Recreating list: cpq10
07 Apr 2021 02:26:27,599 INFO : Truncating list: vbw6
07 Apr 2021 02:26:27,694 INFO : Recreating list: vbw6
07 Apr 2021 02:26:27,764 INFO : Truncating list: cpq11
07 Apr 2021 02:26:27,863 INFO : Recreating list: cpq11
07 Apr 2021 02:26:27,926 INFO : Truncating list: vbw7
07 Apr 2021 02:26:28,017 INFO : Recreating list: vbw7
07 Apr 2021 02:26:28,151 INFO : Merged 5 row(s) into list: withdraw_reason
07 Apr 2021 02:26:28,192 INFO : Merged 3 row(s) into list: cpq13
07 Apr 2021 02:26:28,231 INFO : Merged 6 row(s) into list: cpq11
07 Apr 2021 02:26:28,271 INFO : Merged 4 row(s) into list: cpq10
07 Apr 2021 02:26:28,311 INFO : Merged 2 row(s) into list: sex
07 Apr 2021 02:26:28,349 INFO : Merged 2 row(s) into list: vbw9
07 Apr 2021 02:26:28,393 INFO : Merged 3 row(s) into list: vbw8
07 Apr 2021 02:26:28,438 INFO : Merged 3 row(s) into list: cpq8
07 Apr 2021 02:26:28,457 INFO : Merged 4 row(s) into list: vbw7
07 Apr 2021 02:26:28,498 INFO : Merged 2 row(s) into list: vbw6
07 Apr 2021 02:26:28,537 INFO : Merged 5 row(s) into list: cpq6
07 Apr 2021 02:26:28,541 INFO : 11 lists imported successfully
07 Apr 2021 02:26:28,541 INFO : Done importing lists
07 Apr 2021 02:26:28,554 INFO : Post-processing queries
07 Apr 2021 02:26:28,554 INFO : Skipping query validation.
07 Apr 2021 02:26:28,554 INFO : Done post-processing queries
07 Apr 2021 02:26:28,565 INFO : Successfully completed task 'org.labkey.study.importer.StudyImportFinalTask'