Build log

The build generated 52,991 lines of output.The output is too long and has been truncated to the last 1,000 lines. Download or view full build log.

31-Oct-2023 14:20:57	2023-10-31 18:20:58 INFO Calibrater::setapply(type, applypar) Arranging to APPLY:
31-Oct-2023 14:20:58	2023-10-31 18:20:58 INFO Calibrater::setapply(type, applypar) . G Jones: table=gaincaltest2.ms.G0 select= interp=linear spwmap=[-1] calWt=false
31-Oct-2023 14:20:58	2023-10-31 18:20:58 INFO calibrater::correct Beginning correct---------------------------
31-Oct-2023 14:20:58	2023-10-31 18:20:58 INFO Calibrater::correct2 (VI2/VB2) The following calibration terms are arranged for apply:
31-Oct-2023 14:20:58	2023-10-31 18:20:58 INFO Calibrater::correct2 (VI2/VB2) . G Jones: table=gaincaltest2.ms.G0 select= interp=linear spwmap=[-1] calWt=false
31-Oct-2023 14:21:00	2023-10-31 18:21:01 INFO calibrater::correct Finished correcting.
31-Oct-2023 14:21:01	2023-10-31 18:21:01 INFO calibrater::open **Using OLD VI-driven calibrater tool**
31-Oct-2023 14:21:01	2023-10-31 18:21:01 INFO calibrater::open Opening MS: gaincaltest2.ms for calibration.
31-Oct-2023 14:21:01	2023-10-31 18:21:01 INFO Calibrater:: Initializing nominal selection to the whole MS.
31-Oct-2023 14:21:01	2023-10-31 18:21:01 INFO calibrater::initcalset Beginning initcalset------------------------
31-Oct-2023 14:21:01	2023-10-31 18:21:01 INFO VisSet::VisSet Initializing MODEL_DATA (to unity) and CORRECTED_DATA (to DATA)
31-Oct-2023 14:21:01	2023-10-31 18:21:02 INFO VisSet::VisSet Initialized 328860 rows.
31-Oct-2023 14:21:03	2023-10-31 18:21:03 WARN calibrater::setvi(bool,bool) Forcing use of NEW VisibilityIterator.
31-Oct-2023 14:21:03	test_tool_calibrater.py::calibrater_test::test_reinitModel
31-Oct-2023 14:21:03	Check that initcalset will reset the CORRECTED_DATA to unity
31-Oct-2023 14:21:03	PASSED
31-Oct-2023 14:21:03
31-Oct-2023 14:21:03	2023-10-31 18:21:03 INFO calibrater::open **Using NEW VI2-driven calibrater tool**
31-Oct-2023 14:21:03	2023-10-31 18:21:03 INFO calibrater::open Opening MS: gaincaltest2.ms for calibration.
31-Oct-2023 14:21:03	2023-10-31 18:21:03 INFO Clearing all model records in MS header.
31-Oct-2023 14:21:03	2023-10-31 18:21:03 INFO VisSetUtil::addScrCols Adding MODEL_DATA and CORRECTED_DATA column(s).
31-Oct-2023 14:21:04	2023-10-31 18:21:05 INFO VisSetUtil::initScrCols Initializing MODEL_DATA to (unity).
31-Oct-2023 14:21:04	2023-10-31 18:21:05 INFO VisSetUtil::initScrCols Initialized 328860 rows.
31-Oct-2023 14:21:04	2023-10-31 18:21:05 INFO Calibrater:: Initializing nominal selection to the whole MS.
31-Oct-2023 14:21:04	2023-10-31 18:21:05 INFO calibrater::setapply Beginning setapply--(MSSelection version)-------
31-Oct-2023 14:21:04	2023-10-31 18:21:05 INFO Calibrater::setapply(type, applypar) Arranging to APPLY:
31-Oct-2023 14:21:05	2023-10-31 18:21:05 INFO Calibrater::setapply(type, applypar) . G Jones: table=gaincaltest2.ms.G0 select= interp=linear spwmap=[-1] calWt=false
31-Oct-2023 14:21:05	2023-10-31 18:21:05 INFO calibrater::setsolve Beginning setsolve--(MSSelection version)-------
31-Oct-2023 14:21:05	2023-10-31 18:21:05 INFO Calibrater::setsolve Arranging to SOLVE:
31-Oct-2023 14:21:05	2023-10-31 18:21:05 INFO Calibrater::setsolve . Mf Mueller: table=gaincaltest2.ms.G0 append=false solint=inf,none refantmode='flex' refant='none' minsnr=0 apmode=AP solnorm=false
31-Oct-2023 14:21:05	2023-10-31 18:21:05 INFO calibrater::reset Reseting solve/apply state
31-Oct-2023 14:21:05	2023-10-31 18:21:05 INFO calibrater::solve Beginning solve-----------------------------
31-Oct-2023 14:21:05	2023-10-31 18:21:05 SEVERE Calibrater::solve Caught exception: Please run setsolve before attempting to solve.
31-Oct-2023 14:21:05	2023-10-31 18:21:05 INFO Calibrater::solve Reseting entire solve/apply state.
31-Oct-2023 14:21:05	2023-10-31 18:21:05 SEVERE Exception Reported: Error in Calibrater::solve.
31-Oct-2023 14:21:05	2023-10-31 18:21:05 INFO calibrater::correct Beginning correct---------------------------
31-Oct-2023 14:21:05	2023-10-31 18:21:05 INFO Calibrater::correct2 (VI2/VB2) The following calibration terms are arranged for apply:
31-Oct-2023 14:21:05	2023-10-31 18:21:05 INFO Calibrater::correct2 (VI2/VB2) . (None)
31-Oct-2023 14:21:05	2023-10-31 18:21:05 SEVERE Calibrater::correct2 (VI2/VB2) Caught exception: Nothing to Apply
31-Oct-2023 14:21:05	2023-10-31 18:21:05 INFO Calibrater::correct2 (VI2/VB2) Resetting all calibration application settings.
31-Oct-2023 14:21:05	2023-10-31 18:21:05 SEVERE Exception Reported: Error in Calibrater::correct.
31-Oct-2023 14:21:05	2023-10-31 18:21:05 WARN calibrater::setvi(bool,bool) Already using NEW VisibilityIterator.
31-Oct-2023 14:21:05	test_tool_calibrater.py::calibrater_test::test_resetSolveApply
31-Oct-2023 14:21:05	Check that the reset function can clear set apply and solves
31-Oct-2023 14:21:05	PASSED
31-Oct-2023 14:21:05
31-Oct-2023 14:21:05	2023-10-31 18:21:06 INFO calibrater::open **Using NEW VI2-driven calibrater tool**
31-Oct-2023 14:21:05	2023-10-31 18:21:06 INFO calibrater::open Opening MS: gaincaltest2.ms for calibration.
31-Oct-2023 14:21:05	2023-10-31 18:21:06 INFO Clearing all model records in MS header.
31-Oct-2023 14:21:05	2023-10-31 18:21:06 INFO VisSetUtil::addScrCols Adding MODEL_DATA and CORRECTED_DATA column(s).
31-Oct-2023 14:21:06	2023-10-31 18:21:07 INFO VisSetUtil::initScrCols Initializing MODEL_DATA to (unity).
31-Oct-2023 14:21:07	2023-10-31 18:21:07 INFO VisSetUtil::initScrCols Initialized 328860 rows.
31-Oct-2023 14:21:07	2023-10-31 18:21:07 INFO Calibrater:: Initializing nominal selection to the whole MS.
31-Oct-2023 14:21:07	2023-10-31 18:21:08 INFO calibrater::setdata Beginning selectvis--(MSSelection version)-------
31-Oct-2023 14:21:07	2023-10-31 18:21:08 INFO calibrater::reset Reseting solve/apply state
31-Oct-2023 14:21:07	2023-10-31 18:21:08 INFO Calibrater::selectvis Performing selection on MeasurementSet
31-Oct-2023 14:21:07	2023-10-31 18:21:08 INFO Calibrater::selectvis+ Selecting on spw: '1'
31-Oct-2023 14:21:07	2023-10-31 18:21:08 INFO Calibrater::selectvis By selection 328860 rows are reduced to 82215
31-Oct-2023 14:21:07	2023-10-31 18:21:08 INFO Calibrater::selectvis Frequency selection:
31-Oct-2023 14:21:07	2023-10-31 18:21:08 INFO Calibrater::selectvis . Spw 1:0~7 (8 channels, step by 1)
31-Oct-2023 14:21:07	2023-10-31 18:21:08 INFO calibrater::setdata chanmode=none nchan=1 start=0 step=1 mStart='0km/s' mStep='0km/s' msSelect=''
31-Oct-2023 14:21:07	2023-10-31 18:21:08 WARN calibrater::setvi(bool,bool) Already using NEW VisibilityIterator.
31-Oct-2023 14:21:08	test_tool_calibrater.py::calibrater_test::test_returnDict
31-Oct-2023 14:21:08	Check that the returndict function gives a dictonary with the expected keys
31-Oct-2023 14:21:08	PASSED
31-Oct-2023 14:21:08
31-Oct-2023 14:21:08	2023-10-31 18:21:09 INFO calibrater::open **Using NEW VI2-driven calibrater tool**
31-Oct-2023 14:21:08	2023-10-31 18:21:09 INFO calibrater::open Opening MS: gaincaltest2.ms for calibration.
31-Oct-2023 14:21:08	2023-10-31 18:21:09 INFO Clearing all model records in MS header.
31-Oct-2023 14:21:08	2023-10-31 18:21:09 INFO VisSetUtil::addScrCols Adding MODEL_DATA and CORRECTED_DATA column(s).
31-Oct-2023 14:21:10	2023-10-31 18:21:10 INFO VisSetUtil::initScrCols Initializing MODEL_DATA to (unity).
31-Oct-2023 14:21:10	2023-10-31 18:21:10 INFO VisSetUtil::initScrCols Initialized 328860 rows.
31-Oct-2023 14:21:10	2023-10-31 18:21:10 INFO Calibrater:: Initializing nominal selection to the whole MS.
31-Oct-2023 14:21:10	2023-10-31 18:21:10 INFO calibrater::setdata Beginning selectvis--(MSSelection version)-------
31-Oct-2023 14:21:10	2023-10-31 18:21:10 INFO calibrater::reset Reseting solve/apply state
31-Oct-2023 14:21:10	2023-10-31 18:21:10 INFO Calibrater::selectvis Performing selection on MeasurementSet
31-Oct-2023 14:21:10	2023-10-31 18:21:10 INFO Calibrater::selectvis+ Selecting on antenna/baseline: '0'
31-Oct-2023 14:21:10	2023-10-31 18:21:10 INFO Calibrater::selectvis By selection 328860 rows are reduced to 65772
31-Oct-2023 14:21:10	2023-10-31 18:21:10 INFO Calibrater::selectvis Frequency selection: Selecting all channels in all spws.
31-Oct-2023 14:21:10	2023-10-31 18:21:10 INFO calibrater::setdata chanmode=none nchan=1 start=0 step=1 mStart='0km/s' mStep='0km/s' msSelect=''
31-Oct-2023 14:21:10	2023-10-31 18:21:10 INFO calibrater::setapply Beginning setapply--(MSSelection version)-------
31-Oct-2023 14:21:10	2023-10-31 18:21:10 INFO Calibrater::setapply(type, applypar) Arranging to APPLY:
31-Oct-2023 14:21:10	2023-10-31 18:21:10 INFO Calibrater::setapply(type, applypar) . G Jones: table=gaincaltest2.ms.G0 select= interp=linear spwmap=[-1] calWt=false
31-Oct-2023 14:21:10	2023-10-31 18:21:10 INFO calibrater::correct Beginning correct---------------------------
31-Oct-2023 14:21:10	2023-10-31 18:21:10 INFO Calibrater::correct2 (VI2/VB2) The following calibration terms are arranged for apply:
31-Oct-2023 14:21:10	2023-10-31 18:21:10 INFO Calibrater::correct2 (VI2/VB2) . G Jones: table=gaincaltest2.ms.G0 select= interp=linear spwmap=[-1] calWt=false
31-Oct-2023 14:21:12	2023-10-31 18:21:12 INFO calibrater::correct Finished correcting.
31-Oct-2023 14:21:12	2023-10-31 18:21:13 WARN calibrater::setvi(bool,bool) Already using NEW VisibilityIterator.
31-Oct-2023 14:21:12	test_tool_calibrater.py::calibrater_test::test_selectVisBaseline
31-Oct-2023 14:21:12	Check that selectvis properly selects baseline/antenna
31-Oct-2023 14:21:12	65772 65772
31-Oct-2023 14:21:12	263088 263088
31-Oct-2023 14:21:12	PASSED
31-Oct-2023 14:21:12
31-Oct-2023 14:21:13	2023-10-31 18:21:14 INFO calibrater::open **Using NEW VI2-driven calibrater tool**
31-Oct-2023 14:21:13	2023-10-31 18:21:14 INFO calibrater::open Opening MS: gaincaltest2.ms for calibration.
31-Oct-2023 14:21:13	2023-10-31 18:21:14 INFO Clearing all model records in MS header.
31-Oct-2023 14:21:13	2023-10-31 18:21:14 INFO VisSetUtil::addScrCols Adding MODEL_DATA and CORRECTED_DATA column(s).
31-Oct-2023 14:21:14	2023-10-31 18:21:15 INFO VisSetUtil::initScrCols Initializing MODEL_DATA to (unity).
31-Oct-2023 14:21:15	2023-10-31 18:21:15 INFO VisSetUtil::initScrCols Initialized 328860 rows.
31-Oct-2023 14:21:15	2023-10-31 18:21:15 INFO Calibrater:: Initializing nominal selection to the whole MS.
31-Oct-2023 14:21:15	2023-10-31 18:21:15 INFO calibrater::setdata Beginning selectvis--(MSSelection version)-------
31-Oct-2023 14:21:15	2023-10-31 18:21:15 INFO calibrater::reset Reseting solve/apply state
31-Oct-2023 14:21:15	2023-10-31 18:21:15 INFO Calibrater::selectvis Performing selection on MeasurementSet
31-Oct-2023 14:21:15	2023-10-31 18:21:15 INFO Calibrater::selectvis+ Selecting on field: '0'
31-Oct-2023 14:21:15	2023-10-31 18:21:15 INFO Calibrater::selectvis By selection 328860 rows are reduced to 172260
31-Oct-2023 14:21:15	2023-10-31 18:21:15 INFO Calibrater::selectvis Frequency selection: Selecting all channels in all spws.
31-Oct-2023 14:21:15	2023-10-31 18:21:15 INFO calibrater::setdata chanmode=none nchan=1 start=0 step=1 mStart='0km/s' mStep='0km/s' msSelect=''
31-Oct-2023 14:21:15	2023-10-31 18:21:15 INFO calibrater::setapply Beginning setapply--(MSSelection version)-------
31-Oct-2023 14:21:15	2023-10-31 18:21:15 INFO Calibrater::setapply(type, applypar) Arranging to APPLY:
31-Oct-2023 14:21:15	2023-10-31 18:21:15 INFO Calibrater::setapply(type, applypar) . G Jones: table=gaincaltest2.ms.G0 select= interp=linear spwmap=[-1] calWt=false
31-Oct-2023 14:21:15	2023-10-31 18:21:15 INFO calibrater::correct Beginning correct---------------------------
31-Oct-2023 14:21:15	2023-10-31 18:21:15 INFO Calibrater::correct2 (VI2/VB2) The following calibration terms are arranged for apply:
31-Oct-2023 14:21:15	2023-10-31 18:21:15 INFO Calibrater::correct2 (VI2/VB2) . G Jones: table=gaincaltest2.ms.G0 select= interp=linear spwmap=[-1] calWt=false
31-Oct-2023 14:21:16	2023-10-31 18:21:17 INFO calibrater::correct Finished correcting.
31-Oct-2023 14:21:17	2023-10-31 18:21:17 WARN calibrater::setvi(bool,bool) Already using NEW VisibilityIterator.
31-Oct-2023 14:21:17	test_tool_calibrater.py::calibrater_test::test_selectVisField
31-Oct-2023 14:21:17	Check that the field is properly selected by selectvis
31-Oct-2023 14:21:17	PASSED
31-Oct-2023 14:21:17
31-Oct-2023 14:21:18	2023-10-31 18:21:18 INFO calibrater::open **Using NEW VI2-driven calibrater tool**
31-Oct-2023 14:21:18	2023-10-31 18:21:18 INFO calibrater::open Opening MS: gaincaltest2.ms for calibration.
31-Oct-2023 14:21:18	2023-10-31 18:21:18 INFO Clearing all model records in MS header.
31-Oct-2023 14:21:18	2023-10-31 18:21:18 INFO VisSetUtil::addScrCols Adding MODEL_DATA and CORRECTED_DATA column(s).
31-Oct-2023 14:21:19	2023-10-31 18:21:20 INFO VisSetUtil::initScrCols Initializing MODEL_DATA to (unity).
31-Oct-2023 14:21:19	2023-10-31 18:21:20 INFO VisSetUtil::initScrCols Initialized 328860 rows.
31-Oct-2023 14:21:19	2023-10-31 18:21:20 INFO Calibrater:: Initializing nominal selection to the whole MS.
31-Oct-2023 14:21:19	2023-10-31 18:21:20 INFO calibrater::setdata Beginning selectvis--(MSSelection version)-------
31-Oct-2023 14:21:19	2023-10-31 18:21:20 INFO calibrater::reset Reseting solve/apply state
31-Oct-2023 14:21:19	2023-10-31 18:21:20 INFO Calibrater::selectvis Performing selection on MeasurementSet
31-Oct-2023 14:21:19	2023-10-31 18:21:20 INFO Calibrater::selectvis+ Selecting on intent: 'AMPLI'
31-Oct-2023 14:21:19	2023-10-31 18:21:20 INFO Calibrater::selectvis Selection did not drop any rows
31-Oct-2023 14:21:19	2023-10-31 18:21:20 INFO Calibrater::selectvis Frequency selection: Selecting all channels in all spws.
31-Oct-2023 14:21:19	2023-10-31 18:21:20 INFO calibrater::setdata chanmode=none nchan=1 start=0 step=1 mStart='0km/s' mStep='0km/s' msSelect=''
31-Oct-2023 14:21:19	2023-10-31 18:21:20 INFO calibrater::setapply Beginning setapply--(MSSelection version)-------
31-Oct-2023 14:21:19	2023-10-31 18:21:20 INFO Calibrater::setapply(type, applypar) Arranging to APPLY:
31-Oct-2023 14:21:20	2023-10-31 18:21:20 INFO Calibrater::setapply(type, applypar) . G Jones: table=gaincaltest2.ms.G0 select= interp=linear spwmap=[-1] calWt=false
31-Oct-2023 14:21:20	2023-10-31 18:21:20 INFO calibrater::correct Beginning correct---------------------------
31-Oct-2023 14:21:20	2023-10-31 18:21:20 INFO Calibrater::correct2 (VI2/VB2) The following calibration terms are arranged for apply:
31-Oct-2023 14:21:20	2023-10-31 18:21:20 INFO Calibrater::correct2 (VI2/VB2) . G Jones: table=gaincaltest2.ms.G0 select= interp=linear spwmap=[-1] calWt=false
31-Oct-2023 14:21:22	2023-10-31 18:21:23 INFO calibrater::correct Finished correcting.
31-Oct-2023 14:21:22	2023-10-31 18:21:23 WARN calibrater::setvi(bool,bool) Already using NEW VisibilityIterator.
31-Oct-2023 14:21:22	test_tool_calibrater.py::calibrater_test::test_selectVisIntent
31-Oct-2023 14:21:22	Check that the intent is properly selected by selectvis
31-Oct-2023 14:21:22	PASSED
31-Oct-2023 14:21:22
31-Oct-2023 14:21:23	2023-10-31 18:21:24 INFO calibrater::open **Using NEW VI2-driven calibrater tool**
31-Oct-2023 14:21:23	2023-10-31 18:21:24 INFO calibrater::open Opening MS: gaincaltest2.ms for calibration.
31-Oct-2023 14:21:23	2023-10-31 18:21:24 INFO Clearing all model records in MS header.
31-Oct-2023 14:21:23	2023-10-31 18:21:24 INFO VisSetUtil::addScrCols Adding MODEL_DATA and CORRECTED_DATA column(s).
31-Oct-2023 14:21:24	2023-10-31 18:21:25 INFO VisSetUtil::initScrCols Initializing MODEL_DATA to (unity).
31-Oct-2023 14:21:25	2023-10-31 18:21:25 INFO VisSetUtil::initScrCols Initialized 328860 rows.
31-Oct-2023 14:21:25	2023-10-31 18:21:25 INFO Calibrater:: Initializing nominal selection to the whole MS.
31-Oct-2023 14:21:25	2023-10-31 18:21:25 INFO calibrater::setdata Beginning selectvis--(MSSelection version)-------
31-Oct-2023 14:21:25	2023-10-31 18:21:25 INFO calibrater::reset Reseting solve/apply state
31-Oct-2023 14:21:25	2023-10-31 18:21:25 INFO Calibrater::selectvis Performing selection on MeasurementSet
31-Oct-2023 14:21:25	2023-10-31 18:21:25 INFO Calibrater::selectvis+ Selecting by observation IDs: '0'
31-Oct-2023 14:21:25	2023-10-31 18:21:25 INFO Calibrater::selectvis By selection 328860 rows are reduced to 318870
31-Oct-2023 14:21:25	2023-10-31 18:21:25 INFO Calibrater::selectvis Frequency selection: Selecting all channels in all spws.
31-Oct-2023 14:21:25	2023-10-31 18:21:25 INFO calibrater::setdata chanmode=none nchan=1 start=0 step=1 mStart='0km/s' mStep='0km/s' msSelect=''
31-Oct-2023 14:21:25	2023-10-31 18:21:25 INFO calibrater::setapply Beginning setapply--(MSSelection version)-------
31-Oct-2023 14:21:25	2023-10-31 18:21:25 INFO Calibrater::setapply(type, applypar) Arranging to APPLY:
31-Oct-2023 14:21:25	2023-10-31 18:21:25 INFO Calibrater::setapply(type, applypar) . G Jones: table=gaincaltest2.ms.G0 select= interp=linear spwmap=[-1] calWt=false
31-Oct-2023 14:21:25	2023-10-31 18:21:25 INFO calibrater::correct Beginning correct---------------------------
31-Oct-2023 14:21:25	2023-10-31 18:21:25 INFO Calibrater::correct2 (VI2/VB2) The following calibration terms are arranged for apply:
31-Oct-2023 14:21:25	2023-10-31 18:21:25 INFO Calibrater::correct2 (VI2/VB2) . G Jones: table=gaincaltest2.ms.G0 select= interp=linear spwmap=[-1] calWt=false
31-Oct-2023 14:21:27	2023-10-31 18:21:28 INFO calibrater::correct Finished correcting.
31-Oct-2023 14:21:27	2023-10-31 18:21:28 WARN calibrater::setvi(bool,bool) Already using NEW VisibilityIterator.
31-Oct-2023 14:21:27	test_tool_calibrater.py::calibrater_test::test_selectVisObs
31-Oct-2023 14:21:27	PASSED
31-Oct-2023 14:21:27
31-Oct-2023 14:21:28	2023-10-31 18:21:29 INFO calibrater::open **Using NEW VI2-driven calibrater tool**
31-Oct-2023 14:21:28	2023-10-31 18:21:29 INFO calibrater::open Opening MS: gaincaltest2.ms for calibration.
31-Oct-2023 14:21:28	2023-10-31 18:21:29 INFO Clearing all model records in MS header.
31-Oct-2023 14:21:28	2023-10-31 18:21:29 INFO VisSetUtil::addScrCols Adding MODEL_DATA and CORRECTED_DATA column(s).
31-Oct-2023 14:21:29	2023-10-31 18:21:30 INFO VisSetUtil::initScrCols Initializing MODEL_DATA to (unity).
31-Oct-2023 14:21:30	2023-10-31 18:21:30 INFO VisSetUtil::initScrCols Initialized 328860 rows.
31-Oct-2023 14:21:30	2023-10-31 18:21:30 INFO Calibrater:: Initializing nominal selection to the whole MS.
31-Oct-2023 14:21:30	2023-10-31 18:21:30 INFO calibrater::setdata Beginning selectvis--(MSSelection version)-------
31-Oct-2023 14:21:30	2023-10-31 18:21:30 INFO calibrater::reset Reseting solve/apply state
31-Oct-2023 14:21:30	2023-10-31 18:21:30 INFO Calibrater::selectvis Performing selection on MeasurementSet
31-Oct-2023 14:21:30	2023-10-31 18:21:30 INFO Calibrater::selectvis+ Selecting on scan: '2'
31-Oct-2023 14:21:30	2023-10-31 18:21:30 INFO Calibrater::selectvis By selection 328860 rows are reduced to 15660
31-Oct-2023 14:21:30	2023-10-31 18:21:30 INFO Calibrater::selectvis Frequency selection: Selecting all channels in all spws.
31-Oct-2023 14:21:30	2023-10-31 18:21:30 INFO calibrater::setdata chanmode=none nchan=1 start=0 step=1 mStart='0km/s' mStep='0km/s' msSelect=''
31-Oct-2023 14:21:30	2023-10-31 18:21:30 INFO calibrater::setapply Beginning setapply--(MSSelection version)-------
31-Oct-2023 14:21:30	2023-10-31 18:21:30 INFO Calibrater::setapply(type, applypar) Arranging to APPLY:
31-Oct-2023 14:21:30	2023-10-31 18:21:30 INFO Calibrater::setapply(type, applypar) . G Jones: table=gaincaltest2.ms.G0 select= interp=linear spwmap=[-1] calWt=false
31-Oct-2023 14:21:30	2023-10-31 18:21:30 INFO calibrater::correct Beginning correct---------------------------
31-Oct-2023 14:21:30	2023-10-31 18:21:30 INFO Calibrater::correct2 (VI2/VB2) The following calibration terms are arranged for apply:
31-Oct-2023 14:21:30	2023-10-31 18:21:30 INFO Calibrater::correct2 (VI2/VB2) . G Jones: table=gaincaltest2.ms.G0 select= interp=linear spwmap=[-1] calWt=false
31-Oct-2023 14:21:30	2023-10-31 18:21:30 INFO calibrater::correct Finished correcting.
31-Oct-2023 14:21:31	2023-10-31 18:21:31 WARN calibrater::setvi(bool,bool) Already using NEW VisibilityIterator.
31-Oct-2023 14:21:31	test_tool_calibrater.py::calibrater_test::test_selectVisScan
31-Oct-2023 14:21:31	Check tht the scan is properly selected by selectvis
31-Oct-2023 14:21:31	PASSED
31-Oct-2023 14:21:31
31-Oct-2023 14:21:32	2023-10-31 18:21:32 INFO calibrater::open **Using NEW VI2-driven calibrater tool**
31-Oct-2023 14:21:32	2023-10-31 18:21:32 INFO calibrater::open Opening MS: gaincaltest2.ms for calibration.
31-Oct-2023 14:21:32	2023-10-31 18:21:32 INFO Clearing all model records in MS header.
31-Oct-2023 14:21:32	2023-10-31 18:21:32 INFO VisSetUtil::addScrCols Adding MODEL_DATA and CORRECTED_DATA column(s).
31-Oct-2023 14:21:33	2023-10-31 18:21:33 INFO VisSetUtil::initScrCols Initializing MODEL_DATA to (unity).
31-Oct-2023 14:21:33	2023-10-31 18:21:34 INFO VisSetUtil::initScrCols Initialized 328860 rows.
31-Oct-2023 14:21:33	2023-10-31 18:21:34 INFO Calibrater:: Initializing nominal selection to the whole MS.
31-Oct-2023 14:21:33	2023-10-31 18:21:34 INFO calibrater::setdata Beginning selectvis--(MSSelection version)-------
31-Oct-2023 14:21:33	2023-10-31 18:21:34 INFO calibrater::reset Reseting solve/apply state
31-Oct-2023 14:21:33	2023-10-31 18:21:34 INFO Calibrater::selectvis Performing selection on MeasurementSet
31-Oct-2023 14:21:33	2023-10-31 18:21:34 INFO Calibrater::selectvis+ Selecting on spw: '0'
31-Oct-2023 14:21:33	2023-10-31 18:21:34 INFO Calibrater::selectvis By selection 328860 rows are reduced to 82215
31-Oct-2023 14:21:33	2023-10-31 18:21:34 INFO Calibrater::selectvis Frequency selection:
31-Oct-2023 14:21:33	2023-10-31 18:21:34 INFO Calibrater::selectvis . Spw 0:0~7 (8 channels, step by 1)
31-Oct-2023 14:21:33	2023-10-31 18:21:34 INFO calibrater::setdata chanmode=none nchan=1 start=0 step=1 mStart='0km/s' mStep='0km/s' msSelect=''
31-Oct-2023 14:21:33	2023-10-31 18:21:34 INFO calibrater::setapply Beginning setapply--(MSSelection version)-------
31-Oct-2023 14:21:33	2023-10-31 18:21:34 INFO Calibrater::setapply(type, applypar) Arranging to APPLY:
31-Oct-2023 14:21:33	2023-10-31 18:21:34 INFO Calibrater::setapply(type, applypar) . G Jones: table=gaincaltest2.ms.G0 select= interp=linear spwmap=[-1] calWt=false
31-Oct-2023 14:21:33	2023-10-31 18:21:34 INFO calibrater::correct Beginning correct---------------------------
31-Oct-2023 14:21:33	2023-10-31 18:21:34 INFO Calibrater::correct2 (VI2/VB2) The following calibration terms are arranged for apply:
31-Oct-2023 14:21:33	2023-10-31 18:21:34 INFO Calibrater::correct2 (VI2/VB2) . G Jones: table=gaincaltest2.ms.G0 select= interp=linear spwmap=[-1] calWt=false
31-Oct-2023 14:21:34	2023-10-31 18:21:34 INFO calibrater::correct Finished correcting.
31-Oct-2023 14:21:35	2023-10-31 18:21:35 WARN calibrater::setvi(bool,bool) Already using NEW VisibilityIterator.
31-Oct-2023 14:21:35	test_tool_calibrater.py::calibrater_test::test_selectVisSpw
31-Oct-2023 14:21:35	Check that spw is properly selected by selectvis
31-Oct-2023 14:21:35	PASSED
31-Oct-2023 14:21:35
31-Oct-2023 14:21:35	2023-10-31 18:21:36 INFO calibrater::open **Using NEW VI2-driven calibrater tool**
31-Oct-2023 14:21:35	2023-10-31 18:21:36 INFO calibrater::open Opening MS: gaincaltest2.ms for calibration.
31-Oct-2023 14:21:35	2023-10-31 18:21:36 INFO Clearing all model records in MS header.
31-Oct-2023 14:21:35	2023-10-31 18:21:36 INFO VisSetUtil::addScrCols Adding MODEL_DATA and CORRECTED_DATA column(s).
31-Oct-2023 14:21:37	2023-10-31 18:21:37 INFO VisSetUtil::initScrCols Initializing MODEL_DATA to (unity).
31-Oct-2023 14:21:37	2023-10-31 18:21:37 INFO VisSetUtil::initScrCols Initialized 328860 rows.
31-Oct-2023 14:21:37	2023-10-31 18:21:37 INFO Calibrater:: Initializing nominal selection to the whole MS.
31-Oct-2023 14:21:37	2023-10-31 18:21:37 INFO calibrater::setdata Beginning selectvis--(MSSelection version)-------
31-Oct-2023 14:21:37	2023-10-31 18:21:37 INFO calibrater::reset Reseting solve/apply state
31-Oct-2023 14:21:37	2023-10-31 18:21:37 INFO Calibrater::selectvis Performing selection on MeasurementSet
31-Oct-2023 14:21:37	2023-10-31 18:21:37 INFO Calibrater::selectvis+ Selecting on time: '>04:38:23'
31-Oct-2023 14:21:37	2023-10-31 18:21:37 INFO Calibrater::selectvis By selection 328860 rows are reduced to 313200
31-Oct-2023 14:21:37	2023-10-31 18:21:37 INFO Calibrater::selectvis Frequency selection: Selecting all channels in all spws.
31-Oct-2023 14:21:37	2023-10-31 18:21:37 INFO calibrater::setdata chanmode=none nchan=1 start=0 step=1 mStart='0km/s' mStep='0km/s' msSelect=''
31-Oct-2023 14:21:37	2023-10-31 18:21:37 INFO calibrater::setapply Beginning setapply--(MSSelection version)-------
31-Oct-2023 14:21:37	2023-10-31 18:21:37 INFO Calibrater::setapply(type, applypar) Arranging to APPLY:
31-Oct-2023 14:21:37	2023-10-31 18:21:38 INFO Calibrater::setapply(type, applypar) . G Jones: table=gaincaltest2.ms.G0 select= interp=linear spwmap=[-1] calWt=false
31-Oct-2023 14:21:37	2023-10-31 18:21:38 INFO calibrater::correct Beginning correct---------------------------
31-Oct-2023 14:21:37	2023-10-31 18:21:38 INFO Calibrater::correct2 (VI2/VB2) The following calibration terms are arranged for apply:
31-Oct-2023 14:21:37	2023-10-31 18:21:38 INFO Calibrater::correct2 (VI2/VB2) . G Jones: table=gaincaltest2.ms.G0 select= interp=linear spwmap=[-1] calWt=false
31-Oct-2023 14:21:40	2023-10-31 18:21:40 INFO calibrater::correct Finished correcting.
31-Oct-2023 14:21:40	2023-10-31 18:21:41 WARN calibrater::setvi(bool,bool) Already using NEW VisibilityIterator.
31-Oct-2023 14:21:40	test_tool_calibrater.py::calibrater_test::test_selectVisTime
31-Oct-2023 14:21:40	Check that time is properly selected by selectvis
31-Oct-2023 14:21:40	PASSED
31-Oct-2023 14:21:40
31-Oct-2023 14:21:41	2023-10-31 18:21:41 INFO calibrater::open **Using NEW VI2-driven calibrater tool**
31-Oct-2023 14:21:41	2023-10-31 18:21:41 INFO calibrater::open Opening MS: gaincaltest2.ms for calibration.
31-Oct-2023 14:21:41	2023-10-31 18:21:41 INFO Clearing all model records in MS header.
31-Oct-2023 14:21:41	2023-10-31 18:21:41 INFO VisSetUtil::addScrCols Adding MODEL_DATA and CORRECTED_DATA column(s).
31-Oct-2023 14:21:42	2023-10-31 18:21:42 INFO VisSetUtil::initScrCols Initializing MODEL_DATA to (unity).
31-Oct-2023 14:21:42	2023-10-31 18:21:43 INFO VisSetUtil::initScrCols Initialized 328860 rows.
31-Oct-2023 14:21:42	2023-10-31 18:21:43 INFO Calibrater:: Initializing nominal selection to the whole MS.
31-Oct-2023 14:21:42	2023-10-31 18:21:43 INFO calibrater::setdata Beginning selectvis--(MSSelection version)-------
31-Oct-2023 14:21:42	2023-10-31 18:21:43 INFO calibrater::reset Reseting solve/apply state
31-Oct-2023 14:21:42	2023-10-31 18:21:43 INFO Calibrater::selectvis Performing selection on MeasurementSet
31-Oct-2023 14:21:42	2023-10-31 18:21:43 INFO Calibrater::selectvis+ Selecting on uvrange: '> 500000lambda'
31-Oct-2023 14:21:43	2023-10-31 18:21:43 INFO Calibrater::selectvis By selection 328860 rows are reduced to 103321
31-Oct-2023 14:21:43	2023-10-31 18:21:43 INFO Calibrater::selectvis Frequency selection: Selecting all channels in all spws.
31-Oct-2023 14:21:43	2023-10-31 18:21:43 INFO calibrater::setdata chanmode=none nchan=1 start=0 step=1 mStart='0km/s' mStep='0km/s' msSelect=''
31-Oct-2023 14:21:43	2023-10-31 18:21:43 INFO calibrater::setapply Beginning setapply--(MSSelection version)-------
31-Oct-2023 14:21:43	2023-10-31 18:21:43 INFO Calibrater::setapply(type, applypar) Arranging to APPLY:
31-Oct-2023 14:21:43	2023-10-31 18:21:43 INFO Calibrater::setapply(type, applypar) . G Jones: table=gaincaltest2.ms.G0 select= interp=linear spwmap=[-1] calWt=false
31-Oct-2023 14:21:43	2023-10-31 18:21:43 INFO calibrater::correct Beginning correct---------------------------
31-Oct-2023 14:21:43	2023-10-31 18:21:43 INFO Calibrater::correct2 (VI2/VB2) The following calibration terms are arranged for apply:
31-Oct-2023 14:21:43	2023-10-31 18:21:43 INFO Calibrater::correct2 (VI2/VB2) . G Jones: table=gaincaltest2.ms.G0 select= interp=linear spwmap=[-1] calWt=false
31-Oct-2023 14:21:45	2023-10-31 18:21:45 INFO calibrater::correct Finished correcting.
31-Oct-2023 14:21:45	2023-10-31 18:21:46 WARN calibrater::setvi(bool,bool) Already using NEW VisibilityIterator.
31-Oct-2023 14:21:45	test_tool_calibrater.py::calibrater_test::test_selectVisUVrange
31-Oct-2023 14:21:45	Check that selectvis properly selects for uvrange
31-Oct-2023 14:21:45	PASSED
31-Oct-2023 14:21:45
31-Oct-2023 14:21:45	2023-10-31 18:21:46 INFO calibrater::open **Using NEW VI2-driven calibrater tool**
31-Oct-2023 14:21:45	2023-10-31 18:21:46 INFO calibrater::open Opening MS: gaincaltest2.ms for calibration.
31-Oct-2023 14:21:45	2023-10-31 18:21:46 INFO Clearing all model records in MS header.
31-Oct-2023 14:21:45	2023-10-31 18:21:46 INFO VisSetUtil::addScrCols Adding MODEL_DATA and CORRECTED_DATA column(s).
31-Oct-2023 14:21:47	2023-10-31 18:21:47 INFO VisSetUtil::initScrCols Initializing MODEL_DATA to (unity).
31-Oct-2023 14:21:47	2023-10-31 18:21:48 INFO VisSetUtil::initScrCols Initialized 328860 rows.
31-Oct-2023 14:21:47	2023-10-31 18:21:48 INFO Calibrater:: Initializing nominal selection to the whole MS.
31-Oct-2023 14:21:47	2023-10-31 18:21:48 INFO calibrater::parsecallibfile Beginning parsecallibfile-)-------
31-Oct-2023 14:21:47	2023-10-31 18:21:48 INFO calibrater::setcallib Beginning setcallib---------
31-Oct-2023 14:21:47	2023-10-31 18:21:48 INFO Calibrater::setcallib2(callib) Arranging to APPLY:
31-Oct-2023 14:21:47	2023-10-31 18:21:48 INFO . G Jones: table=gaincaltest2.ms.G0 (by cal library) calWt=true
31-Oct-2023 14:21:47	2023-10-31 18:21:48 INFO . 0:
31-Oct-2023 14:21:47	2023-10-31 18:21:48 INFO + MS: obs= scan= fld= intent= spw=
31-Oct-2023 14:21:47	2023-10-31 18:21:48 INFO + CT: tinterp=linear finterp=
31-Oct-2023 14:21:47	2023-10-31 18:21:48 INFO + obsmap=[] scanmap=[] fldmap=[]
31-Oct-2023 14:21:47	2023-10-31 18:21:48 INFO + spwmap=[] antmap=[]
31-Oct-2023 14:21:47	2023-10-31 18:21:48 INFO calibrater::corrupt Beginning corrupt---------------------------
31-Oct-2023 14:21:47	2023-10-31 18:21:48 INFO Calibrater::corrupt2 (VI2/VB2) The following calibration terms are arranged for apply:
31-Oct-2023 14:21:47	2023-10-31 18:21:48 INFO Calibrater::corrupt2 (VI2/VB2) . G Jones: table=gaincaltest2.ms.G0 (by cal library) calWt=true
31-Oct-2023 14:21:49	2023-10-31 18:21:50 INFO calibrater::corrupt Finished corrupting.
31-Oct-2023 14:21:50	2023-10-31 18:21:51 WARN calibrater::setvi(bool,bool) Already using NEW VisibilityIterator.
31-Oct-2023 14:21:50	test_tool_calibrater.py::calibrater_test::test_setCalLib
31-Oct-2023 14:21:50	Check that a provided cal table can be used to corrupt the MODEL_DATA
31-Oct-2023 14:21:50	PASSED
31-Oct-2023 14:21:50
31-Oct-2023 14:21:50	2023-10-31 18:21:51 INFO calibrater::open **Using NEW VI2-driven calibrater tool**
31-Oct-2023 14:21:50	2023-10-31 18:21:51 INFO calibrater::open Opening MS: gaincaltest2.ms for calibration.
31-Oct-2023 14:21:50	2023-10-31 18:21:51 INFO Clearing all model records in MS header.
31-Oct-2023 14:21:50	2023-10-31 18:21:51 INFO VisSetUtil::addScrCols Adding MODEL_DATA and CORRECTED_DATA column(s).
31-Oct-2023 14:21:52	2023-10-31 18:21:52 INFO VisSetUtil::initScrCols Initializing MODEL_DATA to (unity).
31-Oct-2023 14:21:52	2023-10-31 18:21:52 INFO VisSetUtil::initScrCols Initialized 328860 rows.
31-Oct-2023 14:21:52	2023-10-31 18:21:52 INFO Calibrater:: Initializing nominal selection to the whole MS.
31-Oct-2023 14:21:52	2023-10-31 18:21:52 INFO Calibrater::setCorrDepFlags Setting correlation dependent flags = True
31-Oct-2023 14:21:52	2023-10-31 18:21:52 WARN calibrater::setvi(bool,bool) Already using NEW VisibilityIterator.
31-Oct-2023 14:21:52	test_tool_calibrater.py::calibrater_test::test_setCorrDepFlags
31-Oct-2023 14:21:52	Check that corrdepflags will be checked
31-Oct-2023 14:21:52	PASSED
31-Oct-2023 14:21:52
31-Oct-2023 14:21:52	2023-10-31 18:21:53 INFO calibrater::open **Using NEW VI2-driven calibrater tool**
31-Oct-2023 14:21:52	2023-10-31 18:21:53 INFO calibrater::open Opening MS: ngc5921.ms for calibration.
31-Oct-2023 14:21:52	2023-10-31 18:21:53 INFO Clearing all model records in MS header.
31-Oct-2023 14:21:52	2023-10-31 18:21:53 INFO VisSetUtil::addScrCols Adding MODEL_DATA and CORRECTED_DATA column(s).
31-Oct-2023 14:21:52	2023-10-31 18:21:53 INFO VisSetUtil::initScrCols Initializing MODEL_DATA to (unity).
31-Oct-2023 14:21:52	2023-10-31 18:21:53 INFO VisSetUtil::initScrCols Initialized 22653 rows.
31-Oct-2023 14:21:52	2023-10-31 18:21:53 INFO Calibrater:: Initializing nominal selection to the whole MS.
31-Oct-2023 14:21:52	2023-10-31 18:21:53 INFO calibrater::smooth Beginning smooth--(MSSelection version)-------
31-Oct-2023 14:21:52	2023-10-31 18:21:53 INFO Calibrater::smooth Beginning smoothing/interpolating method.
31-Oct-2023 14:21:52	2023-10-31 18:21:53 WARN Found pre-v4.1 caltable (/home/casatest/casa6/casatestutils/nosedir/test_tool_calibrater/ngc5921.gcal); attempting to update...
31-Oct-2023 14:21:52	2023-10-31 18:21:53 WARN + SUCCEEDED: trivial OBSERVATION/OBSERVATION_ID have been added.
31-Oct-2023 14:21:52	2023-10-31 18:21:53 INFO Calibrater::smooth Storing result in testcalout.cal
31-Oct-2023 14:21:52	2023-10-31 18:21:53 INFO Writing solutions to table: testcalout.cal
31-Oct-2023 14:21:52	2023-10-31 18:21:53 WARN calibrater::setvi(bool,bool) Already using NEW VisibilityIterator.
31-Oct-2023 14:21:53	test_tool_calibrater.py::calibrater_test::test_smoothedCalTables
31-Oct-2023 14:21:53	Check that the smooth command creates a smoothed cal table
31-Oct-2023 14:21:53	PASSED
31-Oct-2023 14:21:53
31-Oct-2023 14:21:53	2023-10-31 18:21:53 WARN calibrater::setvi(bool,bool) Forcing use of OLD VisibilityIterator.
31-Oct-2023 14:21:53	2023-10-31 18:21:53 INFO calibrater::open **Using OLD VI-driven calibrater tool**
31-Oct-2023 14:21:53	2023-10-31 18:21:53 INFO calibrater::open Opening MS: ngc5921.ms for calibration.
31-Oct-2023 14:21:53	2023-10-31 18:21:53 INFO Clearing all model records in MS header.
31-Oct-2023 14:21:53	2023-10-31 18:21:53 INFO VisSetUtil::addScrCols Adding MODEL_DATA and CORRECTED_DATA column(s).
31-Oct-2023 14:21:53	2023-10-31 18:21:53 INFO VisSetUtil::initScrCols Initializing MODEL_DATA to (unity).
31-Oct-2023 14:21:53	2023-10-31 18:21:53 INFO VisSetUtil::initScrCols Initialized 22653 rows.
31-Oct-2023 14:21:53	2023-10-31 18:21:53 INFO Calibrater:: Initializing nominal selection to the whole MS.
31-Oct-2023 14:21:53	2023-10-31 18:21:54 INFO calibrater::setsolvebandpoly Beginning setsolvebandpoly--(MSSelection version)-------
31-Oct-2023 14:21:53	2023-10-31 18:21:54 INFO Calibrater::setsolvebandpoly Arranging to SOLVE:
31-Oct-2023 14:21:53	2023-10-31 18:21:54 INFO Calibrater::setsolvebandpoly . BPOLY: table=bpoly append=false solint=inf,none refantmode='flex' refant='none' minsnr=0 apmode= solnorm=true normtype=MEAN
31-Oct-2023 14:21:53	2023-10-31 18:21:54 INFO calibrater::solve Beginning solve-----------------------------
31-Oct-2023 14:21:53	2023-10-31 18:21:54 INFO Calibrater::solve The following calibration terms are arranged for apply:
31-Oct-2023 14:21:53	2023-10-31 18:21:54 INFO Calibrater::solve . (None)
31-Oct-2023 14:21:53	2023-10-31 18:21:54 INFO Calibrater::solve The following calibration term is arranged for solve:
31-Oct-2023 14:21:53	2023-10-31 18:21:54 INFO Calibrater::solve . BPOLY: table=bpoly append=false solint=inf,none refantmode='flex' refant='none' minsnr=0 apmode= solnorm=true normtype=MEAN
31-Oct-2023 14:21:53	2023-10-31 18:21:54 INFO Calibrater::solve Solving for BPOLY
31-Oct-2023 14:21:53	2023-10-31 18:21:54 INFO For solint = inf, found 7 solution intervals.
31-Oct-2023 14:21:53	2023-10-31 18:21:54 INFO BJonesPoly::selfSolveOne() THIS IS THE NEW MULTI-SPW-FLEXIBLE VERSION
31-Oct-2023 14:21:53	2023-10-31 18:21:54 INFO BJonesPoly::selfSolveOne() Fitting bandpass amplitude and phase polynomials.
31-Oct-2023 14:21:53	2023-10-31 18:21:54 INFO BJonesPoly::selfSolveOne() Polynomial degree for amplitude is 5
31-Oct-2023 14:21:53	2023-10-31 18:21:54 INFO BJonesPoly::selfSolveOne() Polynomial degree for phase is 7
31-Oct-2023 14:21:53	2023-10-31 18:21:54 INFO BJonesPoly::selfSolveOne() Spectral grid for fit will have 63 points spaced by 24.4141 kHz.
31-Oct-2023 14:21:53	2023-10-31 18:21:54 INFO BJonesPoly::selfSolveOne() Polynomial solution will be valid over frequency range: 1.41267e+09-1.41418e+09 Hz.
31-Oct-2023 14:21:53	2023-10-31 18:21:54 INFO BJonesPoly::selfSolveOne() Total bandwidth: 1538.09 kHz.
31-Oct-2023 14:21:53	2023-10-31 18:21:54 INFO BJonesPoly::selfSolveOne() Found data for 351 baselines among 27 antennas.
31-Oct-2023 14:21:53	2023-10-31 18:21:54 INFO BJonesPoly::selfSolveOne() Fitting amplitude polynomial.
31-Oct-2023 14:21:53	2023-10-31 18:21:54 INFO BJonesPoly::selfSolveOne() Per-baseline RMS log(Amp) statistics: (min/mean/max) = 0.059507/0.0681762/0.0765806
31-Oct-2023 14:21:53	2023-10-31 18:21:54 INFO BJonesPoly::selfSolveOne() Fitting phase polynomial.
31-Oct-2023 14:21:53	2023-10-31 18:21:54 INFO BJonesPoly::selfSolveOne() Per baseline RMS phase (deg) statistics: (min/mean/max) = 0.336529/0.750193/1.6779
31-Oct-2023 14:21:53	2023-10-31 18:21:54 INFO BJonesPoly::selfSolveOne() Fitting amplitude polynomial.
31-Oct-2023 14:21:53	2023-10-31 18:21:54 INFO BJonesPoly::selfSolveOne() Per-baseline RMS log(Amp) statistics: (min/mean/max) = 0.0630839/0.0689061/0.0756384
31-Oct-2023 14:21:53	2023-10-31 18:21:54 INFO BJonesPoly::selfSolveOne() Fitting phase polynomial.
31-Oct-2023 14:21:53	2023-10-31 18:21:54 INFO BJonesPoly::selfSolveOne() Per baseline RMS phase (deg) statistics: (min/mean/max) = 0.279482/0.74979/1.59355
31-Oct-2023 14:21:53	2023-10-31 18:21:54 INFO BJonesPoly::selfSolveOne() Normalizing antenna-based solutions.
31-Oct-2023 14:21:53	2023-10-31 18:21:54 INFO BJonesPoly::updateCalTable() Storing calibration in table bpoly
31-Oct-2023 14:21:53	2023-10-31 18:21:54 INFO BJonesPoly::selfSolveOne() THIS IS THE NEW MULTI-SPW-FLEXIBLE VERSION
31-Oct-2023 14:21:53	2023-10-31 18:21:54 INFO BJonesPoly::selfSolveOne() Fitting bandpass amplitude and phase polynomials.
31-Oct-2023 14:21:53	2023-10-31 18:21:54 INFO BJonesPoly::selfSolveOne() Polynomial degree for amplitude is 5
31-Oct-2023 14:21:53	2023-10-31 18:21:54 INFO BJonesPoly::selfSolveOne() Polynomial degree for phase is 7
31-Oct-2023 14:21:53	2023-10-31 18:21:54 INFO BJonesPoly::selfSolveOne() Spectral grid for fit will have 63 points spaced by 24.4141 kHz.
31-Oct-2023 14:21:53	2023-10-31 18:21:54 INFO BJonesPoly::selfSolveOne() Polynomial solution will be valid over frequency range: 1.41267e+09-1.41418e+09 Hz.
31-Oct-2023 14:21:53	2023-10-31 18:21:54 INFO BJonesPoly::selfSolveOne() Total bandwidth: 1538.09 kHz.
31-Oct-2023 14:21:53	2023-10-31 18:21:54 INFO BJonesPoly::selfSolveOne() Found data for 351 baselines among 27 antennas.
31-Oct-2023 14:21:53	2023-10-31 18:21:54 INFO BJonesPoly::selfSolveOne() Fitting amplitude polynomial.
31-Oct-2023 14:21:53	2023-10-31 18:21:54 INFO BJonesPoly::selfSolveOne() Per-baseline RMS log(Amp) statistics: (min/mean/max) = 0.0672607/0.089081/0.111106
31-Oct-2023 14:21:53	2023-10-31 18:21:54 INFO BJonesPoly::selfSolveOne() Fitting phase polynomial.
31-Oct-2023 14:21:54	2023-10-31 18:21:54 INFO BJonesPoly::selfSolveOne() Per baseline RMS phase (deg) statistics: (min/mean/max) = 2.31075/3.32219/4.29305
31-Oct-2023 14:21:54	2023-10-31 18:21:54 INFO BJonesPoly::selfSolveOne() Fitting amplitude polynomial.
31-Oct-2023 14:21:54	2023-10-31 18:21:54 INFO BJonesPoly::selfSolveOne() Per-baseline RMS log(Amp) statistics: (min/mean/max) = 0.0652822/0.0889198/0.116912
31-Oct-2023 14:21:54	2023-10-31 18:21:54 INFO BJonesPoly::selfSolveOne() Fitting phase polynomial.
31-Oct-2023 14:21:54	2023-10-31 18:21:54 INFO BJonesPoly::selfSolveOne() Per baseline RMS phase (deg) statistics: (min/mean/max) = 2.44269/3.26616/4.3519
31-Oct-2023 14:21:54	2023-10-31 18:21:54 INFO BJonesPoly::selfSolveOne() Normalizing antenna-based solutions.
31-Oct-2023 14:21:54	2023-10-31 18:21:54 INFO BJonesPoly::updateCalTable() Storing calibration in table bpoly
31-Oct-2023 14:21:54	2023-10-31 18:21:54 INFO BJonesPoly::selfSolveOne() THIS IS THE NEW MULTI-SPW-FLEXIBLE VERSION
31-Oct-2023 14:21:54	2023-10-31 18:21:54 INFO BJonesPoly::selfSolveOne() Fitting bandpass amplitude and phase polynomials.
31-Oct-2023 14:21:54	2023-10-31 18:21:54 INFO BJonesPoly::selfSolveOne() Polynomial degree for amplitude is 5
31-Oct-2023 14:21:54	2023-10-31 18:21:54 INFO BJonesPoly::selfSolveOne() Polynomial degree for phase is 7
31-Oct-2023 14:21:54	2023-10-31 18:21:54 INFO BJonesPoly::selfSolveOne() Spectral grid for fit will have 63 points spaced by 24.4141 kHz.
31-Oct-2023 14:21:54	2023-10-31 18:21:54 INFO BJonesPoly::selfSolveOne() Polynomial solution will be valid over frequency range: 1.41267e+09-1.41418e+09 Hz.
31-Oct-2023 14:21:54	2023-10-31 18:21:54 INFO BJonesPoly::selfSolveOne() Total bandwidth: 1538.09 kHz.
31-Oct-2023 14:21:54	2023-10-31 18:21:54 INFO BJonesPoly::selfSolveOne() Found data for 351 baselines among 27 antennas.
31-Oct-2023 14:21:54	2023-10-31 18:21:54 INFO BJonesPoly::selfSolveOne() Fitting amplitude polynomial.
31-Oct-2023 14:21:54	2023-10-31 18:21:54 INFO BJonesPoly::selfSolveOne() Per-baseline RMS log(Amp) statistics: (min/mean/max) = 0.350681/0.587724/0.894558
31-Oct-2023 14:21:54	2023-10-31 18:21:54 INFO BJonesPoly::selfSolveOne() Fitting phase polynomial.
31-Oct-2023 14:21:56	2023-10-31 18:21:56 INFO BJonesPoly::selfSolveOne() Per baseline RMS phase (deg) statistics: (min/mean/max) = 21.296/59.0077/111.454
31-Oct-2023 14:21:56	2023-10-31 18:21:56 INFO BJonesPoly::selfSolveOne() Fitting amplitude polynomial.
31-Oct-2023 14:21:56	2023-10-31 18:21:56 INFO BJonesPoly::selfSolveOne() Per-baseline RMS log(Amp) statistics: (min/mean/max) = 0.354236/0.581733/0.988903
31-Oct-2023 14:21:56	2023-10-31 18:21:56 INFO BJonesPoly::selfSolveOne() Fitting phase polynomial.
31-Oct-2023 14:21:57	2023-10-31 18:21:58 INFO BJonesPoly::selfSolveOne() Per baseline RMS phase (deg) statistics: (min/mean/max) = 17.2419/56.3249/117.264
31-Oct-2023 14:21:57	2023-10-31 18:21:58 INFO BJonesPoly::selfSolveOne() Normalizing antenna-based solutions.
31-Oct-2023 14:21:57	2023-10-31 18:21:58 INFO BJonesPoly::updateCalTable() Storing calibration in table bpoly
31-Oct-2023 14:21:57	2023-10-31 18:21:58 INFO BJonesPoly::selfSolveOne() THIS IS THE NEW MULTI-SPW-FLEXIBLE VERSION
31-Oct-2023 14:21:57	2023-10-31 18:21:58 INFO BJonesPoly::selfSolveOne() Fitting bandpass amplitude and phase polynomials.
31-Oct-2023 14:21:57	2023-10-31 18:21:58 INFO BJonesPoly::selfSolveOne() Polynomial degree for amplitude is 5
31-Oct-2023 14:21:57	2023-10-31 18:21:58 INFO BJonesPoly::selfSolveOne() Polynomial degree for phase is 7
31-Oct-2023 14:21:57	2023-10-31 18:21:58 INFO BJonesPoly::selfSolveOne() Spectral grid for fit will have 63 points spaced by 24.4141 kHz.
31-Oct-2023 14:21:57	2023-10-31 18:21:58 INFO BJonesPoly::selfSolveOne() Polynomial solution will be valid over frequency range: 1.41267e+09-1.41418e+09 Hz.
31-Oct-2023 14:21:57	2023-10-31 18:21:58 INFO BJonesPoly::selfSolveOne() Total bandwidth: 1538.09 kHz.
31-Oct-2023 14:21:57	2023-10-31 18:21:58 INFO BJonesPoly::selfSolveOne() Found data for 351 baselines among 27 antennas.
31-Oct-2023 14:21:57	2023-10-31 18:21:58 INFO BJonesPoly::selfSolveOne() Fitting amplitude polynomial.
31-Oct-2023 14:21:57	2023-10-31 18:21:58 INFO BJonesPoly::selfSolveOne() Per-baseline RMS log(Amp) statistics: (min/mean/max) = 0.0850169/0.113968/0.15276
31-Oct-2023 14:21:57	2023-10-31 18:21:58 INFO BJonesPoly::selfSolveOne() Fitting phase polynomial.
31-Oct-2023 14:21:58	2023-10-31 18:21:58 INFO BJonesPoly::selfSolveOne() Per baseline RMS phase (deg) statistics: (min/mean/max) = 3.67561/5.33243/8.17296
31-Oct-2023 14:21:58	2023-10-31 18:21:58 INFO BJonesPoly::selfSolveOne() Fitting amplitude polynomial.
31-Oct-2023 14:21:58	2023-10-31 18:21:58 INFO BJonesPoly::selfSolveOne() Per-baseline RMS log(Amp) statistics: (min/mean/max) = 0.0784236/0.114345/0.159908
31-Oct-2023 14:21:58	2023-10-31 18:21:58 INFO BJonesPoly::selfSolveOne() Fitting phase polynomial.
31-Oct-2023 14:21:58	2023-10-31 18:21:58 INFO BJonesPoly::selfSolveOne() Per baseline RMS phase (deg) statistics: (min/mean/max) = 3.46392/5.27232/7.20673
31-Oct-2023 14:21:58	2023-10-31 18:21:58 INFO BJonesPoly::selfSolveOne() Normalizing antenna-based solutions.
31-Oct-2023 14:21:58	2023-10-31 18:21:58 INFO BJonesPoly::updateCalTable() Storing calibration in table bpoly
31-Oct-2023 14:21:58	2023-10-31 18:21:58 INFO BJonesPoly::selfSolveOne() THIS IS THE NEW MULTI-SPW-FLEXIBLE VERSION
31-Oct-2023 14:21:58	2023-10-31 18:21:58 INFO BJonesPoly::selfSolveOne() Fitting bandpass amplitude and phase polynomials.
31-Oct-2023 14:21:58	2023-10-31 18:21:58 INFO BJonesPoly::selfSolveOne() Polynomial degree for amplitude is 5
31-Oct-2023 14:21:58	2023-10-31 18:21:58 INFO BJonesPoly::selfSolveOne() Polynomial degree for phase is 7
31-Oct-2023 14:21:58	2023-10-31 18:21:58 INFO BJonesPoly::selfSolveOne() Spectral grid for fit will have 63 points spaced by 24.4141 kHz.
31-Oct-2023 14:21:58	2023-10-31 18:21:58 INFO BJonesPoly::selfSolveOne() Polynomial solution will be valid over frequency range: 1.41267e+09-1.41418e+09 Hz.
31-Oct-2023 14:21:58	2023-10-31 18:21:58 INFO BJonesPoly::selfSolveOne() Total bandwidth: 1538.09 kHz.
31-Oct-2023 14:21:58	2023-10-31 18:21:58 INFO BJonesPoly::selfSolveOne() Found data for 351 baselines among 27 antennas.
31-Oct-2023 14:21:58	2023-10-31 18:21:58 INFO BJonesPoly::selfSolveOne() Fitting amplitude polynomial.
31-Oct-2023 14:21:58	2023-10-31 18:21:58 INFO BJonesPoly::selfSolveOne() Per-baseline RMS log(Amp) statistics: (min/mean/max) = 0.0703936/0.102501/0.131676
31-Oct-2023 14:21:58	2023-10-31 18:21:58 INFO BJonesPoly::selfSolveOne() Fitting phase polynomial.
31-Oct-2023 14:21:58	2023-10-31 18:21:59 INFO BJonesPoly::selfSolveOne() Per baseline RMS phase (deg) statistics: (min/mean/max) = 2.98728/4.47977/5.84264
31-Oct-2023 14:21:58	2023-10-31 18:21:59 INFO BJonesPoly::selfSolveOne() Fitting amplitude polynomial.
31-Oct-2023 14:21:58	2023-10-31 18:21:59 INFO BJonesPoly::selfSolveOne() Per-baseline RMS log(Amp) statistics: (min/mean/max) = 0.0751114/0.102994/0.138529
31-Oct-2023 14:21:58	2023-10-31 18:21:59 INFO BJonesPoly::selfSolveOne() Fitting phase polynomial.
31-Oct-2023 14:21:58	2023-10-31 18:21:59 INFO BJonesPoly::selfSolveOne() Per baseline RMS phase (deg) statistics: (min/mean/max) = 3.18629/4.47068/5.8941
31-Oct-2023 14:21:58	2023-10-31 18:21:59 INFO BJonesPoly::selfSolveOne() Normalizing antenna-based solutions.
31-Oct-2023 14:21:58	2023-10-31 18:21:59 INFO BJonesPoly::updateCalTable() Storing calibration in table bpoly
31-Oct-2023 14:21:58	2023-10-31 18:21:59 INFO BJonesPoly::selfSolveOne() THIS IS THE NEW MULTI-SPW-FLEXIBLE VERSION
31-Oct-2023 14:21:58	2023-10-31 18:21:59 INFO BJonesPoly::selfSolveOne() Fitting bandpass amplitude and phase polynomials.
31-Oct-2023 14:21:58	2023-10-31 18:21:59 INFO BJonesPoly::selfSolveOne() Polynomial degree for amplitude is 5
31-Oct-2023 14:21:58	2023-10-31 18:21:59 INFO BJonesPoly::selfSolveOne() Polynomial degree for phase is 7
31-Oct-2023 14:21:58	2023-10-31 18:21:59 INFO BJonesPoly::selfSolveOne() Spectral grid for fit will have 63 points spaced by 24.4141 kHz.
31-Oct-2023 14:21:58	2023-10-31 18:21:59 INFO BJonesPoly::selfSolveOne() Polynomial solution will be valid over frequency range: 1.41267e+09-1.41418e+09 Hz.
31-Oct-2023 14:21:58	2023-10-31 18:21:59 INFO BJonesPoly::selfSolveOne() Total bandwidth: 1538.09 kHz.
31-Oct-2023 14:21:58	2023-10-31 18:21:59 INFO BJonesPoly::selfSolveOne() Found data for 351 baselines among 27 antennas.
31-Oct-2023 14:21:58	2023-10-31 18:21:59 INFO BJonesPoly::selfSolveOne() Fitting amplitude polynomial.
31-Oct-2023 14:21:58	2023-10-31 18:21:59 INFO BJonesPoly::selfSolveOne() Per-baseline RMS log(Amp) statistics: (min/mean/max) = 0.350626/0.604424/0.974388
31-Oct-2023 14:21:58	2023-10-31 18:21:59 INFO BJonesPoly::selfSolveOne() Fitting phase polynomial.
31-Oct-2023 14:22:00	2023-10-31 18:22:01 INFO BJonesPoly::selfSolveOne() Per baseline RMS phase (deg) statistics: (min/mean/max) = 21.2542/59.3511/120.719
31-Oct-2023 14:22:00	2023-10-31 18:22:01 INFO BJonesPoly::selfSolveOne() Fitting amplitude polynomial.
31-Oct-2023 14:22:00	2023-10-31 18:22:01 INFO BJonesPoly::selfSolveOne() Per-baseline RMS log(Amp) statistics: (min/mean/max) = 0.382806/0.598119/0.941571
31-Oct-2023 14:22:00	2023-10-31 18:22:01 INFO BJonesPoly::selfSolveOne() Fitting phase polynomial.
31-Oct-2023 14:22:02	2023-10-31 18:22:02 INFO BJonesPoly::selfSolveOne() Per baseline RMS phase (deg) statistics: (min/mean/max) = 20.0637/57.2112/118.101
31-Oct-2023 14:22:02	2023-10-31 18:22:02 INFO BJonesPoly::selfSolveOne() Normalizing antenna-based solutions.
31-Oct-2023 14:22:02	2023-10-31 18:22:03 INFO BJonesPoly::updateCalTable() Storing calibration in table bpoly
31-Oct-2023 14:22:02	2023-10-31 18:22:03 INFO BJonesPoly::selfSolveOne() THIS IS THE NEW MULTI-SPW-FLEXIBLE VERSION
31-Oct-2023 14:22:02	2023-10-31 18:22:03 INFO BJonesPoly::selfSolveOne() Fitting bandpass amplitude and phase polynomials.
31-Oct-2023 14:22:02	2023-10-31 18:22:03 INFO BJonesPoly::selfSolveOne() Polynomial degree for amplitude is 5
31-Oct-2023 14:22:02	2023-10-31 18:22:03 INFO BJonesPoly::selfSolveOne() Polynomial degree for phase is 7
31-Oct-2023 14:22:02	2023-10-31 18:22:03 INFO BJonesPoly::selfSolveOne() Spectral grid for fit will have 63 points spaced by 24.4141 kHz.
31-Oct-2023 14:22:02	2023-10-31 18:22:03 INFO BJonesPoly::selfSolveOne() Polynomial solution will be valid over frequency range: 1.41267e+09-1.41418e+09 Hz.
31-Oct-2023 14:22:02	2023-10-31 18:22:03 INFO BJonesPoly::selfSolveOne() Total bandwidth: 1538.09 kHz.
31-Oct-2023 14:22:02	2023-10-31 18:22:03 INFO BJonesPoly::selfSolveOne() Found data for 351 baselines among 27 antennas.
31-Oct-2023 14:22:02	2023-10-31 18:22:03 INFO BJonesPoly::selfSolveOne() Fitting amplitude polynomial.
31-Oct-2023 14:22:02	2023-10-31 18:22:03 INFO BJonesPoly::selfSolveOne() Per-baseline RMS log(Amp) statistics: (min/mean/max) = 0.0750931/0.0978998/0.125897
31-Oct-2023 14:22:02	2023-10-31 18:22:03 INFO BJonesPoly::selfSolveOne() Fitting phase polynomial.
31-Oct-2023 14:22:02	2023-10-31 18:22:03 INFO BJonesPoly::selfSolveOne() Per baseline RMS phase (deg) statistics: (min/mean/max) = 2.72932/3.98787/5.33715
31-Oct-2023 14:22:02	2023-10-31 18:22:03 INFO BJonesPoly::selfSolveOne() Fitting amplitude polynomial.
31-Oct-2023 14:22:02	2023-10-31 18:22:03 INFO BJonesPoly::selfSolveOne() Per-baseline RMS log(Amp) statistics: (min/mean/max) = 0.0658572/0.0972125/0.140794
31-Oct-2023 14:22:02	2023-10-31 18:22:03 INFO BJonesPoly::selfSolveOne() Fitting phase polynomial.
31-Oct-2023 14:22:02	2023-10-31 18:22:03 INFO BJonesPoly::selfSolveOne() Per baseline RMS phase (deg) statistics: (min/mean/max) = 2.97943/3.97841/5.72903
31-Oct-2023 14:22:02	2023-10-31 18:22:03 INFO BJonesPoly::selfSolveOne() Normalizing antenna-based solutions.
31-Oct-2023 14:22:02	2023-10-31 18:22:03 INFO BJonesPoly::updateCalTable() Storing calibration in table bpoly
31-Oct-2023 14:22:03	2023-10-31 18:22:03 INFO Calibrater::solve Found good BPOLY solutions in 7 slots.
31-Oct-2023 14:22:03	2023-10-31 18:22:03 INFO calibrater::solve Finished solving.
31-Oct-2023 14:22:03	2023-10-31 18:22:03 WARN calibrater::setvi(bool,bool) Forcing use of NEW VisibilityIterator.
31-Oct-2023 14:22:03	test_tool_calibrater.py::calibrater_test::test_solveBandpass
31-Oct-2023 14:22:03	Check that solve band poly creates the output table
31-Oct-2023 14:22:03	PASSED
31-Oct-2023 14:22:03
31-Oct-2023 14:22:03	2023-10-31 18:22:03 WARN calibrater::setvi(bool,bool) Forcing use of OLD VisibilityIterator.
31-Oct-2023 14:22:03	2023-10-31 18:22:03 INFO calibrater::open **Using OLD VI-driven calibrater tool**
31-Oct-2023 14:22:03	2023-10-31 18:22:03 INFO calibrater::open Opening MS: ngc5921.ms for calibration.
31-Oct-2023 14:22:03	2023-10-31 18:22:03 INFO Clearing all model records in MS header.
31-Oct-2023 14:22:03	2023-10-31 18:22:03 INFO VisSetUtil::addScrCols Adding MODEL_DATA and CORRECTED_DATA column(s).
31-Oct-2023 14:22:03	2023-10-31 18:22:04 INFO VisSetUtil::initScrCols Initializing MODEL_DATA to (unity).
31-Oct-2023 14:22:03	2023-10-31 18:22:04 INFO VisSetUtil::initScrCols Initialized 22653 rows.
31-Oct-2023 14:22:03	2023-10-31 18:22:04 INFO Calibrater:: Initializing nominal selection to the whole MS.
31-Oct-2023 14:22:03	2023-10-31 18:22:04 INFO calibrater::setsolvegainspline Beginning setsolvegainspline--(MSSelection version)-------
31-Oct-2023 14:22:03	2023-10-31 18:22:04 INFO Calibrater::setsolvegainspline Arranging to SOLVE:
31-Oct-2023 14:22:03	2023-10-31 18:22:04 INFO Calibrater::setsolvegainspline . GSPLINE: table=gainspline append=false solint=inf refantmode='flex' refant='none' minsnr=0 apmode=AMP solnorm=false
31-Oct-2023 14:22:03	2023-10-31 18:22:04 INFO calibrater::solve Beginning solve-----------------------------
31-Oct-2023 14:22:03	2023-10-31 18:22:04 INFO Calibrater::solve The following calibration terms are arranged for apply:
31-Oct-2023 14:22:03	2023-10-31 18:22:04 INFO Calibrater::solve . (None)
31-Oct-2023 14:22:03	2023-10-31 18:22:04 INFO Calibrater::solve The following calibration term is arranged for solve:
31-Oct-2023 14:22:03	2023-10-31 18:22:04 INFO Calibrater::solve . GSPLINE: table=gainspline append=false solint=inf refantmode='flex' refant='none' minsnr=0 apmode=AMP solnorm=false
31-Oct-2023 14:22:03	2023-10-31 18:22:04 INFO GJonesSpline::solve() Fitting time-dependent cubic splines.
31-Oct-2023 14:22:03	2023-10-31 18:22:04 INFO GJonesSpline::solve() Solving for phase splines with splinetime= 10800
31-Oct-2023 14:22:03	2023-10-31 18:22:04 INFO GJonesSpline::solve() Solving for amplitude splines with splinetime= 10800
31-Oct-2023 14:22:03	2023-10-31 18:22:04 INFO GJonesSpline::solve() Accumulating data for: field= 1331+30500002_0, spw= 0, nchan= 63
31-Oct-2023 14:22:03	2023-10-31 18:22:04 INFO GJonesSpline::solve() Accumulating data for: field= 1445+09900002_0, spw= 0, nchan= 63
31-Oct-2023 14:22:03	2023-10-31 18:22:04 INFO GJonesSpline::solve() Accumulating data for: field= N5921_2, spw= 0, nchan= 63
31-Oct-2023 14:22:03	2023-10-31 18:22:04 INFO GJonesSpline::solve() Number of timestamps in data = 60
31-Oct-2023 14:22:03	2023-10-31 18:22:04 INFO GJonesSpline::getKnots() Gridded splinetime = 5280 sec.
31-Oct-2023 14:22:03	2023-10-31 18:22:04 INFO GJonesSpline::solve() Number of cubic spline control points = 4
31-Oct-2023 14:22:03	2023-10-31 18:22:04 INFO GJonesSpline::solve() Number of cubic spline knots = 8
31-Oct-2023 14:22:03	2023-10-31 18:22:04 INFO GJonesSpline::solve() Number of cubic spline segments = 1
31-Oct-2023 14:22:03	2023-10-31 18:22:04 INFO GJonesSpline::solve() Fitting amplitude spline.
31-Oct-2023 14:22:03	test_tool_calibrater.py::calibrater_test::test_solveGainspline DPBTRF ;problem leading minor 23
31-Oct-2023 14:22:03	DPBTRF ;problem leading minor 23
31-Oct-2023 14:22:03	2023-10-31 18:22:04 INFO GJonesSpline::solve() Searching for and correcting phase-wraps on each baseline.
31-Oct-2023 14:22:03	2023-10-31 18:22:04 INFO GJonesSpline::solve() Fitting phase spline.
31-Oct-2023 14:22:03	DPBTRF ;problem leading minor 22
31-Oct-2023 14:22:03	DPBTRF ;problem leading minor 22
31-Oct-2023 14:22:03	2023-10-31 18:22:04 INFO GJonesSpline::updateCalTable Storing solutions in table gainspline
31-Oct-2023 14:22:03	2023-10-31 18:22:04 INFO calibrater::solve Finished solving.
31-Oct-2023 14:22:03	2023-10-31 18:22:04 WARN calibrater::setvi(bool,bool) Forcing use of NEW VisibilityIterator.
31-Oct-2023 14:22:03
31-Oct-2023 14:22:03	Check that solve gain spline creates the output table
31-Oct-2023 14:22:03	PASSED
31-Oct-2023 14:22:03
31-Oct-2023 14:22:04	2023-10-31 18:22:04 INFO calibrater::open **Using NEW VI2-driven calibrater tool**
31-Oct-2023 14:22:04	2023-10-31 18:22:04 INFO calibrater::open Opening MS: gaincaltest2.ms for calibration.
31-Oct-2023 14:22:04	2023-10-31 18:22:04 INFO Clearing all model records in MS header.
31-Oct-2023 14:22:04	2023-10-31 18:22:04 INFO VisSetUtil::addScrCols Adding MODEL_DATA and CORRECTED_DATA column(s).
31-Oct-2023 14:22:05	2023-10-31 18:22:05 INFO VisSetUtil::initScrCols Initializing MODEL_DATA to (unity).
31-Oct-2023 14:22:05	2023-10-31 18:22:06 INFO VisSetUtil::initScrCols Initialized 328860 rows.
31-Oct-2023 14:22:05	2023-10-31 18:22:06 INFO Calibrater:: Initializing nominal selection to the whole MS.
31-Oct-2023 14:22:05	2023-10-31 18:22:06 INFO calibrater::specifycal Beginning specifycal-----------------------
31-Oct-2023 14:22:05	2023-10-31 18:22:06 INFO Creating G Jones table from specified parameters.
31-Oct-2023 14:22:05	2023-10-31 18:22:06 INFO Generating 'G' corrections.
31-Oct-2023 14:22:05	2023-10-31 18:22:06 INFO Specified parameter(s) (per spw and pol) repeated on all antennas.
31-Oct-2023 14:22:05	2023-10-31 18:22:06 INFO Specified parameter(s) (per spw and antenna) repeated on all polarizations.
31-Oct-2023 14:22:05	2023-10-31 18:22:06 INFO spwId=1 antId=<all> polId=<all> parameter= 3 (ip0,ip1 = [0, 0, 0],[1, 0, 9])
31-Oct-2023 14:22:05	2023-10-31 18:22:06 INFO Writing solutions to table: testcalout.cal
31-Oct-2023 14:22:05	2023-10-31 18:22:06 WARN calibrater::setvi(bool,bool) Already using NEW VisibilityIterator.
31-Oct-2023 14:22:05	test_tool_calibrater.py::calibrater_test::test_specifyCal
31-Oct-2023 14:22:05	Check that specifycal can set values for specific spws and antennas
31-Oct-2023 14:22:05	PASSED
31-Oct-2023 14:22:05
31-Oct-2023 14:22:06	2023-10-31 18:22:06 WARN calibrater::setvi(bool,bool) Forcing use of OLD VisibilityIterator.
31-Oct-2023 14:22:06	2023-10-31 18:22:06 INFO calibrater::open **Using OLD VI-driven calibrater tool**
31-Oct-2023 14:22:06	2023-10-31 18:22:06 INFO calibrater::open Opening MS: gaincaltest2.ms for calibration.
31-Oct-2023 14:22:06	2023-10-31 18:22:06 INFO Clearing all model records in MS header.
31-Oct-2023 14:22:06	2023-10-31 18:22:06 INFO VisSetUtil::addScrCols Adding MODEL_DATA and CORRECTED_DATA column(s).
31-Oct-2023 14:22:07	2023-10-31 18:22:08 INFO VisSetUtil::initScrCols Initializing MODEL_DATA to (unity).
31-Oct-2023 14:22:08	2023-10-31 18:22:08 INFO VisSetUtil::initScrCols Initialized 328860 rows.
31-Oct-2023 14:22:08	2023-10-31 18:22:08 INFO Calibrater:: Initializing nominal selection to the whole MS.
31-Oct-2023 14:22:08	2023-10-31 18:22:08 INFO calibrater::setapply Beginning setapply--(MSSelection version)-------
31-Oct-2023 14:22:08	2023-10-31 18:22:08 INFO Calibrater::setapply(type, applypar) Arranging to APPLY:
31-Oct-2023 14:22:08	2023-10-31 18:22:09 INFO Calibrater::setapply(type, applypar) . G Jones: table=gaincaltest2.ms.G0 select= interp=linear spwmap=[-1] calWt=false
31-Oct-2023 14:22:08	2023-10-31 18:22:09 INFO calibrater::setsolve Beginning setsolve--(MSSelection version)-------
31-Oct-2023 14:22:08	2023-10-31 18:22:09 INFO Calibrater::setsolve Arranging to SOLVE:
31-Oct-2023 14:22:08	2023-10-31 18:22:09 INFO Calibrater::setsolve . Mf Mueller: table=output.ms append=false solint=inf,none refantmode='flex' refant='none' minsnr=0 apmode=AP solnorm=false
31-Oct-2023 14:22:08	2023-10-31 18:22:09 INFO Calibrater::state The following calibration terms are arranged for apply:
31-Oct-2023 14:22:08	2023-10-31 18:22:09 INFO Calibrater::state . G Jones: table=gaincaltest2.ms.G0 select= interp=linear spwmap=[-1] calWt=false
31-Oct-2023 14:22:08	2023-10-31 18:22:09 INFO Calibrater::state The following calibration term is arranged for solve:
31-Oct-2023 14:22:08	2023-10-31 18:22:09 INFO Calibrater::state . Mf Mueller: table=output.ms append=false solint=inf,none refantmode='flex' refant='none' minsnr=0 apmode=AP solnorm=false
31-Oct-2023 14:22:08	2023-10-31 18:22:09 INFO calibrater::solve Beginning solve-----------------------------
31-Oct-2023 14:22:08	2023-10-31 18:22:09 INFO Calibrater::solve The following calibration terms are arranged for apply:
31-Oct-2023 14:22:08	2023-10-31 18:22:09 INFO Calibrater::solve . G Jones: table=gaincaltest2.ms.G0 select= interp=linear spwmap=[-1] calWt=false
31-Oct-2023 14:22:08	2023-10-31 18:22:09 INFO Calibrater::solve The following calibration term is arranged for solve:
31-Oct-2023 14:22:08	2023-10-31 18:22:09 INFO Calibrater::solve . Mf Mueller: table=output.ms append=false solint=inf,none refantmode='flex' refant='none' minsnr=0 apmode=AP solnorm=false
31-Oct-2023 14:22:08	2023-10-31 18:22:09 INFO Solving for Mf Mueller
31-Oct-2023 14:22:08	2023-10-31 18:22:09 INFO For solint = inf, found 84 solution intervals.
31-Oct-2023 14:22:10	2023-10-31 18:22:10 INFO Found good Mf Mueller solutions in 84 intervals.
31-Oct-2023 14:22:10	2023-10-31 18:22:10 INFO Writing solutions to table: output.ms
31-Oct-2023 14:22:10	2023-10-31 18:22:10 INFO calibrater::solve Finished solving.
31-Oct-2023 14:22:10	2023-10-31 18:22:10 WARN calibrater::setvi(bool,bool) Forcing use of NEW VisibilityIterator.
31-Oct-2023 14:22:10	test_tool_calibrater.py::calibrater_test::test_standardPath
31-Oct-2023 14:22:10	open setapply setsolve state solve close
31-Oct-2023 14:22:10	PASSED
31-Oct-2023 14:22:10
31-Oct-2023 14:22:10	2023-10-31 18:22:11 INFO calibrater::open **Using NEW VI2-driven calibrater tool**
31-Oct-2023 14:22:10	2023-10-31 18:22:11 INFO calibrater::open Opening MS: gaincaltest2.ms for calibration.
31-Oct-2023 14:22:10	2023-10-31 18:22:11 INFO Clearing all model records in MS header.
31-Oct-2023 14:22:10	2023-10-31 18:22:11 INFO VisSetUtil::addScrCols Adding MODEL_DATA and CORRECTED_DATA column(s).
31-Oct-2023 14:22:11	2023-10-31 18:22:12 INFO VisSetUtil::initScrCols Initializing MODEL_DATA to (unity).
31-Oct-2023 14:22:12	2023-10-31 18:22:12 INFO VisSetUtil::initScrCols Initialized 328860 rows.
31-Oct-2023 14:22:12	2023-10-31 18:22:12 INFO Calibrater:: Initializing nominal selection to the whole MS.
31-Oct-2023 14:22:12	2023-10-31 18:22:12 INFO name:: No table opened.
31-Oct-2023 14:22:12	2023-10-31 18:22:12 INFO showcache:: The Table Cache has the following 16 entries:
31-Oct-2023 14:22:12	2023-10-31 18:22:12 INFO showcache:: 0: "/home/casatest/casa6/casatestutils/nosedir/test_tool_calibrater/gaincaltest2.ms"
31-Oct-2023 14:22:12	2023-10-31 18:22:12 INFO showcache:: 1: "/home/casatest/casa6/casatestutils/nosedir/test_tool_calibrater/gaincaltest2.ms/ANTENNA"
31-Oct-2023 14:22:12	2023-10-31 18:22:12 INFO showcache:: 2: "/home/casatest/casa6/casatestutils/nosedir/test_tool_calibrater/gaincaltest2.ms/DATA_DESCRIPTION"
31-Oct-2023 14:22:12	2023-10-31 18:22:12 INFO showcache:: 3: "/home/casatest/casa6/casatestutils/nosedir/test_tool_calibrater/gaincaltest2.ms/FEED"
31-Oct-2023 14:22:12	2023-10-31 18:22:12 INFO showcache:: 4: "/home/casatest/casa6/casatestutils/nosedir/test_tool_calibrater/gaincaltest2.ms/FIELD"
31-Oct-2023 14:22:12	2023-10-31 18:22:12 INFO showcache:: 5: "/home/casatest/casa6/casatestutils/nosedir/test_tool_calibrater/gaincaltest2.ms/FLAG_CMD"
31-Oct-2023 14:22:12	2023-10-31 18:22:12 INFO showcache:: 6: "/home/casatest/casa6/casatestutils/nosedir/test_tool_calibrater/gaincaltest2.ms/HISTORY"
31-Oct-2023 14:22:12	2023-10-31 18:22:12 INFO showcache:: 7: "/home/casatest/casa6/casatestutils/nosedir/test_tool_calibrater/gaincaltest2.ms/OBSERVATION"
31-Oct-2023 14:22:12	2023-10-31 18:22:12 INFO showcache:: 8: "/home/casatest/casa6/casatestutils/nosedir/test_tool_calibrater/gaincaltest2.ms/POINTING"
31-Oct-2023 14:22:12	2023-10-31 18:22:12 INFO showcache:: 9: "/home/casatest/casa6/casatestutils/nosedir/test_tool_calibrater/gaincaltest2.ms/POLARIZATION"
31-Oct-2023 14:22:12	2023-10-31 18:22:12 INFO showcache:: 10: "/home/casatest/casa6/casatestutils/nosedir/test_tool_calibrater/gaincaltest2.ms/PROCESSOR"
31-Oct-2023 14:22:12	2023-10-31 18:22:12 INFO showcache:: 11: "/home/casatest/casa6/casatestutils/nosedir/test_tool_calibrater/gaincaltest2.ms/SOURCE"
31-Oct-2023 14:22:12	2023-10-31 18:22:12 INFO showcache:: 12: "/home/casatest/casa6/casatestutils/nosedir/test_tool_calibrater/gaincaltest2.ms/SPECTRAL_WINDOW"
31-Oct-2023 14:22:12	2023-10-31 18:22:12 INFO showcache:: 13: "/home/casatest/casa6/casatestutils/nosedir/test_tool_calibrater/gaincaltest2.ms/STATE"
31-Oct-2023 14:22:12	2023-10-31 18:22:12 INFO showcache:: 14: "/home/casatest/casa6/casatestutils/nosedir/test_tool_calibrater/gaincaltest2.ms/SYSCAL"
31-Oct-2023 14:22:12	2023-10-31 18:22:12 INFO showcache:: 15: "/home/casatest/casa6/casatestutils/nosedir/test_tool_calibrater/gaincaltest2.ms/WEATHER"
31-Oct-2023 14:22:12	2023-10-31 18:22:12 INFO name:: No table opened.
31-Oct-2023 14:22:12	2023-10-31 18:22:12 INFO showcache:: The Table Cache is empty.
31-Oct-2023 14:22:12	2023-10-31 18:22:12 WARN calibrater::setvi(bool,bool) Already using NEW VisibilityIterator.
31-Oct-2023 14:22:12	test_tool_calibrater.py::calibrater_test::test_takesMs
31-Oct-2023 14:22:12	Check that the calibrater tool can open and close an MS
31-Oct-2023 14:22:12	PASSED
31-Oct-2023 14:22:12
31-Oct-2023 14:22:12	2023-10-31 18:22:12 INFO calibrater::open **Using NEW VI2-driven calibrater tool**
31-Oct-2023 14:22:12	2023-10-31 18:22:12 INFO calibrater::open Opening MS: gaincaltest2.ms for calibration.
31-Oct-2023 14:22:12	2023-10-31 18:22:12 INFO Clearing all model records in MS header.
31-Oct-2023 14:22:12	2023-10-31 18:22:13 INFO VisSetUtil::addScrCols Adding MODEL_DATA and CORRECTED_DATA column(s).
31-Oct-2023 14:22:13	2023-10-31 18:22:14 INFO VisSetUtil::initScrCols Initializing MODEL_DATA to (unity).
31-Oct-2023 14:22:13	2023-10-31 18:22:14 INFO VisSetUtil::initScrCols Initialized 328860 rows.
31-Oct-2023 14:22:13	2023-10-31 18:22:14 INFO Calibrater:: Initializing nominal selection to the whole MS.
31-Oct-2023 14:22:13	2023-10-31 18:22:14 INFO calibrater::setapply Beginning setapply--(MSSelection version)-------
31-Oct-2023 14:22:13	2023-10-31 18:22:14 INFO Calibrater::setapply(type, applypar) Arranging to APPLY:
31-Oct-2023 14:22:14	2023-10-31 18:22:14 INFO Calibrater::setapply(type, applypar) . G Jones: table=gaincaltest2.ms.G0 select= interp=linear spwmap=[-1] calWt=false
31-Oct-2023 14:22:14	2023-10-31 18:22:14 INFO calibrater::correct Beginning correct---------------------------
31-Oct-2023 14:22:14	2023-10-31 18:22:14 INFO Calibrater::correct2 (VI2/VB2) The following calibration terms are arranged for apply:
31-Oct-2023 14:22:14	2023-10-31 18:22:14 INFO Calibrater::correct2 (VI2/VB2) . G Jones: table=gaincaltest2.ms.G0 select= interp=linear spwmap=[-1] calWt=false
31-Oct-2023 14:22:16	2023-10-31 18:22:17 INFO calibrater::correct Finished correcting.
31-Oct-2023 14:22:16	2023-10-31 18:22:17 WARN calibrater::setvi(bool,bool) Already using NEW VisibilityIterator.
31-Oct-2023 14:22:16	test_tool_calibrater.py::calibrater_test::test_writeToCorrected
31-Oct-2023 14:22:16	Check that the tool writes to the CORRECTED_DATA column
31-Oct-2023 14:22:16	PASSED
31-Oct-2023 14:22:16
31-Oct-2023 14:22:16	- generated xml file: /home/casatest/casa6/casatestutils/nosedir/xml/test_tool_calibrater/nose.xml -
31-Oct-2023 14:22:16	=================== 24 passed, 1 warning in 96.60s (0:01:36) ===================
31-Oct-2023 14:22:17
31-Oct-2023 14:22:17
31-Oct-2023 14:22:17	Setting Working Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_sdm/
31-Oct-2023 14:22:17	Test Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_sdm
31-Oct-2023 14:22:17
31-Oct-2023 14:22:17	Running Command: pytest --junitxml=/home/casatest/casa6/casatestutils/nosedir/xml/test_tool_sdm/nose.xml -s --disable-pytest-warnings --verbose -ra --tb=short /home/casatest/casa6/casatestutils/nosedir/test_tool_sdm/
31-Oct-2023 14:22:17
31-Oct-2023 14:22:17	Setting Working Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_image_regrid/
31-Oct-2023 14:22:17	Test Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_image_regrid
31-Oct-2023 14:22:17
31-Oct-2023 14:22:17	Running Command: pytest --junitxml=/home/casatest/casa6/casatestutils/nosedir/xml/test_tool_image_regrid/nose.xml -s --disable-pytest-warnings --verbose -ra --tb=short /home/casatest/casa6/casatestutils/nosedir/test_tool_image_regrid/
31-Oct-2023 14:22:17
31-Oct-2023 14:22:17	Setting Working Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_table/
31-Oct-2023 14:22:17	Test Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_table
31-Oct-2023 14:22:17
31-Oct-2023 14:22:17	Running Command: pytest --junitxml=/home/casatest/casa6/casatestutils/nosedir/xml/test_tool_table/nose.xml -s --disable-pytest-warnings --verbose -ra --tb=short /home/casatest/casa6/casatestutils/nosedir/test_tool_table/
31-Oct-2023 14:22:17
31-Oct-2023 14:22:17	Setting Working Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_vpmanager/
31-Oct-2023 14:22:17	Test Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_vpmanager
31-Oct-2023 14:22:17
31-Oct-2023 14:22:17	Running Command: pytest --junitxml=/home/casatest/casa6/casatestutils/nosedir/xml/test_tool_vpmanager/nose.xml -s --disable-pytest-warnings --verbose -ra --tb=short /home/casatest/casa6/casatestutils/nosedir/test_tool_vpmanager/
31-Oct-2023 14:22:17
31-Oct-2023 14:22:17	Setting Working Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_image_subimage/
31-Oct-2023 14:22:17	Test Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_image_subimage
31-Oct-2023 14:22:17
31-Oct-2023 14:22:17	Running Command: pytest --junitxml=/home/casatest/casa6/casatestutils/nosedir/xml/test_tool_image_subimage/nose.xml -s --disable-pytest-warnings --verbose -ra --tb=short /home/casatest/casa6/casatestutils/nosedir/test_tool_image_subimage/
31-Oct-2023 14:22:17
31-Oct-2023 14:22:17	Setting Working Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_quanta/
31-Oct-2023 14:22:17	Test Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_quanta
31-Oct-2023 14:22:17
31-Oct-2023 14:22:17	Running Command: pytest --junitxml=/home/casatest/casa6/casatestutils/nosedir/xml/test_tool_quanta/nose.xml -s --disable-pytest-warnings --verbose -ra --tb=short /home/casatest/casa6/casatestutils/nosedir/test_tool_quanta/
31-Oct-2023 14:22:17
31-Oct-2023 14:22:17	Setting Working Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_linearmosaic/
31-Oct-2023 14:22:17	Test Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_linearmosaic
31-Oct-2023 14:22:17
31-Oct-2023 14:22:17	Running Command: pytest --junitxml=/home/casatest/casa6/casatestutils/nosedir/xml/test_tool_linearmosaic/nose.xml -s --disable-pytest-warnings --verbose -ra --tb=short /home/casatest/casa6/casatestutils/nosedir/test_tool_linearmosaic/
31-Oct-2023 14:22:17
31-Oct-2023 14:22:17	Setting Working Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_image_statistics/
31-Oct-2023 14:22:17	Test Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_image_statistics
31-Oct-2023 14:22:17
31-Oct-2023 14:22:17	Running Command: pytest --junitxml=/home/casatest/casa6/casatestutils/nosedir/xml/test_tool_image_statistics/nose.xml -s --disable-pytest-warnings --verbose -ra --tb=short /home/casatest/casa6/casatestutils/nosedir/test_tool_image_statistics/
31-Oct-2023 14:22:17
31-Oct-2023 14:22:17	Setting Working Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_imagepol/
31-Oct-2023 14:22:17	Test Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_imagepol
31-Oct-2023 14:22:17
31-Oct-2023 14:22:17	Running Command: pytest --junitxml=/home/casatest/casa6/casatestutils/nosedir/xml/test_tool_imagepol/nose.xml -s --disable-pytest-warnings --verbose -ra --tb=short /home/casatest/casa6/casatestutils/nosedir/test_tool_imagepol/
31-Oct-2023 14:22:17
31-Oct-2023 14:22:17	Setting Working Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_msuvbinner/
31-Oct-2023 14:22:17	Test Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_msuvbinner
31-Oct-2023 14:22:17
31-Oct-2023 14:22:17	Running Command: pytest --junitxml=/home/casatest/casa6/casatestutils/nosedir/xml/test_tool_msuvbinner/nose.xml -s --disable-pytest-warnings --verbose -ra --tb=short /home/casatest/casa6/casatestutils/nosedir/test_tool_msuvbinner/
31-Oct-2023 14:22:17
31-Oct-2023 14:22:17	Setting Working Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_image/
31-Oct-2023 14:22:17	Test Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_image
31-Oct-2023 14:22:17
31-Oct-2023 14:22:17	Running Command: pytest --junitxml=/home/casatest/casa6/casatestutils/nosedir/xml/test_tool_image/nose.xml -s --disable-pytest-warnings --verbose -ra --tb=short /home/casatest/casa6/casatestutils/nosedir/test_tool_image/
31-Oct-2023 14:22:17
31-Oct-2023 14:22:17	Setting Working Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_agentflagger/
31-Oct-2023 14:22:17	Test Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_agentflagger
31-Oct-2023 14:22:17
31-Oct-2023 14:22:17	Running Command: pytest --junitxml=/home/casatest/casa6/casatestutils/nosedir/xml/test_tool_agentflagger/nose.xml -s --disable-pytest-warnings --verbose -ra --tb=short /home/casatest/casa6/casatestutils/nosedir/test_tool_agentflagger/
31-Oct-2023 14:22:17
31-Oct-2023 14:22:17	Setting Working Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_regionmanager/
31-Oct-2023 14:22:17	Test Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_regionmanager
31-Oct-2023 14:22:17
31-Oct-2023 14:22:17	Running Command: pytest --junitxml=/home/casatest/casa6/casatestutils/nosedir/xml/test_tool_regionmanager/nose.xml -s --disable-pytest-warnings --verbose -ra --tb=short /home/casatest/casa6/casatestutils/nosedir/test_tool_regionmanager/
31-Oct-2023 14:22:17
31-Oct-2023 14:22:17	Setting Working Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_ms/
31-Oct-2023 14:22:17	Test Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_ms
31-Oct-2023 14:22:17
31-Oct-2023 14:22:17	Running Command: pytest --junitxml=/home/casatest/casa6/casatestutils/nosedir/xml/test_tool_ms/nose.xml -s --disable-pytest-warnings --verbose -ra --tb=short /home/casatest/casa6/casatestutils/nosedir/test_tool_ms/
31-Oct-2023 14:22:17
31-Oct-2023 14:22:17	Setting Working Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_coordsys/
31-Oct-2023 14:22:17	Test Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_coordsys
31-Oct-2023 14:22:17
31-Oct-2023 14:22:17	Running Command: pytest --junitxml=/home/casatest/casa6/casatestutils/nosedir/xml/test_tool_coordsys/nose.xml -s --disable-pytest-warnings --verbose -ra --tb=short /home/casatest/casa6/casatestutils/nosedir/test_tool_coordsys/
31-Oct-2023 14:22:17
31-Oct-2023 14:22:17	Setting Working Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_logsink/
31-Oct-2023 14:22:17	Test Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_logsink
31-Oct-2023 14:22:17
31-Oct-2023 14:22:17	Running Command: pytest --junitxml=/home/casatest/casa6/casatestutils/nosedir/xml/test_tool_logsink/nose.xml -s --disable-pytest-warnings --verbose -ra --tb=short /home/casatest/casa6/casatestutils/nosedir/test_tool_logsink/
31-Oct-2023 14:22:17
31-Oct-2023 14:22:17	Setting Working Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_calibrater/
31-Oct-2023 14:22:17	Test Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_calibrater
31-Oct-2023 14:22:17
31-Oct-2023 14:22:17	Running Command: pytest --junitxml=/home/casatest/casa6/casatestutils/nosedir/xml/test_tool_calibrater/nose.xml -s --disable-pytest-warnings --verbose -ra --tb=short /home/casatest/casa6/casatestutils/nosedir/test_tool_calibrater/
31-Oct-2023 14:22:18	total 184828
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci 15001 112782 Oct 31 18:04 casatestutils-6.6.1.2a14234.dev1-py3-none-any.whl
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci 15001 188983044 Oct 31 18:04 casatools-6.6.1.2a14234.dev1-cp38-cp38-manylinux_2_28_x86_64.whl
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 4314 Oct 31 18:22 test_tool_agentflagger.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 980 Oct 31 18:22 test_tool_calanalysis.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 2631 Oct 31 18:22 test_tool_calibrater.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 545 Oct 31 18:22 test_tool_componentlist.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 7441 Oct 31 18:22 test_tool_coordsys.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 12801 Oct 31 18:22 test_tool_image.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 2194 Oct 31 18:22 test_tool_image_collapse.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 1022 Oct 31 18:22 test_tool_image_deviation.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 2549 Oct 31 18:22 test_tool_image_fitprofile.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 1152 Oct 31 18:22 test_tool_image_pbcor.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 857 Oct 31 18:22 test_tool_image_pv.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 980 Oct 31 18:22 test_tool_image_rebin.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 1310 Oct 31 18:22 test_tool_image_regrid.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 1507 Oct 31 18:22 test_tool_image_statistics.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 739 Oct 31 18:22 test_tool_image_subimage.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 864 Oct 31 18:22 test_tool_image_transpose.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 1940 Oct 31 18:22 test_tool_imagepol.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 813 Oct 31 18:22 test_tool_linearmosaic.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 642 Oct 31 18:22 test_tool_logsink.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 523 Oct 31 18:22 test_tool_measures.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 5198 Oct 31 18:22 test_tool_ms.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 341 Oct 31 18:22 test_tool_ms_createmultims.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 2069 Oct 31 18:22 test_tool_ms_statwt.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 8486 Oct 31 18:22 test_tool_msmetadata.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 333 Oct 31 18:22 test_tool_msuvbinner.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 1145 Oct 31 18:22 test_tool_quanta.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 3951 Oct 31 18:22 test_tool_regionmanager.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 2046 Oct 31 18:22 test_tool_sdm.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 2070 Oct 31 18:22 test_tool_sdm_toms.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 422 Oct 31 18:22 test_tool_simulator.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 1337 Oct 31 18:22 test_tool_table.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 1691 Oct 31 18:22 test_tool_vpmanager.xml
31-Oct-2023 14:22:18	Finished task 'Test wheel' with result: Success
31-Oct-2023 14:22:18	Starting task 'Tar work directory' of type 'com.atlassian.bamboo.plugins.scripttask:task.builder.script'
31-Oct-2023 14:22:18	Beginning to execute external process for build 'CASA - CMake Dev Test - CAS-14234 - Test Tools Many Linux 2.28 #2 (CASA-CMDT86-TTOMLPY38-2)' ... running command line: /export/home/cbt-el7-1/bamboo-home/temp/CASA-CMDT86-TTOMLPY38-2-ScriptBuildTask-6272131098193253316.sh ... in: /export/home/cbt-el7-1/bamboo-home/xml-data/build-dir/CASA-CMDT86-TTOMLPY38
31-Oct-2023 14:22:18	Package working directory
31-Oct-2023 14:22:18	tar: work: Cannot stat: No such file or directory
31-Oct-2023 14:22:18	tar: Exiting with failure status due to previous errors
31-Oct-2023 14:22:18	total 184832
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci 15001 112782 Oct 31 18:04 casatestutils-6.6.1.2a14234.dev1-py3-none-any.whl
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci 15001 188983044 Oct 31 18:04 casatools-6.6.1.2a14234.dev1-cp38-cp38-manylinux_2_28_x86_64.whl
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 4314 Oct 31 18:22 test_tool_agentflagger.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 980 Oct 31 18:22 test_tool_calanalysis.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 2631 Oct 31 18:22 test_tool_calibrater.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 545 Oct 31 18:22 test_tool_componentlist.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 7441 Oct 31 18:22 test_tool_coordsys.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 12801 Oct 31 18:22 test_tool_image.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 2194 Oct 31 18:22 test_tool_image_collapse.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 1022 Oct 31 18:22 test_tool_image_deviation.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 2549 Oct 31 18:22 test_tool_image_fitprofile.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 1152 Oct 31 18:22 test_tool_image_pbcor.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 857 Oct 31 18:22 test_tool_image_pv.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 980 Oct 31 18:22 test_tool_image_rebin.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 1310 Oct 31 18:22 test_tool_image_regrid.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 1507 Oct 31 18:22 test_tool_image_statistics.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 739 Oct 31 18:22 test_tool_image_subimage.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 864 Oct 31 18:22 test_tool_image_transpose.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 1940 Oct 31 18:22 test_tool_imagepol.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 813 Oct 31 18:22 test_tool_linearmosaic.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 642 Oct 31 18:22 test_tool_logsink.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 523 Oct 31 18:22 test_tool_measures.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 5198 Oct 31 18:22 test_tool_ms.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 341 Oct 31 18:22 test_tool_ms_createmultims.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 2069 Oct 31 18:22 test_tool_ms_statwt.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 8486 Oct 31 18:22 test_tool_msmetadata.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 333 Oct 31 18:22 test_tool_msuvbinner.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 1145 Oct 31 18:22 test_tool_quanta.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 3951 Oct 31 18:22 test_tool_regionmanager.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 2046 Oct 31 18:22 test_tool_sdm.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 2070 Oct 31 18:22 test_tool_sdm_toms.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 422 Oct 31 18:22 test_tool_simulator.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 1337 Oct 31 18:22 test_tool_table.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 1691 Oct 31 18:22 test_tool_vpmanager.xml
31-Oct-2023 14:22:18	-rw-r--r-- 1 casaci root 45 Oct 31 18:22 work-el7-3.8.tar.gz
31-Oct-2023 14:22:18	Done packaging working directory
31-Oct-2023 14:22:18	Finished task 'Tar work directory' with result: Success
31-Oct-2023 14:22:18	Starting task 'Parse tests' of type 'com.atlassian.bamboo.plugins.testresultparser:task.testresultparser.junit'
31-Oct-2023 14:22:18	Parsing test results under /export/home/cbt-el7-1/bamboo-home/xml-data/build-dir/CASA-CMDT86-TTOMLPY38...
31-Oct-2023 14:22:18	Finished task 'Parse tests' with result: Success
31-Oct-2023 14:22:18	Substituting variable: ${bamboo.repository.branch.name} with CAS-14234
31-Oct-2023 14:22:18	Starting task 'Upload wheel' of type 'com.atlassian.bamboo.plugins.scripttask:task.builder.script'
31-Oct-2023 14:22:18	Beginning to execute external process for build 'CASA - CMake Dev Test - CAS-14234 - Test Tools Many Linux 2.28 #2 (CASA-CMDT86-TTOMLPY38-2)' ... running command line: /export/home/cbt-el7-1/bamboo-home/temp/CASA-CMDT86-TTOMLPY38-2-ScriptBuildTask-7417125185346525046.sh ... in: /export/home/cbt-el7-1/bamboo-home/xml-data/build-dir/CASA-CMDT86-TTOMLPY38
31-Oct-2023 14:22:21	Collecting twine
31-Oct-2023 14:22:21	Downloading twine-4.0.2-py3-none-any.whl (36 kB)
31-Oct-2023 14:22:21	Collecting pkginfo>=1.8.1
31-Oct-2023 14:22:21	Downloading pkginfo-1.9.6-py3-none-any.whl (30 kB)
31-Oct-2023 14:22:21	Collecting keyring>=15.1
31-Oct-2023 14:22:21	Downloading keyring-24.2.0-py3-none-any.whl (37 kB)
31-Oct-2023 14:22:22	Collecting urllib3>=1.26.0
31-Oct-2023 14:22:22	Downloading urllib3-2.0.7-py3-none-any.whl (124 kB)
31-Oct-2023 14:22:22	━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 124.2/124.2 KB 2.2 MB/s eta 0:00:00
31-Oct-2023 14:22:22	Collecting importlib-metadata>=3.6
31-Oct-2023 14:22:22	Downloading importlib_metadata-6.8.0-py3-none-any.whl (22 kB)
31-Oct-2023 14:22:22	Collecting rfc3986>=1.4.0
31-Oct-2023 14:22:22	Downloading rfc3986-2.0.0-py2.py3-none-any.whl (31 kB)
31-Oct-2023 14:22:22	Collecting rich>=12.0.0
31-Oct-2023 14:22:22	Downloading rich-13.6.0-py3-none-any.whl (239 kB)
31-Oct-2023 14:22:22	━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 239.8/239.8 KB 5.9 MB/s eta 0:00:00
31-Oct-2023 14:22:22	Collecting readme-renderer>=35.0
31-Oct-2023 14:22:22	Downloading readme_renderer-42.0-py3-none-any.whl (13 kB)
31-Oct-2023 14:22:23	Collecting requests>=2.20
31-Oct-2023 14:22:23	Downloading requests-2.31.0-py3-none-any.whl (62 kB)
31-Oct-2023 14:22:23	━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 62.6/62.6 KB 8.3 MB/s eta 0:00:00
31-Oct-2023 14:22:23	Collecting requests-toolbelt!=0.9.0,>=0.8.0
31-Oct-2023 14:22:23	Downloading requests_toolbelt-1.0.0-py2.py3-none-any.whl (54 kB)
31-Oct-2023 14:22:23	━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 54.5/54.5 KB 8.5 MB/s eta 0:00:00
31-Oct-2023 14:22:23	Collecting zipp>=0.5
31-Oct-2023 14:22:23	Downloading zipp-3.17.0-py3-none-any.whl (7.4 kB)
31-Oct-2023 14:22:23	Collecting jaraco.classes
31-Oct-2023 14:22:23	Downloading jaraco.classes-3.3.0-py3-none-any.whl (5.9 kB)
31-Oct-2023 14:22:23	Collecting jeepney>=0.4.2
31-Oct-2023 14:22:23	Downloading jeepney-0.8.0-py3-none-any.whl (48 kB)
31-Oct-2023 14:22:23	━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 48.4/48.4 KB 6.6 MB/s eta 0:00:00
31-Oct-2023 14:22:23	Collecting SecretStorage>=3.2
31-Oct-2023 14:22:23	Downloading SecretStorage-3.3.3-py3-none-any.whl (15 kB)
31-Oct-2023 14:22:24	Collecting Pygments>=2.5.1
31-Oct-2023 14:22:24	Downloading Pygments-2.16.1-py3-none-any.whl (1.2 MB)
31-Oct-2023 14:22:24	━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 10.5 MB/s eta 0:00:00
31-Oct-2023 14:22:24	Collecting nh3>=0.2.14
31-Oct-2023 14:22:24	Downloading nh3-0.2.14-cp37-abi3-manylinux_2_17_x86_64.manylinux2014_x86_64.whl (1.7 MB)
31-Oct-2023 14:22:24	━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.7/1.7 MB 13.5 MB/s eta 0:00:00
31-Oct-2023 14:22:24	Collecting docutils>=0.13.1
31-Oct-2023 14:22:24	Downloading docutils-0.20.1-py3-none-any.whl (572 kB)
31-Oct-2023 14:22:24	━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 572.7/572.7 KB 18.6 MB/s eta 0:00:00
31-Oct-2023 14:22:24	Collecting certifi>=2017.4.17
31-Oct-2023 14:22:24	Downloading certifi-2023.7.22-py3-none-any.whl (158 kB)
31-Oct-2023 14:22:24	━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 158.3/158.3 KB 16.8 MB/s eta 0:00:00
31-Oct-2023 14:22:25	Collecting charset-normalizer<4,>=2
31-Oct-2023 14:22:25	Downloading charset_normalizer-3.3.1-cp310-cp310-manylinux_2_17_x86_64.manylinux2014_x86_64.whl (139 kB)
31-Oct-2023 14:22:25	━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 139.2/139.2 KB 17.1 MB/s eta 0:00:00
31-Oct-2023 14:22:25	Collecting idna<4,>=2.5
31-Oct-2023 14:22:25	Downloading idna-3.4-py3-none-any.whl (61 kB)
31-Oct-2023 14:22:25	━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 61.5/61.5 KB 8.8 MB/s eta 0:00:00
31-Oct-2023 14:22:25	Collecting markdown-it-py>=2.2.0
31-Oct-2023 14:22:25	Downloading markdown_it_py-3.0.0-py3-none-any.whl (87 kB)
31-Oct-2023 14:22:25	━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 87.5/87.5 KB 13.0 MB/s eta 0:00:00
31-Oct-2023 14:22:25	Collecting mdurl~=0.1
31-Oct-2023 14:22:25	Downloading mdurl-0.1.2-py3-none-any.whl (10.0 kB)
31-Oct-2023 14:22:26	Collecting cryptography>=2.0
31-Oct-2023 14:22:26	Downloading cryptography-41.0.5-cp37-abi3-manylinux_2_28_x86_64.whl (4.4 MB)
31-Oct-2023 14:22:26	━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 4.4/4.4 MB 13.8 MB/s eta 0:00:00
31-Oct-2023 14:22:26	Collecting more-itertools
31-Oct-2023 14:22:26	Downloading more_itertools-10.1.0-py3-none-any.whl (55 kB)
31-Oct-2023 14:22:26	━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 55.8/55.8 KB 7.7 MB/s eta 0:00:00
31-Oct-2023 14:22:27	Collecting cffi>=1.12
31-Oct-2023 14:22:27	Downloading cffi-1.16.0-cp310-cp310-manylinux_2_17_x86_64.manylinux2014_x86_64.whl (443 kB)
31-Oct-2023 14:22:27	━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 443.9/443.9 KB 20.6 MB/s eta 0:00:00
31-Oct-2023 14:22:27	Collecting pycparser
31-Oct-2023 14:22:27	Downloading pycparser-2.21-py2.py3-none-any.whl (118 kB)
31-Oct-2023 14:22:27	━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 118.7/118.7 KB 15.8 MB/s eta 0:00:00
31-Oct-2023 14:22:27	Installing collected packages: nh3, zipp, urllib3, rfc3986, Pygments, pycparser, pkginfo, more-itertools, mdurl, jeepney, idna, docutils, charset-normalizer, certifi, requests, readme-renderer, markdown-it-py, jaraco.classes, importlib-metadata, cffi, rich, requests-toolbelt, cryptography, SecretStorage, keyring, twine
31-Oct-2023 14:22:30	Successfully installed Pygments-2.16.1 SecretStorage-3.3.3 certifi-2023.7.22 cffi-1.16.0 charset-normalizer-3.3.1 cryptography-41.0.5 docutils-0.20.1 idna-3.4 importlib-metadata-6.8.0 jaraco.classes-3.3.0 jeepney-0.8.0 keyring-24.2.0 markdown-it-py-3.0.0 mdurl-0.1.2 more-itertools-10.1.0 nh3-0.2.14 pkginfo-1.9.6 pycparser-2.21 readme-renderer-42.0 requests-2.31.0 requests-toolbelt-1.0.0 rfc3986-2.0.0 rich-13.6.0 twine-4.0.2 urllib3-2.0.7 zipp-3.17.0
31-Oct-2023 14:22:30	WARNING: Running pip as the 'root' user can result in broken permissions and conflicting behaviour with the system package manager. It is recommended to use a virtual environment instead: https://pip.pypa.io/warnings/venv
31-Oct-2023 14:22:30	WARNING: You are using pip version 22.0.4; however, version 23.3.1 is available.
31-Oct-2023 14:22:30	You should consider upgrading via the '/usr/local/bin/python3.10 -m pip install --upgrade pip' command.
31-Oct-2023 14:22:31	Cloning into 'casa-build-utils'...
31-Oct-2023 14:22:32	Uploading distributions to
31-Oct-2023 14:22:32	https://casa-pip.nrao.edu:443/repository/casa-dev-wheel/
31-Oct-2023 14:22:33	Uploading casatools-6.6.1.2a14234.dev1-cp38-cp38-manylinux_2_28_x86_64.whl
31-Oct-2023 14:22:33
31-Oct-2023 14:22:33	0% ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 0.0/189.0 MB • --:-- • ?
31-Oct-2023 14:22:33	3% ━╺━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 6.4/189.0 MB • 00:03 • 90.2 MB/s
31-Oct-2023 14:22:34	5% ━╸━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 9.4/189.0 MB • 00:04 • 53.1 MB/s
31-Oct-2023 14:22:34	6% ━━╺━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 11.8/189.0 MB • 00:04 • 53.1 MB/s
31-Oct-2023 14:22:34	8% ━━━╺━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 14.7/189.0 MB • 00:04 • 43.6 MB/s
31-Oct-2023 14:22:34	9% ━━━╸━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 17.8/189.0 MB • 00:05 • 37.2 MB/s
31-Oct-2023 14:22:34	11% ━━━━╺━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 20.7/189.0 MB • 00:06 • 31.2 MB/s
31-Oct-2023 14:22:34	13% ━━━━━╺━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 23.7/189.0 MB • 00:07 • 27.0 MB/s
31-Oct-2023 14:22:34	14% ━━━━━╸━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 26.5/189.0 MB • 00:06 • 27.3 MB/s
31-Oct-2023 14:22:34	15% ━━━━━━╺━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 29.2/189.0 MB • 00:06 • 27.5 MB/s
31-Oct-2023 14:22:34	17% ━━━━━━╸━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 32.0/189.0 MB • 00:06 • 27.7 MB/s
31-Oct-2023 14:22:35	17% ━━━━━━╸━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 32.8/189.0 MB • 00:07 • 24.0 MB/s
31-Oct-2023 14:22:35	18% ━━━━━━━╺━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 35.0/189.0 MB • 00:07 • 24.0 MB/s
31-Oct-2023 14:22:35	20% ━━━━━━━╸━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 37.7/189.0 MB • 00:06 • 26.4 MB/s
31-Oct-2023 14:22:35	21% ━━━━━━━━╸━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 40.5/189.0 MB • 00:06 • 26.4 MB/s
31-Oct-2023 14:22:35	23% ━━━━━━━━━╺━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 43.1/189.0 MB • 00:06 • 26.6 MB/s
31-Oct-2023 14:22:35	24% ━━━━━━━━━╸━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 45.7/189.0 MB • 00:06 • 26.8 MB/s
31-Oct-2023 14:22:35	26% ━━━━━━━━━━╺━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 48.6/189.0 MB • 00:06 • 28.0 MB/s
31-Oct-2023 14:22:35	27% ━━━━━━━━━━╸━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 51.2/189.0 MB • 00:05 • 28.6 MB/s
31-Oct-2023 14:22:35	28% ━━━━━━━━━━━╺━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 53.9/189.0 MB • 00:06 • 26.1 MB/s
31-Oct-2023 14:22:35	30% ━━━━━━━━━━━╸━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 56.5/189.0 MB • 00:06 • 26.2 MB/s
31-Oct-2023 14:22:36	31% ━━━━━━━━━━━━╸━━━━━━━━━━━━━━━━━━━━━━━━━━━ 59.3/189.0 MB • 00:06 • 23.9 MB/s
31-Oct-2023 14:22:36	33% ━━━━━━━━━━━━━╺━━━━━━━━━━━━━━━━━━━━━━━━━━ 62.0/189.0 MB • 00:06 • 23.8 MB/s
31-Oct-2023 14:22:36	34% ━━━━━━━━━━━━━╸━━━━━━━━━━━━━━━━━━━━━━━━━━ 64.7/189.0 MB • 00:06 • 23.9 MB/s
31-Oct-2023 14:22:36	36% ━━━━━━━━━━━━━━╺━━━━━━━━━━━━━━━━━━━━━━━━━ 67.5/189.0 MB • 00:06 • 23.8 MB/s
31-Oct-2023 14:22:36	37% ━━━━━━━━━━━━━━╸━━━━━━━━━━━━━━━━━━━━━━━━━ 70.2/189.0 MB • 00:06 • 23.7 MB/s
31-Oct-2023 14:22:36	39% ━━━━━━━━━━━━━━━╺━━━━━━━━━━━━━━━━━━━━━━━━ 73.1/189.0 MB • 00:05 • 26.3 MB/s
31-Oct-2023 14:22:36	40% ━━━━━━━━━━━━━━━━╺━━━━━━━━━━━━━━━━━━━━━━━ 76.1/189.0 MB • 00:05 • 26.4 MB/s
31-Oct-2023 14:22:36	42% ━━━━━━━━━━━━━━━━╸━━━━━━━━━━━━━━━━━━━━━━━ 79.2/189.0 MB • 00:05 • 26.7 MB/s
31-Oct-2023 14:22:36	44% ━━━━━━━━━━━━━━━━━╸━━━━━━━━━━━━━━━━━━━━━━ 82.8/189.0 MB • 00:04 • 27.3 MB/s
31-Oct-2023 14:22:36	45% ━━━━━━━━━━━━━━━━━━╺━━━━━━━━━━━━━━━━━━━━━ 85.8/189.0 MB • 00:04 • 27.4 MB/s
31-Oct-2023 14:22:37	47% ━━━━━━━━━━━━━━━━━━╸━━━━━━━━━━━━━━━━━━━━━ 89.0/189.0 MB • 00:04 • 30.8 MB/s
31-Oct-2023 14:22:37	48% ━━━━━━━━━━━━━━━━━━━╺━━━━━━━━━━━━━━━━━━━━ 91.6/189.0 MB • 00:04 • 27.8 MB/s
31-Oct-2023 14:22:37	50% ━━━━━━━━━━━━━━━━━━━╸━━━━━━━━━━━━━━━━━━━━ 94.3/189.0 MB • 00:04 • 30.6 MB/s
31-Oct-2023 14:22:37	51% ━━━━━━━━━━━━━━━━━━━━╸━━━━━━━━━━━━━━━━━━━ 97.0/189.0 MB • 00:04 • 30.3 MB/s
31-Oct-2023 14:22:37	53% ━━━━━━━━━━━━━━━━━━━━━╺━━━━━━━━━━━━━━━━━━ 99.5/189.0 MB • 00:04 • 26.9 MB/s
31-Oct-2023 14:22:37	54% ━━━━━━━━━━━━━━━━━━━━━╸━━━━━━━━━━━━━━━━━━ 102.1/189.0 MB • 00:04 • 26.8 MB/s
31-Oct-2023 14:22:37	55% ━━━━━━━━━━━━━━━━━━━━━━╺━━━━━━━━━━━━━━━━━ 104.6/189.0 MB • 00:04 • 26.6 MB/s
31-Oct-2023 14:22:37	57% ━━━━━━━━━━━━━━━━━━━━━━╸━━━━━━━━━━━━━━━━━ 107.3/189.0 MB • 00:04 • 26.8 MB/s
31-Oct-2023 14:22:37	58% ━━━━━━━━━━━━━━━━━━━━━━━╺━━━━━━━━━━━━━━━━ 109.9/189.0 MB • 00:03 • 26.9 MB/s
31-Oct-2023 14:22:38	60% ━━━━━━━━━━━━━━━━━━━━━━━╸━━━━━━━━━━━━━━━━ 112.5/189.0 MB • 00:03 • 27.1 MB/s
31-Oct-2023 14:22:38	61% ━━━━━━━━━━━━━━━━━━━━━━━━╺━━━━━━━━━━━━━━━ 115.0/189.0 MB • 00:03 • 27.5 MB/s
31-Oct-2023 14:22:38	62% ━━━━━━━━━━━━━━━━━━━━━━━━╸━━━━━━━━━━━━━━━ 117.5/189.0 MB • 00:03 • 27.5 MB/s
31-Oct-2023 14:22:38	64% ━━━━━━━━━━━━━━━━━━━━━━━━━╺━━━━━━━━━━━━━━ 120.3/189.0 MB • 00:03 • 24.8 MB/s
31-Oct-2023 14:22:38	65% ━━━━━━━━━━━━━━━━━━━━━━━━━━╺━━━━━━━━━━━━━ 123.4/189.0 MB • 00:03 • 24.7 MB/s
31-Oct-2023 14:22:38	67% ━━━━━━━━━━━━━━━━━━━━━━━━━━╸━━━━━━━━━━━━━ 126.8/189.0 MB • 00:03 • 27.6 MB/s
31-Oct-2023 14:22:38	69% ━━━━━━━━━━━━━━━━━━━━━━━━━━━╸━━━━━━━━━━━━ 130.4/189.0 MB • 00:03 • 27.9 MB/s
31-Oct-2023 14:22:38	70% ━━━━━━━━━━━━━━━━━━━━━━━━━━━━╺━━━━━━━━━━━ 133.1/189.0 MB • 00:03 • 27.8 MB/s
31-Oct-2023 14:22:38	72% ━━━━━━━━━━━━━━━━━━━━━━━━━━━━╸━━━━━━━━━━━ 135.5/189.0 MB • 00:02 • 27.5 MB/s
31-Oct-2023 14:22:38	73% ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━╺━━━━━━━━━━ 138.3/189.0 MB • 00:02 • 27.2 MB/s
31-Oct-2023 14:22:39	74% ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━╸━━━━━━━━━━ 140.3/189.0 MB • 00:02 • 26.5 MB/s
31-Oct-2023 14:22:39	76% ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━╺━━━━━━━━━ 143.2/189.0 MB • 00:02 • 26.3 MB/s
31-Oct-2023 14:22:39	78% ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━╺━━━━━━━━ 146.7/189.0 MB • 00:02 • 26.0 MB/s
31-Oct-2023 14:22:39	79% ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━╸━━━━━━━━ 149.0/189.0 MB • 00:02 • 26.1 MB/s
31-Oct-2023 14:22:39	80% ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━╺━━━━━━━ 151.8/189.0 MB • 00:02 • 26.4 MB/s
31-Oct-2023 14:22:39	82% ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━╸━━━━━━━ 154.4/189.0 MB • 00:02 • 26.7 MB/s
31-Oct-2023 14:22:39	83% ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━╺━━━━━━ 157.0/189.0 MB • 00:02 • 27.4 MB/s
31-Oct-2023 14:22:39	84% ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━╸━━━━━━ 159.4/189.0 MB • 00:02 • 27.4 MB/s
31-Oct-2023 14:22:39	86% ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━╺━━━━━ 162.0/189.0 MB • 00:01 • 27.4 MB/s
31-Oct-2023 14:22:40	87% ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━╸━━━━━ 164.6/189.0 MB • 00:01 • 27.4 MB/s
31-Oct-2023 14:22:40	88% ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━╺━━━━ 167.1/189.0 MB • 00:01 • 27.5 MB/s
31-Oct-2023 14:22:40	90% ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━╸━━━━ 169.6/189.0 MB • 00:01 • 27.5 MB/s
31-Oct-2023 14:22:40	91% ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━╺━━━ 172.4/189.0 MB • 00:01 • 24.7 MB/s
31-Oct-2023 14:22:40	93% ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━╺━━ 175.3/189.0 MB • 00:01 • 27.4 MB/s
31-Oct-2023 14:22:40	94% ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━╸━━ 177.7/189.0 MB • 00:01 • 26.6 MB/s
31-Oct-2023 14:22:40	95% ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━╺━ 180.5/189.0 MB • 00:01 • 26.6 MB/s
31-Oct-2023 14:22:40	97% ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━╸━ 183.4/189.0 MB • 00:01 • 23.9 MB/s
31-Oct-2023 14:22:40	99% ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━╺ 186.3/189.0 MB • 00:01 • 26.5 MB/s
31-Oct-2023 14:22:40	100% ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 189.0/189.0 MB • 00:07 • 26.7 MB/s
31-Oct-2023 14:22:41	100% ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 189.0/189.0 MB • 00:07 • 26.7 MB/s
31-Oct-2023 14:22:41	100% ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 189.0/189.0 MB • 00:07 • 26.7 MB/s
31-Oct-2023 14:22:41	100% ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 189.0/189.0 MB • 00:07 • 26.7 MB/s
31-Oct-2023 14:22:41	100% ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 189.0/189.0 MB • 00:07 • 26.7 MB/s
31-Oct-2023 14:22:41	100% ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 189.0/189.0 MB • 00:07 • 26.7 MB/s
31-Oct-2023 14:22:41	WARNING Error during upload. Retry with the --verbose option for more details.
31-Oct-2023 14:22:41	ERROR HTTPError: 400 Bad Request from
31-Oct-2023 14:22:41	https://casa-pip.nrao.edu:443/repository/casa-dev-wheel/
31-Oct-2023 14:22:41	Repository does not allow updating assets: casa-dev-wheel
31-Oct-2023 14:22:41	Uploading distributions to
31-Oct-2023 14:22:41	https://casa-pip.nrao.edu:443/repository/casa-dev-wheel/
31-Oct-2023 14:22:41	Uploading casatestutils-6.6.1.2a14234.dev1-py3-none-any.whl
31-Oct-2023 14:22:41
31-Oct-2023 14:22:41	0% ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 0.0/125.1 kB • --:-- • ?
31-Oct-2023 14:22:41	100% ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 125.1/125.1 kB • 00:00 • 49.8 MB/s
31-Oct-2023 14:22:41	WARNING Error during upload. Retry with the --verbose option for more details.
31-Oct-2023 14:22:41	ERROR HTTPError: 400 Bad Request from
31-Oct-2023 14:22:41	https://casa-pip.nrao.edu:443/repository/casa-dev-wheel/
31-Oct-2023 14:22:41	Repository does not allow updating assets: casa-dev-wheel
31-Oct-2023 14:22:42	Finished task 'Upload wheel' with result: Success
31-Oct-2023 14:22:42	Starting task 'Cleanup' of type 'com.atlassian.bamboo.plugins.scripttask:task.builder.script'
31-Oct-2023 14:22:42	Beginning to execute external process for build 'CASA - CMake Dev Test - CAS-14234 - Test Tools Many Linux 2.28 #2 (CASA-CMDT86-TTOMLPY38-2)' ... running command line: /export/home/cbt-el7-1/bamboo-home/temp/CASA-CMDT86-TTOMLPY38-2-ScriptBuildTask-6146311668812773524.sh ... in: /export/home/cbt-el7-1/bamboo-home/xml-data/build-dir/CASA-CMDT86-TTOMLPY38
31-Oct-2023 14:22:42	Starting cleanup
31-Oct-2023 14:22:53	wheel-container-test
31-Oct-2023 14:22:55	wheel-container-test
31-Oct-2023 14:22:55	Cleanup complete
31-Oct-2023 14:22:55	Finished task 'Cleanup' with result: Success
31-Oct-2023 14:22:55	Running post build plugin 'Docker Container Cleanup'
31-Oct-2023 14:22:55	Beginning to execute external process for build 'CASA - CMake Dev Test - CAS-14234 - Test Tools Many Linux 2.28 #2 (CASA-CMDT86-TTOMLPY38-2)' ... running command line: /bin/docker rm -f wheel-container-test ... in: /export/home/cbt-el7-1/bamboo-home/xml-data/build-dir/CASA-CMDT86-TTOMLPY38
31-Oct-2023 14:22:55	Error response from daemon: No such container: wheel-container-test
31-Oct-2023 14:22:55	Running post build plugin 'NCover Results Collector'
31-Oct-2023 14:22:55	Running post build plugin 'Clover Results Collector'
31-Oct-2023 14:22:55	Running post build plugin 'npm Cache Cleanup'
31-Oct-2023 14:22:55	Running post build plugin 'Artifact Copier'
31-Oct-2023 14:22:55	Publishing an artifact: Workdir
31-Oct-2023 14:22:55	Finished publishing of artifact Non required job artifact: [Workdir], pattern: [work*.tar.gz] anchored at: [wheeldirectory/] in 110.0 ms
31-Oct-2023 14:22:55	Publishing an artifact: Tests
31-Oct-2023 14:22:55	Finished publishing of artifact Non required job artifact: [Tests], pattern: [*.xml] anchored at: [wheeldirectory/] in 149.6 ms
31-Oct-2023 14:22:55	Publishing an artifact: xml Directories
31-Oct-2023 14:22:55	Finished publishing of artifact Non required job artifact: [xml Directories], pattern: [*/.xml] anchored at: [wheeldirectory/] in 186.2 ms
31-Oct-2023 14:22:55	Finalising the build...
31-Oct-2023 14:22:55	Stopping timer.
31-Oct-2023 14:22:55	Build CASA-CMDT86-TTOMLPY38-2 completed.
31-Oct-2023 14:22:55	Running on server: post build plugin 'NCover Results Collector'
31-Oct-2023 14:22:55	Running on server: post build plugin 'Build Hanging Detection Configuration'
31-Oct-2023 14:22:55	Running on server: post build plugin 'Clover Delta Calculator'
31-Oct-2023 14:22:55	Running on server: post build plugin 'Maven Dependencies Postprocessor'
31-Oct-2023 14:22:55	All post build plugins have finished
31-Oct-2023 14:22:55	Generating build results summary...
31-Oct-2023 14:22:56	Saving build results to disk...
31-Oct-2023 14:22:56	Store variable context...
31-Oct-2023 14:22:56	Indexing build results...
31-Oct-2023 14:22:56	Finished building CASA-CMDT86-TTOMLPY38-2.

Build: #2 did not complete

Job: Test Tools Many Linux 2.28 was successful

Stages & jobs

Default Stage

Publish

Create Upload Plan Branch

Build log

Build #2

Build: #2 did not complete

Job: Test Tools Many Linux 2.28 was successful

Stages & jobs

Default Stage

Publish

Create Upload Plan Branch

Build log