05 May 2021 02:02:35,931 INFO : Starting to run task 'org.labkey.study.pipeline.StudyReloadSourceTask' at location 'webserver'
05 May 2021 02:02:35,931 INFO : Starting REDCap export
05 May 2021 02:02:36,871 INFO : Creating study archive
05 May 2021 02:02:36,872 INFO : Writing dataset metadata
05 May 2021 02:02:36,999 INFO : Creating column lookups
05 May 2021 02:02:37,776 WARN : Unable to locate subject id field: first_name for dataset: demographics row ignored.
05 May 2021 02:02:37,777 WARN : Unable to locate subject id field: first_name for dataset: demographics row ignored.
05 May 2021 02:02:37,777 WARN : Unable to locate subject id field: first_name for dataset: demographics row ignored.
05 May 2021 02:02:37,777 WARN : Unable to locate subject id field: first_name for dataset: demographics row ignored.
05 May 2021 02:02:37,777 WARN : Unable to locate subject id field: first_name for dataset: demographics row ignored.
05 May 2021 02:02:37,777 WARN : Unable to locate subject id field: first_name for dataset: demographics row ignored.
05 May 2021 02:02:37,777 WARN : Unable to locate subject id field: first_name for dataset: demographics row ignored.
05 May 2021 02:02:37,777 WARN : Unable to locate subject id field: first_name for dataset: demographics row ignored.
05 May 2021 02:02:37,778 WARN : Unable to locate subject id field: first_name for dataset: demographics row ignored.
05 May 2021 02:02:37,778 WARN : Unable to locate subject id field: first_name for dataset: demographics row ignored.
05 May 2021 02:02:37,778 WARN : Unable to locate subject id field: first_name for dataset: demographics row ignored.
05 May 2021 02:02:37,778 WARN : Unable to locate subject id field: first_name for dataset: demographics row ignored.
05 May 2021 02:02:37,778 WARN : Unable to locate subject id field: first_name for dataset: demographics row ignored.
05 May 2021 02:02:37,778 WARN : Unable to locate subject id field: first_name for dataset: demographics row ignored.
05 May 2021 02:02:37,778 WARN : Unable to locate subject id field: first_name for dataset: demographics row ignored.
05 May 2021 02:02:37,778 WARN : Unable to locate subject id field: first_name for dataset: demographics row ignored.
05 May 2021 02:02:37,778 WARN : Unable to locate subject id field: first_name for dataset: demographics row ignored.
05 May 2021 02:02:37,778 WARN : Unable to locate subject id field: first_name for dataset: demographics row ignored.
05 May 2021 02:02:37,778 WARN : Unable to locate subject id field: first_name for dataset: demographics row ignored.
05 May 2021 02:02:37,778 WARN : Unable to locate subject id field: first_name for dataset: emergency_contact_info row ignored.
05 May 2021 02:02:37,778 WARN : Unable to locate subject id field: first_name for dataset: emergency_contact_info row ignored.
05 May 2021 02:02:37,778 WARN : Unable to locate subject id field: first_name for dataset: emergency_contact_info row ignored.
05 May 2021 02:02:37,778 WARN : Unable to locate subject id field: first_name for dataset: emergency_contact_info row ignored.
05 May 2021 02:02:37,778 WARN : Unable to locate subject id field: first_name for dataset: emergency_contact_info row ignored.
05 May 2021 02:02:37,779 WARN : Unable to locate subject id field: first_name for dataset: emergency_contact_info row ignored.
05 May 2021 02:02:37,779 WARN : Unable to locate subject id field: first_name for dataset: emergency_contact_info row ignored.
05 May 2021 02:02:37,779 WARN : Unable to locate subject id field: first_name for dataset: emergency_contact_info row ignored.
05 May 2021 02:02:37,779 WARN : Unable to locate subject id field: first_name for dataset: emergency_contact_info row ignored.
05 May 2021 02:02:37,779 WARN : Unable to locate subject id field: first_name for dataset: emergency_contact_info row ignored.
05 May 2021 02:02:37,779 WARN : Unable to locate subject id field: first_name for dataset: emergency_contact_info row ignored.
05 May 2021 02:02:37,779 WARN : Unable to locate subject id field: first_name for dataset: emergency_contact_info row ignored.
05 May 2021 02:02:37,779 WARN : Unable to locate subject id field: first_name for dataset: emergency_contact_info row ignored.
05 May 2021 02:02:37,779 WARN : Unable to locate subject id field: first_name for dataset: emergency_contact_info row ignored.
05 May 2021 02:02:37,779 WARN : Unable to locate subject id field: first_name for dataset: emergency_contact_info row ignored.
05 May 2021 02:02:37,779 WARN : Unable to locate subject id field: first_name for dataset: emergency_contact_info row ignored.
05 May 2021 02:02:37,779 WARN : Unable to locate subject id field: first_name for dataset: emergency_contact_info row ignored.
05 May 2021 02:02:37,779 WARN : Unable to locate subject id field: first_name for dataset: emergency_contact_info row ignored.
05 May 2021 02:02:37,785 WARN : Unable to locate subject id field: first_name for dataset: emergency_contact_info row ignored.
05 May 2021 02:02:37,785 WARN : Unable to locate subject id field: first_name for dataset: baseline_lab_data row ignored.
05 May 2021 02:02:37,787 WARN : Unable to locate subject id field: first_name for dataset: baseline_lab_data row ignored.
05 May 2021 02:02:37,787 WARN : Unable to locate subject id field: first_name for dataset: baseline_lab_data row ignored.
05 May 2021 02:02:37,787 WARN : Unable to locate subject id field: first_name for dataset: baseline_lab_data row ignored.
05 May 2021 02:02:37,787 WARN : Unable to locate subject id field: first_name for dataset: baseline_lab_data row ignored.
05 May 2021 02:02:37,787 WARN : Unable to locate subject id field: first_name for dataset: baseline_lab_data row ignored.
05 May 2021 02:02:37,787 WARN : Unable to locate subject id field: first_name for dataset: baseline_lab_data row ignored.
05 May 2021 02:02:37,787 WARN : Unable to locate subject id field: first_name for dataset: baseline_lab_data row ignored.
05 May 2021 02:02:37,787 WARN : Unable to locate subject id field: first_name for dataset: baseline_lab_data row ignored.
05 May 2021 02:02:37,787 WARN : Unable to locate subject id field: first_name for dataset: baseline_lab_data row ignored.
05 May 2021 02:02:37,787 WARN : Unable to locate subject id field: first_name for dataset: baseline_lab_data row ignored.
05 May 2021 02:02:37,787 WARN : Unable to locate subject id field: first_name for dataset: baseline_lab_data row ignored.
05 May 2021 02:02:37,787 WARN : Unable to locate subject id field: first_name for dataset: baseline_lab_data row ignored.
05 May 2021 02:02:37,787 WARN : Unable to locate subject id field: first_name for dataset: baseline_lab_data row ignored.
05 May 2021 02:02:37,787 WARN : Unable to locate subject id field: first_name for dataset: baseline_lab_data row ignored.
05 May 2021 02:02:37,787 WARN : Unable to locate subject id field: first_name for dataset: baseline_lab_data row ignored.
05 May 2021 02:02:37,787 WARN : Unable to locate subject id field: first_name for dataset: baseline_lab_data row ignored.
05 May 2021 02:02:37,788 WARN : Unable to locate subject id field: first_name for dataset: baseline_lab_data row ignored.
05 May 2021 02:02:37,788 WARN : Unable to locate subject id field: first_name for dataset: baseline_lab_data row ignored.
05 May 2021 02:02:37,788 WARN : Unable to locate subject id field: first_name for dataset: visit_blood_workup row ignored.
05 May 2021 02:02:37,788 WARN : Unable to locate subject id field: first_name for dataset: visit_blood_workup row ignored.
05 May 2021 02:02:37,788 WARN : Unable to locate subject id field: first_name for dataset: visit_blood_workup row ignored.
05 May 2021 02:02:37,788 WARN : Unable to locate subject id field: first_name for dataset: visit_blood_workup row ignored.
05 May 2021 02:02:37,788 WARN : Unable to locate subject id field: first_name for dataset: visit_blood_workup row ignored.
05 May 2021 02:02:37,788 WARN : Unable to locate subject id field: first_name for dataset: visit_blood_workup row ignored.
05 May 2021 02:02:37,788 WARN : Unable to locate subject id field: first_name for dataset: visit_blood_workup row ignored.
05 May 2021 02:02:37,788 WARN : Unable to locate subject id field: first_name for dataset: visit_blood_workup row ignored.
05 May 2021 02:02:37,788 WARN : Unable to locate subject id field: first_name for dataset: visit_blood_workup row ignored.
05 May 2021 02:02:37,788 WARN : Unable to locate subject id field: first_name for dataset: visit_blood_workup row ignored.
05 May 2021 02:02:37,789 WARN : Unable to locate subject id field: first_name for dataset: visit_blood_workup row ignored.
05 May 2021 02:02:37,789 WARN : Unable to locate subject id field: first_name for dataset: visit_blood_workup row ignored.
05 May 2021 02:02:37,789 WARN : Unable to locate subject id field: first_name for dataset: visit_blood_workup row ignored.
05 May 2021 02:02:37,789 WARN : Unable to locate subject id field: first_name for dataset: visit_blood_workup row ignored.
05 May 2021 02:02:37,790 WARN : Unable to locate subject id field: first_name for dataset: visit_blood_workup row ignored.
05 May 2021 02:02:37,790 WARN : Unable to locate subject id field: first_name for dataset: visit_blood_workup row ignored.
05 May 2021 02:02:37,791 WARN : Unable to locate subject id field: first_name for dataset: visit_blood_workup row ignored.
05 May 2021 02:02:37,791 WARN : Unable to locate subject id field: first_name for dataset: visit_blood_workup row ignored.
05 May 2021 02:02:37,791 WARN : Unable to locate subject id field: first_name for dataset: completion_data row ignored.
05 May 2021 02:02:37,791 WARN : Unable to locate subject id field: first_name for dataset: completion_data row ignored.
05 May 2021 02:02:37,791 WARN : Unable to locate subject id field: first_name for dataset: completion_data row ignored.
05 May 2021 02:02:37,791 WARN : Unable to locate subject id field: first_name for dataset: completion_data row ignored.
05 May 2021 02:02:37,791 WARN : Unable to locate subject id field: first_name for dataset: completion_data row ignored.
05 May 2021 02:02:37,791 WARN : Unable to locate subject id field: first_name for dataset: completion_data row ignored.
05 May 2021 02:02:37,791 WARN : Unable to locate subject id field: first_name for dataset: completion_data row ignored.
05 May 2021 02:02:37,792 WARN : Unable to locate subject id field: first_name for dataset: completion_data row ignored.
05 May 2021 02:02:37,792 WARN : Unable to locate subject id field: first_name for dataset: completion_data row ignored.
05 May 2021 02:02:37,792 WARN : Unable to locate subject id field: first_name for dataset: completion_data row ignored.
05 May 2021 02:02:37,792 WARN : Unable to locate subject id field: first_name for dataset: completion_data row ignored.
05 May 2021 02:02:37,792 WARN : Unable to locate subject id field: first_name for dataset: completion_data row ignored.
05 May 2021 02:02:37,792 WARN : Unable to locate subject id field: first_name for dataset: completion_data row ignored.
05 May 2021 02:02:37,792 WARN : Unable to locate subject id field: first_name for dataset: completion_data row ignored.
05 May 2021 02:02:37,792 WARN : Unable to locate subject id field: first_name for dataset: completion_data row ignored.
05 May 2021 02:02:37,792 WARN : Unable to locate subject id field: first_name for dataset: completion_data row ignored.
05 May 2021 02:02:37,792 WARN : Unable to locate subject id field: first_name for dataset: completion_data row ignored.
05 May 2021 02:02:37,792 WARN : Unable to locate subject id field: first_name for dataset: completion_data row ignored.
05 May 2021 02:02:37,793 WARN : Unable to locate subject id field: first_name for dataset: completion_data row ignored.
05 May 2021 02:02:37,793 WARN : Unable to locate subject id field: first_name for dataset: completion_project_questionnaire row ignored.
05 May 2021 02:02:37,793 WARN : Unable to locate subject id field: first_name for dataset: completion_project_questionnaire row ignored.
05 May 2021 02:02:37,793 WARN : Unable to locate subject id field: first_name for dataset: completion_project_questionnaire row ignored.
05 May 2021 02:02:37,793 WARN : Unable to locate subject id field: first_name for dataset: completion_project_questionnaire row ignored.
05 May 2021 02:02:37,793 WARN : Unable to locate subject id field: first_name for dataset: completion_project_questionnaire row ignored.
05 May 2021 02:02:37,793 WARN : Unable to locate subject id field: first_name for dataset: completion_project_questionnaire row ignored.
05 May 2021 02:02:37,793 WARN : Unable to locate subject id field: first_name for dataset: completion_project_questionnaire row ignored.
05 May 2021 02:02:37,793 WARN : Unable to locate subject id field: first_name for dataset: completion_project_questionnaire row ignored.
05 May 2021 02:02:37,793 WARN : Unable to locate subject id field: first_name for dataset: completion_project_questionnaire row ignored.
05 May 2021 02:02:37,793 WARN : Unable to locate subject id field: first_name for dataset: completion_project_questionnaire row ignored.
05 May 2021 02:02:37,793 WARN : Unable to locate subject id field: first_name for dataset: completion_project_questionnaire row ignored.
05 May 2021 02:02:37,793 WARN : Unable to locate subject id field: first_name for dataset: completion_project_questionnaire row ignored.
05 May 2021 02:02:37,793 WARN : Unable to locate subject id field: first_name for dataset: completion_project_questionnaire row ignored.
05 May 2021 02:02:37,793 WARN : Unable to locate subject id field: first_name for dataset: completion_project_questionnaire row ignored.
05 May 2021 02:02:37,793 WARN : Unable to locate subject id field: first_name for dataset: completion_project_questionnaire row ignored.
05 May 2021 02:02:37,793 WARN : Unable to locate subject id field: first_name for dataset: completion_project_questionnaire row ignored.
05 May 2021 02:02:37,793 WARN : Unable to locate subject id field: first_name for dataset: completion_project_questionnaire row ignored.
05 May 2021 02:02:37,793 WARN : Unable to locate subject id field: first_name for dataset: completion_project_questionnaire row ignored.
05 May 2021 02:02:37,793 WARN : Unable to locate subject id field: first_name for dataset: completion_project_questionnaire row ignored.
05 May 2021 02:02:37,797 INFO : Finished creating study archive
05 May 2021 02:02:37,797 INFO : Successfully completed task 'org.labkey.study.pipeline.StudyReloadSourceTask'
05 May 2021 02:02:37,852 INFO : Starting to run task 'org.labkey.study.importer.StudyImportInitialTask' at location 'webserver'
05 May 2021 02:02:37,856 INFO : Reloading study from study.xml
05 May 2021 02:02:37,861 INFO : Loading top-level study properties (label, start/end date, description, etc.)
05 May 2021 02:02:38,217 INFO : Done importing top-level study properties (label, start/end date, description, etc.)
05 May 2021 02:02:38,241 INFO : Loading datasets manifest from datasets_manifest.xml
05 May 2021 02:02:38,243 INFO : Loading dataset schema from datasets_metadata.xml
05 May 2021 02:02:39,249 INFO : Successfully completed task 'org.labkey.study.importer.StudyImportInitialTask'
05 May 2021 02:02:39,307 INFO : Starting to run task 'org.labkey.study.pipeline.StudyImportDatasetTask' at location 'webserver'
05 May 2021 02:02:39,308 INFO : Start batch RedCap Integration.dataset
05 May 2021 02:02:39,375 INFO : demographics: Starting import from dataset001.tsv
05 May 2021 02:02:39,670 DEBUG: <next>
05 May 2021 02:02:39,671 DEBUG: <clear and set parameters on org.labkey.api.data.ParameterMapStatement@94e41cc>
05 May 2021 02:02:39,672 DEBUG: </clear and set parameters on org.labkey.api.data.ParameterMapStatement@94e41cc>
05 May 2021 02:02:39,672 DEBUG: </next>
05 May 2021 02:02:39,672 DEBUG: <next>
05 May 2021 02:02:39,672 DEBUG: <clear and set parameters on org.labkey.api.data.ParameterMapStatement@94e41cc>
05 May 2021 02:02:39,672 DEBUG: </clear and set parameters on org.labkey.api.data.ParameterMapStatement@94e41cc>
05 May 2021 02:02:39,672 DEBUG: </next>
05 May 2021 02:02:39,672 DEBUG: <next>
05 May 2021 02:02:39,673 DEBUG: <clear and set parameters on org.labkey.api.data.ParameterMapStatement@94e41cc>
05 May 2021 02:02:39,673 DEBUG: </clear and set parameters on org.labkey.api.data.ParameterMapStatement@94e41cc>
05 May 2021 02:02:39,673 DEBUG: </next>
05 May 2021 02:02:39,673 DEBUG: <next>
05 May 2021 02:02:39,673 DEBUG: <clear and set parameters on org.labkey.api.data.ParameterMapStatement@94e41cc>
05 May 2021 02:02:39,673 DEBUG: </clear and set parameters on org.labkey.api.data.ParameterMapStatement@94e41cc>
05 May 2021 02:02:39,673 DEBUG: </next>
05 May 2021 02:02:39,673 DEBUG: <next>
05 May 2021 02:02:39,674 DEBUG: <clear and set parameters on org.labkey.api.data.ParameterMapStatement@94e41cc>
05 May 2021 02:02:39,674 DEBUG: </clear and set parameters on org.labkey.api.data.ParameterMapStatement@94e41cc>
05 May 2021 02:02:39,674 DEBUG: </next>
05 May 2021 02:02:39,674 DEBUG: <next>
05 May 2021 02:02:39,674 DEBUG: <swap() - old: org.labkey.api.data.ParameterMapStatement@94e41cc>
05 May 2021 02:02:39,678 DEBUG: </swap() - new: org.labkey.api.data.ParameterMapStatement@322daaee>
05 May 2021 02:02:39,678 DEBUG: <executeBatch() on org.labkey.api.data.ParameterMapStatement@94e41cc>
05 May 2021 02:02:39,678 DEBUG: <close() on _queue>
05 May 2021 02:02:39,678 DEBUG: <close() on _queue>
05 May 2021 02:02:39,679 DEBUG: </close() on _queue>
05 May 2021 02:02:39,679 DEBUG: <join() on _asyncThread>
05 May 2021 02:02:39,688 DEBUG: </executeBatch() on org.labkey.api.data.ParameterMapStatement@94e41cc>
05 May 2021 02:02:39,688 DEBUG: exit background thread
05 May 2021 02:02:39,689 DEBUG: </join() on _asyncThread>
05 May 2021 02:02:39,689 DEBUG: </next>
05 May 2021 02:02:39,689 DEBUG: <close()>
05 May 2021 02:02:39,689 DEBUG: <close() on _data>
05 May 2021 02:02:39,689 DEBUG: </close() on _data>
05 May 2021 02:02:39,689 DEBUG: <close() on _queue>
05 May 2021 02:02:39,689 DEBUG: </close() on _queue>
05 May 2021 02:02:39,689 DEBUG: <join() on _asyncThread>
05 May 2021 02:02:39,689 DEBUG: </join() on _asyncThread>
05 May 2021 02:02:39,689 DEBUG: <close() on org.labkey.api.data.ParameterMapStatement@94e41cc>
05 May 2021 02:02:39,690 DEBUG: </close() on org.labkey.api.data.ParameterMapStatement@94e41cc>
05 May 2021 02:02:39,690 DEBUG: <close() on org.labkey.api.data.ParameterMapStatement@322daaee>
05 May 2021 02:02:39,690 DEBUG: </close() on org.labkey.api.data.ParameterMapStatement@322daaee>
05 May 2021 02:02:39,690 DEBUG: </close()>
05 May 2021 02:02:39,715 INFO : demographics: Processed 5 rows from dataset001.tsv
05 May 2021 02:02:39,715 INFO : demographics: Deleted 5 rows
05 May 2021 02:02:39,715 INFO : demographics: Merged 5 rows
05 May 2021 02:02:39,744 INFO : emergency_contact_info: Starting import from dataset002.tsv
05 May 2021 02:02:40,010 DEBUG: <next>
05 May 2021 02:02:40,011 DEBUG: <clear and set parameters on org.labkey.api.data.ParameterMapStatement@848027f>
05 May 2021 02:02:40,011 DEBUG: </clear and set parameters on org.labkey.api.data.ParameterMapStatement@848027f>
05 May 2021 02:02:40,011 DEBUG: </next>
05 May 2021 02:02:40,011 DEBUG: <next>
05 May 2021 02:02:40,011 DEBUG: <clear and set parameters on org.labkey.api.data.ParameterMapStatement@848027f>
05 May 2021 02:02:40,011 DEBUG: </clear and set parameters on org.labkey.api.data.ParameterMapStatement@848027f>
05 May 2021 02:02:40,011 DEBUG: </next>
05 May 2021 02:02:40,011 DEBUG: <next>
05 May 2021 02:02:40,011 DEBUG: <clear and set parameters on org.labkey.api.data.ParameterMapStatement@848027f>
05 May 2021 02:02:40,011 DEBUG: </clear and set parameters on org.labkey.api.data.ParameterMapStatement@848027f>
05 May 2021 02:02:40,011 DEBUG: </next>
05 May 2021 02:02:40,011 DEBUG: <next>
05 May 2021 02:02:40,012 DEBUG: <clear and set parameters on org.labkey.api.data.ParameterMapStatement@848027f>
05 May 2021 02:02:40,012 DEBUG: </clear and set parameters on org.labkey.api.data.ParameterMapStatement@848027f>
05 May 2021 02:02:40,012 DEBUG: </next>
05 May 2021 02:02:40,012 DEBUG: <next>
05 May 2021 02:02:40,012 DEBUG: <clear and set parameters on org.labkey.api.data.ParameterMapStatement@848027f>
05 May 2021 02:02:40,012 DEBUG: </clear and set parameters on org.labkey.api.data.ParameterMapStatement@848027f>
05 May 2021 02:02:40,012 DEBUG: </next>
05 May 2021 02:02:40,012 DEBUG: <next>
05 May 2021 02:02:40,012 DEBUG: <swap() - old: org.labkey.api.data.ParameterMapStatement@848027f>
05 May 2021 02:02:40,012 DEBUG: </swap() - new: org.labkey.api.data.ParameterMapStatement@1418e53f>
05 May 2021 02:02:40,012 DEBUG: <close() on _queue>
05 May 2021 02:02:40,012 DEBUG: <close() on _queue>
05 May 2021 02:02:40,012 DEBUG: </close() on _queue>
05 May 2021 02:02:40,012 DEBUG: <executeBatch() on org.labkey.api.data.ParameterMapStatement@848027f>
05 May 2021 02:02:40,012 DEBUG: <join() on _asyncThread>
05 May 2021 02:02:40,035 DEBUG: </executeBatch() on org.labkey.api.data.ParameterMapStatement@848027f>
05 May 2021 02:02:40,035 DEBUG: exit background thread
05 May 2021 02:02:40,035 DEBUG: </join() on _asyncThread>
05 May 2021 02:02:40,035 DEBUG: </next>
05 May 2021 02:02:40,035 DEBUG: <close()>
05 May 2021 02:02:40,035 DEBUG: <close() on _data>
05 May 2021 02:02:40,035 DEBUG: </close() on _data>
05 May 2021 02:02:40,036 DEBUG: <close() on _queue>
05 May 2021 02:02:40,036 DEBUG: </close() on _queue>
05 May 2021 02:02:40,036 DEBUG: <join() on _asyncThread>
05 May 2021 02:02:40,036 DEBUG: </join() on _asyncThread>
05 May 2021 02:02:40,036 DEBUG: <close() on org.labkey.api.data.ParameterMapStatement@848027f>
05 May 2021 02:02:40,036 DEBUG: </close() on org.labkey.api.data.ParameterMapStatement@848027f>
05 May 2021 02:02:40,036 DEBUG: <close() on org.labkey.api.data.ParameterMapStatement@1418e53f>
05 May 2021 02:02:40,036 DEBUG: </close() on org.labkey.api.data.ParameterMapStatement@1418e53f>
05 May 2021 02:02:40,036 DEBUG: </close()>
05 May 2021 02:02:40,060 INFO : emergency_contact_info: Processed 5 rows from dataset002.tsv
05 May 2021 02:02:40,060 INFO : emergency_contact_info: Deleted 5 rows
05 May 2021 02:02:40,060 INFO : emergency_contact_info: Merged 5 rows
05 May 2021 02:02:40,092 INFO : baseline_lab_data: Starting import from dataset003.tsv
05 May 2021 02:02:40,308 DEBUG: <next>
05 May 2021 02:02:40,308 DEBUG: <clear and set parameters on org.labkey.api.data.ParameterMapStatement@7a184552>
05 May 2021 02:02:40,308 DEBUG: </clear and set parameters on org.labkey.api.data.ParameterMapStatement@7a184552>
05 May 2021 02:02:40,308 DEBUG: </next>
05 May 2021 02:02:40,309 DEBUG: <next>
05 May 2021 02:02:40,309 DEBUG: <clear and set parameters on org.labkey.api.data.ParameterMapStatement@7a184552>
05 May 2021 02:02:40,309 DEBUG: </clear and set parameters on org.labkey.api.data.ParameterMapStatement@7a184552>
05 May 2021 02:02:40,309 DEBUG: </next>
05 May 2021 02:02:40,309 DEBUG: <next>
05 May 2021 02:02:40,309 DEBUG: <clear and set parameters on org.labkey.api.data.ParameterMapStatement@7a184552>
05 May 2021 02:02:40,309 DEBUG: </clear and set parameters on org.labkey.api.data.ParameterMapStatement@7a184552>
05 May 2021 02:02:40,309 DEBUG: </next>
05 May 2021 02:02:40,309 DEBUG: <next>
05 May 2021 02:02:40,309 DEBUG: <clear and set parameters on org.labkey.api.data.ParameterMapStatement@7a184552>
05 May 2021 02:02:40,309 DEBUG: </clear and set parameters on org.labkey.api.data.ParameterMapStatement@7a184552>
05 May 2021 02:02:40,310 DEBUG: </next>
05 May 2021 02:02:40,310 DEBUG: <next>
05 May 2021 02:02:40,310 DEBUG: <clear and set parameters on org.labkey.api.data.ParameterMapStatement@7a184552>
05 May 2021 02:02:40,310 DEBUG: </clear and set parameters on org.labkey.api.data.ParameterMapStatement@7a184552>
05 May 2021 02:02:40,310 DEBUG: </next>
05 May 2021 02:02:40,310 DEBUG: <next>
05 May 2021 02:02:40,310 DEBUG: <swap() - old: org.labkey.api.data.ParameterMapStatement@7a184552>
05 May 2021 02:02:40,310 DEBUG: </swap() - new: org.labkey.api.data.ParameterMapStatement@5cc7ab7b>
05 May 2021 02:02:40,310 DEBUG: <close() on _queue>
05 May 2021 02:02:40,310 DEBUG: <close() on _queue>
05 May 2021 02:02:40,310 DEBUG: <executeBatch() on org.labkey.api.data.ParameterMapStatement@7a184552>
05 May 2021 02:02:40,310 DEBUG: </close() on _queue>
05 May 2021 02:02:40,310 DEBUG: <join() on _asyncThread>
05 May 2021 02:02:40,321 DEBUG: </executeBatch() on org.labkey.api.data.ParameterMapStatement@7a184552>
05 May 2021 02:02:40,321 DEBUG: exit background thread
05 May 2021 02:02:40,322 DEBUG: </join() on _asyncThread>
05 May 2021 02:02:40,322 DEBUG: </next>
05 May 2021 02:02:40,322 DEBUG: <close()>
05 May 2021 02:02:40,322 DEBUG: <close() on _data>
05 May 2021 02:02:40,322 DEBUG: </close() on _data>
05 May 2021 02:02:40,322 DEBUG: <close() on _queue>
05 May 2021 02:02:40,322 DEBUG: </close() on _queue>
05 May 2021 02:02:40,322 DEBUG: <join() on _asyncThread>
05 May 2021 02:02:40,322 DEBUG: </join() on _asyncThread>
05 May 2021 02:02:40,322 DEBUG: <close() on org.labkey.api.data.ParameterMapStatement@7a184552>
05 May 2021 02:02:40,323 DEBUG: </close() on org.labkey.api.data.ParameterMapStatement@7a184552>
05 May 2021 02:02:40,323 DEBUG: <close() on org.labkey.api.data.ParameterMapStatement@5cc7ab7b>
05 May 2021 02:02:40,323 DEBUG: </close() on org.labkey.api.data.ParameterMapStatement@5cc7ab7b>
05 May 2021 02:02:40,323 DEBUG: </close()>
05 May 2021 02:02:40,345 INFO : baseline_lab_data: Processed 5 rows from dataset003.tsv
05 May 2021 02:02:40,345 INFO : baseline_lab_data: Deleted 5 rows
05 May 2021 02:02:40,345 INFO : baseline_lab_data: Merged 5 rows
05 May 2021 02:02:40,384 INFO : visit_blood_workup: Starting import from dataset004.tsv
05 May 2021 02:02:40,438 DEBUG: <next>
05 May 2021 02:02:40,438 DEBUG: <close() on _queue>
05 May 2021 02:02:40,438 DEBUG: <close() on _queue>
05 May 2021 02:02:40,438 DEBUG: </close() on _queue>
05 May 2021 02:02:40,438 DEBUG: <join() on _asyncThread>
05 May 2021 02:02:40,438 DEBUG: exit background thread
05 May 2021 02:02:40,438 DEBUG: </join() on _asyncThread>
05 May 2021 02:02:40,438 DEBUG: </next>
05 May 2021 02:02:40,439 DEBUG: <close()>
05 May 2021 02:02:40,439 DEBUG: <close() on _data>
05 May 2021 02:02:40,439 DEBUG: </close() on _data>
05 May 2021 02:02:40,439 DEBUG: <close() on _queue>
05 May 2021 02:02:40,439 DEBUG: </close() on _queue>
05 May 2021 02:02:40,439 DEBUG: <join() on _asyncThread>
05 May 2021 02:02:40,439 DEBUG: </join() on _asyncThread>
05 May 2021 02:02:40,439 DEBUG: <close() on org.labkey.api.data.ParameterMapStatement@6a5bf6b3>
05 May 2021 02:02:40,439 DEBUG: </close() on org.labkey.api.data.ParameterMapStatement@6a5bf6b3>
05 May 2021 02:02:40,439 DEBUG: <close() on org.labkey.api.data.ParameterMapStatement@747eff75>
05 May 2021 02:02:40,439 DEBUG: </close() on org.labkey.api.data.ParameterMapStatement@747eff75>
05 May 2021 02:02:40,439 DEBUG: </close()>
05 May 2021 02:02:40,494 INFO : completion_data: Starting import from dataset005.tsv
05 May 2021 02:02:40,556 DEBUG: <next>
05 May 2021 02:02:40,556 DEBUG: <close() on _queue>
05 May 2021 02:02:40,556 DEBUG: <close() on _queue>
05 May 2021 02:02:40,556 DEBUG: </close() on _queue>
05 May 2021 02:02:40,556 DEBUG: <join() on _asyncThread>
05 May 2021 02:02:40,558 DEBUG: exit background thread
05 May 2021 02:02:40,558 DEBUG: </join() on _asyncThread>
05 May 2021 02:02:40,558 DEBUG: </next>
05 May 2021 02:02:40,558 DEBUG: <close()>
05 May 2021 02:02:40,558 DEBUG: <close() on _data>
05 May 2021 02:02:40,558 DEBUG: </close() on _data>
05 May 2021 02:02:40,558 DEBUG: <close() on _queue>
05 May 2021 02:02:40,558 DEBUG: </close() on _queue>
05 May 2021 02:02:40,558 DEBUG: <join() on _asyncThread>
05 May 2021 02:02:40,558 DEBUG: </join() on _asyncThread>
05 May 2021 02:02:40,559 DEBUG: <close() on org.labkey.api.data.ParameterMapStatement@7bf7a0e0>
05 May 2021 02:02:40,559 DEBUG: </close() on org.labkey.api.data.ParameterMapStatement@7bf7a0e0>
05 May 2021 02:02:40,559 DEBUG: <close() on org.labkey.api.data.ParameterMapStatement@790b5ae9>
05 May 2021 02:02:40,559 DEBUG: </close() on org.labkey.api.data.ParameterMapStatement@790b5ae9>
05 May 2021 02:02:40,559 DEBUG: </close()>
05 May 2021 02:02:40,598 INFO : completion_project_questionnaire: Starting import from dataset006.tsv
05 May 2021 02:02:40,672 DEBUG: <next>
05 May 2021 02:02:40,673 DEBUG: <close() on _queue>
05 May 2021 02:02:40,673 DEBUG: <close() on _queue>
05 May 2021 02:02:40,673 DEBUG: </close() on _queue>
05 May 2021 02:02:40,673 DEBUG: <join() on _asyncThread>
05 May 2021 02:02:40,673 DEBUG: exit background thread
05 May 2021 02:02:40,673 DEBUG: </join() on _asyncThread>
05 May 2021 02:02:40,673 DEBUG: </next>
05 May 2021 02:02:40,673 DEBUG: <close()>
05 May 2021 02:02:40,673 DEBUG: <close() on _data>
05 May 2021 02:02:40,673 DEBUG: </close() on _data>
05 May 2021 02:02:40,673 DEBUG: <close() on _queue>
05 May 2021 02:02:40,673 DEBUG: </close() on _queue>
05 May 2021 02:02:40,673 DEBUG: <join() on _asyncThread>
05 May 2021 02:02:40,673 DEBUG: </join() on _asyncThread>
05 May 2021 02:02:40,673 DEBUG: <close() on org.labkey.api.data.ParameterMapStatement@3afe4ecb>
05 May 2021 02:02:40,673 DEBUG: </close() on org.labkey.api.data.ParameterMapStatement@3afe4ecb>
05 May 2021 02:02:40,673 DEBUG: <close() on org.labkey.api.data.ParameterMapStatement@12050ea2>
05 May 2021 02:02:40,673 DEBUG: </close() on org.labkey.api.data.ParameterMapStatement@12050ea2>
05 May 2021 02:02:40,673 DEBUG: </close()>
05 May 2021 02:02:40,678 INFO : Finish batch RedCap Integration.dataset
05 May 2021 02:02:40,685 INFO : Updating participant visits
05 May 2021 02:02:40,686 INFO : Updating participants
05 May 2021 02:02:40,693 INFO : Updating participant visit table
05 May 2021 02:02:40,806 INFO : Updating visit table
05 May 2021 02:02:40,816 INFO : Updating cohorts
05 May 2021 02:02:40,816 INFO : Clearing participant visit caches
05 May 2021 02:02:40,820 INFO : Finished updating participants
05 May 2021 02:02:40,821 INFO : Successfully completed task 'org.labkey.study.pipeline.StudyImportDatasetTask'
05 May 2021 02:02:40,881 INFO : Starting to run task 'org.labkey.api.specimen.pipeline.StudyImportSpecimenTask' at location 'webserver'
05 May 2021 02:02:40,881 INFO : Successfully completed task 'org.labkey.api.specimen.pipeline.StudyImportSpecimenTask'
05 May 2021 02:02:40,923 INFO : Starting to run task 'org.labkey.study.importer.StudyImportFinalTask' at location 'webserver'
05 May 2021 02:02:40,956 INFO : Loading dataset cohort assignments
05 May 2021 02:02:40,957 INFO : Done importing dataset cohort assignments
05 May 2021 02:02:41,033 INFO : Loading lists
05 May 2021 02:02:41,037 INFO : Truncating list: vbw8
05 May 2021 02:24:27,044 INFO : Recreating list: vbw8
05 May 2021 02:24:27,250 INFO : Truncating list: cpq13
05 May 2021 02:24:27,387 INFO : Recreating list: cpq13
05 May 2021 02:24:27,477 INFO : Truncating list: sex
05 May 2021 02:24:27,578 INFO : Recreating list: sex
05 May 2021 02:24:27,685 INFO : Truncating list: withdraw_reason
05 May 2021 02:24:27,784 INFO : Recreating list: withdraw_reason
05 May 2021 02:24:27,873 INFO : Truncating list: cpq6
05 May 2021 02:24:27,965 INFO : Recreating list: cpq6
05 May 2021 02:24:28,052 INFO : Truncating list: vbw9
05 May 2021 02:24:28,146 INFO : Recreating list: vbw9
05 May 2021 02:24:28,229 INFO : Truncating list: cpq8
05 May 2021 02:24:28,316 INFO : Recreating list: cpq8
05 May 2021 02:24:28,393 INFO : Truncating list: cpq10
05 May 2021 02:24:28,483 INFO : Recreating list: cpq10
05 May 2021 02:24:28,559 INFO : Truncating list: vbw6
05 May 2021 02:24:28,647 INFO : Recreating list: vbw6
05 May 2021 02:24:28,724 INFO : Truncating list: cpq11
05 May 2021 02:24:28,816 INFO : Recreating list: cpq11
05 May 2021 02:24:28,897 INFO : Truncating list: vbw7
05 May 2021 02:24:28,993 INFO : Recreating list: vbw7
05 May 2021 02:24:29,151 INFO : Merged 5 row(s) into list: withdraw_reason
05 May 2021 02:24:29,196 INFO : Merged 3 row(s) into list: cpq13
05 May 2021 02:24:29,239 INFO : Merged 6 row(s) into list: cpq11
05 May 2021 02:24:29,281 INFO : Merged 4 row(s) into list: cpq10
05 May 2021 02:24:29,324 INFO : Merged 2 row(s) into list: sex
05 May 2021 02:24:29,363 INFO : Merged 2 row(s) into list: vbw9
05 May 2021 02:24:29,405 INFO : Merged 3 row(s) into list: vbw8
05 May 2021 02:24:29,445 INFO : Merged 3 row(s) into list: cpq8
05 May 2021 02:24:29,465 INFO : Merged 4 row(s) into list: vbw7
05 May 2021 02:24:29,506 INFO : Merged 2 row(s) into list: vbw6
05 May 2021 02:24:29,548 INFO : Merged 5 row(s) into list: cpq6
05 May 2021 02:24:29,552 INFO : 11 lists imported successfully
05 May 2021 02:24:29,552 INFO : Done importing lists
05 May 2021 02:24:29,561 INFO : Post-processing queries
05 May 2021 02:24:29,561 INFO : Skipping query validation.
05 May 2021 02:24:29,561 INFO : Done post-processing queries
05 May 2021 02:24:29,573 INFO : Successfully completed task 'org.labkey.study.importer.StudyImportFinalTask'