Build log

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

20-Apr-2026 14:58:08	2026-04-20 18:58:09 INFO showcache:: 14: "/home/casatest/casa6/casatestutils/nosedir/test_tool_calibrater/gaincaltest2.ms/SYSCAL"
20-Apr-2026 14:58:08	2026-04-20 18:58:09 INFO showcache:: 15: "/home/casatest/casa6/casatestutils/nosedir/test_tool_calibrater/gaincaltest2.ms/WEATHER"
20-Apr-2026 14:58:08	2026-04-20 18:58:09 WARN calibrater::setvi(bool,bool) Already using NEW VisibilityIterator.
20-Apr-2026 14:58:08	test_tool_calibrater.py::calibrater_test::test_done
20-Apr-2026 14:58:08	Check that done closes the active calibrator tool
20-Apr-2026 14:58:08	PASSED
20-Apr-2026 14:58:08
20-Apr-2026 14:58:08	2026-04-20 18:58:09 WARN calibrater::setvi(bool,bool) Forcing use of OLD VisibilityIterator.
20-Apr-2026 14:58:08	2026-04-20 18:58:09 INFO calibrater::open **Using OLD VI-driven calibrater tool**
20-Apr-2026 14:58:08	2026-04-20 18:58:09 INFO calibrater::open Opening MS: gaincaltest2.ms for calibration.
20-Apr-2026 14:58:08	2026-04-20 18:58:09 INFO Clearing all model records in MS header.
20-Apr-2026 14:58:08	2026-04-20 18:58:09 INFO VisSetUtil::addScrCols Adding MODEL_DATA and CORRECTED_DATA column(s).
20-Apr-2026 14:58:10	2026-04-20 18:58:11 INFO VisSetUtil::initScrCols Initializing MODEL_DATA to (unity).
20-Apr-2026 14:58:11	2026-04-20 18:58:11 INFO VisSetUtil::initScrCols Initialized 328860 rows.
20-Apr-2026 14:58:11	2026-04-20 18:58:11 INFO Calibrater:: Initializing nominal selection to the whole MS.
20-Apr-2026 14:58:11	2026-04-20 18:58:11 INFO calibrater::setapply Beginning setapply--(MSSelection version)-------
20-Apr-2026 14:58:11	2026-04-20 18:58:11 INFO Calibrater::setapply(type, applypar) Arranging to APPLY:
20-Apr-2026 14:58:11	2026-04-20 18:58:11 INFO Calibrater::setapply(type, applypar) . G Jones: table=gaincaltest2.ms.G0 select= interp=linear spwmap=[-1] calWt=false
20-Apr-2026 14:58:11	2026-04-20 18:58:11 INFO calibrater::correct Beginning correct---------------------------
20-Apr-2026 14:58:11	2026-04-20 18:58:11 INFO Calibrater::correct2 (VI2/VB2) The following calibration terms are arranged for apply:
20-Apr-2026 14:58:11	2026-04-20 18:58:11 INFO Calibrater::correct2 (VI2/VB2) . G Jones: table=gaincaltest2.ms.G0 select= interp=linear spwmap=[-1] calWt=false
20-Apr-2026 14:58:15	2026-04-20 18:58:15 INFO calibrater::correct Finished correcting.
20-Apr-2026 14:58:15	2026-04-20 18:58:16 INFO calibrater::open **Using OLD VI-driven calibrater tool**
20-Apr-2026 14:58:15	2026-04-20 18:58:16 INFO calibrater::open Opening MS: gaincaltest2.ms for calibration.
20-Apr-2026 14:58:15	2026-04-20 18:58:16 INFO Calibrater:: Initializing nominal selection to the whole MS.
20-Apr-2026 14:58:15	2026-04-20 18:58:16 INFO calibrater::initcalset Beginning initcalset------------------------
20-Apr-2026 14:58:16	2026-04-20 18:58:16 INFO VisSet::VisSet Initializing MODEL_DATA (to unity) and CORRECTED_DATA (to DATA)
20-Apr-2026 14:58:16	2026-04-20 18:58:16 INFO VisSet::VisSet Initialized 328860 rows.
20-Apr-2026 14:58:18	2026-04-20 18:58:18 WARN calibrater::setvi(bool,bool) Forcing use of NEW VisibilityIterator.
20-Apr-2026 14:58:18	test_tool_calibrater.py::calibrater_test::test_reinitModel
20-Apr-2026 14:58:18	Check that initcalset will reset the CORRECTED_DATA to unity
20-Apr-2026 14:58:18	PASSED
20-Apr-2026 14:58:18
20-Apr-2026 14:58:18	2026-04-20 18:58:18 INFO calibrater::open **Using NEW VI2-driven calibrater tool**
20-Apr-2026 14:58:18	2026-04-20 18:58:18 INFO calibrater::open Opening MS: gaincaltest2.ms for calibration.
20-Apr-2026 14:58:18	2026-04-20 18:58:18 INFO Clearing all model records in MS header.
20-Apr-2026 14:58:18	2026-04-20 18:58:18 INFO VisSetUtil::addScrCols Adding MODEL_DATA and CORRECTED_DATA column(s).
20-Apr-2026 14:58:20	2026-04-20 18:58:20 INFO VisSetUtil::initScrCols Initializing MODEL_DATA to (unity).
20-Apr-2026 14:58:20	2026-04-20 18:58:20 INFO VisSetUtil::initScrCols Initialized 328860 rows.
20-Apr-2026 14:58:20	2026-04-20 18:58:20 INFO Calibrater:: Initializing nominal selection to the whole MS.
20-Apr-2026 14:58:20	2026-04-20 18:58:20 INFO calibrater::setapply Beginning setapply--(MSSelection version)-------
20-Apr-2026 14:58:20	2026-04-20 18:58:20 INFO Calibrater::setapply(type, applypar) Arranging to APPLY:
20-Apr-2026 14:58:20	2026-04-20 18:58:21 INFO Calibrater::setapply(type, applypar) . G Jones: table=gaincaltest2.ms.G0 select= interp=linear spwmap=[-1] calWt=false
20-Apr-2026 14:58:20	2026-04-20 18:58:21 INFO calibrater::setsolve Beginning setsolve--(MSSelection version)-------
20-Apr-2026 14:58:20	2026-04-20 18:58:21 INFO Calibrater::setsolve Arranging to SOLVE:
20-Apr-2026 14:58:20	2026-04-20 18:58:21 INFO Calibrater::setsolve . Mf Mueller: table=gaincaltest2.ms.G0 append=false solint=inf,none refantmode='flex' refant='none' minsnr=0 apmode=AP solnorm=false
20-Apr-2026 14:58:20	2026-04-20 18:58:21 INFO calibrater::reset Reseting solve/apply state
20-Apr-2026 14:58:20	2026-04-20 18:58:21 INFO calibrater::solve Beginning solve-----------------------------
20-Apr-2026 14:58:20	2026-04-20 18:58:21 SEVERE Calibrater::solve Caught exception: Please run setsolve before attempting to solve.
20-Apr-2026 14:58:20	2026-04-20 18:58:21 INFO Calibrater::solve Reseting entire solve/apply state.
20-Apr-2026 14:58:20	2026-04-20 18:58:21 SEVERE Exception Reported: Error in Calibrater::solve.
20-Apr-2026 14:58:20	2026-04-20 18:58:21 INFO calibrater::correct Beginning correct---------------------------
20-Apr-2026 14:58:20	2026-04-20 18:58:21 INFO Calibrater::correct2 (VI2/VB2) The following calibration terms are arranged for apply:
20-Apr-2026 14:58:20	2026-04-20 18:58:21 INFO Calibrater::correct2 (VI2/VB2) . (None)
20-Apr-2026 14:58:20	2026-04-20 18:58:21 SEVERE Calibrater::correct2 (VI2/VB2) Caught exception: Nothing to Apply
20-Apr-2026 14:58:20	2026-04-20 18:58:21 INFO Calibrater::correct2 (VI2/VB2) Resetting all calibration application settings.
20-Apr-2026 14:58:20	2026-04-20 18:58:21 SEVERE Exception Reported: Error in Calibrater::correct.
20-Apr-2026 14:58:20	2026-04-20 18:58:21 WARN calibrater::setvi(bool,bool) Already using NEW VisibilityIterator.
20-Apr-2026 14:58:20	test_tool_calibrater.py::calibrater_test::test_resetSolveApply
20-Apr-2026 14:58:20	Check that the reset function can clear set apply and solves
20-Apr-2026 14:58:20	PASSED
20-Apr-2026 14:58:20
20-Apr-2026 14:58:21	2026-04-20 18:58:21 INFO calibrater::open **Using NEW VI2-driven calibrater tool**
20-Apr-2026 14:58:21	2026-04-20 18:58:21 INFO calibrater::open Opening MS: gaincaltest2.ms for calibration.
20-Apr-2026 14:58:21	2026-04-20 18:58:21 INFO Clearing all model records in MS header.
20-Apr-2026 14:58:21	2026-04-20 18:58:21 INFO VisSetUtil::addScrCols Adding MODEL_DATA and CORRECTED_DATA column(s).
20-Apr-2026 14:58:23	2026-04-20 18:58:23 INFO VisSetUtil::initScrCols Initializing MODEL_DATA to (unity).
20-Apr-2026 14:58:23	2026-04-20 18:58:23 INFO VisSetUtil::initScrCols Initialized 328860 rows.
20-Apr-2026 14:58:23	2026-04-20 18:58:23 INFO Calibrater:: Initializing nominal selection to the whole MS.
20-Apr-2026 14:58:24	2026-04-20 18:58:24 INFO calibrater::setdata Beginning selectvis--(MSSelection version)-------
20-Apr-2026 14:58:24	2026-04-20 18:58:24 INFO calibrater::reset Reseting solve/apply state
20-Apr-2026 14:58:24	2026-04-20 18:58:24 INFO Calibrater::selectvis Performing selection on MeasurementSet
20-Apr-2026 14:58:24	2026-04-20 18:58:24 INFO Calibrater::selectvis+ Selecting on spw: '1'
20-Apr-2026 14:58:24	2026-04-20 18:58:24 INFO Calibrater::selectvis By selection 328860 rows are reduced to 82215
20-Apr-2026 14:58:24	2026-04-20 18:58:24 INFO Calibrater::selectvis Frequency selection:
20-Apr-2026 14:58:24	2026-04-20 18:58:24 INFO Calibrater::selectvis . Spw 1:0~7 (8 channels, step by 1)
20-Apr-2026 14:58:24	2026-04-20 18:58:24 INFO calibrater::setdata chanmode=none nchan=1 start=0 step=1 mStart='0km/s' mStep='0km/s' msSelect=''
20-Apr-2026 14:58:24	2026-04-20 18:58:24 WARN calibrater::setvi(bool,bool) Already using NEW VisibilityIterator.
20-Apr-2026 14:58:24	test_tool_calibrater.py::calibrater_test::test_returnDict
20-Apr-2026 14:58:24	Check that the returndict function gives a dictonary with the expected keys
20-Apr-2026 14:58:24	PASSED
20-Apr-2026 14:58:24
20-Apr-2026 14:58:25	2026-04-20 18:58:26 INFO calibrater::open **Using NEW VI2-driven calibrater tool**
20-Apr-2026 14:58:25	2026-04-20 18:58:26 INFO calibrater::open Opening MS: gaincaltest2.ms for calibration.
20-Apr-2026 14:58:25	2026-04-20 18:58:26 INFO Clearing all model records in MS header.
20-Apr-2026 14:58:25	2026-04-20 18:58:26 INFO VisSetUtil::addScrCols Adding MODEL_DATA and CORRECTED_DATA column(s).
20-Apr-2026 14:58:27	2026-04-20 18:58:27 INFO VisSetUtil::initScrCols Initializing MODEL_DATA to (unity).
20-Apr-2026 14:58:27	2026-04-20 18:58:28 INFO VisSetUtil::initScrCols Initialized 328860 rows.
20-Apr-2026 14:58:27	2026-04-20 18:58:28 INFO Calibrater:: Initializing nominal selection to the whole MS.
20-Apr-2026 14:58:27	2026-04-20 18:58:28 INFO calibrater::setdata Beginning selectvis--(MSSelection version)-------
20-Apr-2026 14:58:27	2026-04-20 18:58:28 INFO calibrater::reset Reseting solve/apply state
20-Apr-2026 14:58:27	2026-04-20 18:58:28 INFO Calibrater::selectvis Performing selection on MeasurementSet
20-Apr-2026 14:58:27	2026-04-20 18:58:28 INFO Calibrater::selectvis+ Selecting on antenna/baseline: '0'
20-Apr-2026 14:58:27	2026-04-20 18:58:28 INFO Calibrater::selectvis By selection 328860 rows are reduced to 65772
20-Apr-2026 14:58:27	2026-04-20 18:58:28 INFO Calibrater::selectvis Frequency selection: Selecting all channels in all spws.
20-Apr-2026 14:58:27	2026-04-20 18:58:28 INFO calibrater::setdata chanmode=none nchan=1 start=0 step=1 mStart='0km/s' mStep='0km/s' msSelect=''
20-Apr-2026 14:58:27	2026-04-20 18:58:28 INFO calibrater::setapply Beginning setapply--(MSSelection version)-------
20-Apr-2026 14:58:27	2026-04-20 18:58:28 INFO Calibrater::setapply(type, applypar) Arranging to APPLY:
20-Apr-2026 14:58:27	2026-04-20 18:58:28 INFO Calibrater::setapply(type, applypar) . G Jones: table=gaincaltest2.ms.G0 select= interp=linear spwmap=[-1] calWt=false
20-Apr-2026 14:58:27	2026-04-20 18:58:28 INFO calibrater::correct Beginning correct---------------------------
20-Apr-2026 14:58:27	2026-04-20 18:58:28 INFO Calibrater::correct2 (VI2/VB2) The following calibration terms are arranged for apply:
20-Apr-2026 14:58:27	2026-04-20 18:58:28 INFO Calibrater::correct2 (VI2/VB2) . G Jones: table=gaincaltest2.ms.G0 select= interp=linear spwmap=[-1] calWt=false
20-Apr-2026 14:58:30	2026-04-20 18:58:30 INFO calibrater::correct Finished correcting.
20-Apr-2026 14:58:31	2026-04-20 18:58:31 WARN calibrater::setvi(bool,bool) Already using NEW VisibilityIterator.
20-Apr-2026 14:58:31	test_tool_calibrater.py::calibrater_test::test_selectVisBaseline
20-Apr-2026 14:58:31	Check that selectvis properly selects baseline/antenna
20-Apr-2026 14:58:31	65772 65772
20-Apr-2026 14:58:31	263088 263088
20-Apr-2026 14:58:31	PASSED
20-Apr-2026 14:58:31
20-Apr-2026 14:58:32	2026-04-20 18:58:32 INFO calibrater::open **Using NEW VI2-driven calibrater tool**
20-Apr-2026 14:58:32	2026-04-20 18:58:32 INFO calibrater::open Opening MS: gaincaltest2.ms for calibration.
20-Apr-2026 14:58:32	2026-04-20 18:58:32 INFO Clearing all model records in MS header.
20-Apr-2026 14:58:32	2026-04-20 18:58:32 INFO VisSetUtil::addScrCols Adding MODEL_DATA and CORRECTED_DATA column(s).
20-Apr-2026 14:58:34	2026-04-20 18:58:34 INFO VisSetUtil::initScrCols Initializing MODEL_DATA to (unity).
20-Apr-2026 14:58:34	2026-04-20 18:58:35 INFO VisSetUtil::initScrCols Initialized 328860 rows.
20-Apr-2026 14:58:34	2026-04-20 18:58:35 INFO Calibrater:: Initializing nominal selection to the whole MS.
20-Apr-2026 14:58:34	2026-04-20 18:58:35 INFO calibrater::setdata Beginning selectvis--(MSSelection version)-------
20-Apr-2026 14:58:34	2026-04-20 18:58:35 INFO calibrater::reset Reseting solve/apply state
20-Apr-2026 14:58:34	2026-04-20 18:58:35 INFO Calibrater::selectvis Performing selection on MeasurementSet
20-Apr-2026 14:58:34	2026-04-20 18:58:35 INFO Calibrater::selectvis+ Selecting on field: '0'
20-Apr-2026 14:58:34	2026-04-20 18:58:35 INFO Calibrater::selectvis By selection 328860 rows are reduced to 172260
20-Apr-2026 14:58:34	2026-04-20 18:58:35 INFO Calibrater::selectvis Frequency selection: Selecting all channels in all spws.
20-Apr-2026 14:58:34	2026-04-20 18:58:35 INFO calibrater::setdata chanmode=none nchan=1 start=0 step=1 mStart='0km/s' mStep='0km/s' msSelect=''
20-Apr-2026 14:58:34	2026-04-20 18:58:35 INFO calibrater::setapply Beginning setapply--(MSSelection version)-------
20-Apr-2026 14:58:34	2026-04-20 18:58:35 INFO Calibrater::setapply(type, applypar) Arranging to APPLY:
20-Apr-2026 14:58:34	2026-04-20 18:58:35 INFO Calibrater::setapply(type, applypar) . G Jones: table=gaincaltest2.ms.G0 select= interp=linear spwmap=[-1] calWt=false
20-Apr-2026 14:58:34	2026-04-20 18:58:35 INFO calibrater::correct Beginning correct---------------------------
20-Apr-2026 14:58:34	2026-04-20 18:58:35 INFO Calibrater::correct2 (VI2/VB2) The following calibration terms are arranged for apply:
20-Apr-2026 14:58:34	2026-04-20 18:58:35 INFO Calibrater::correct2 (VI2/VB2) . G Jones: table=gaincaltest2.ms.G0 select= interp=linear spwmap=[-1] calWt=false
20-Apr-2026 14:58:36	2026-04-20 18:58:37 INFO calibrater::correct Finished correcting.
20-Apr-2026 14:58:37	2026-04-20 18:58:37 WARN calibrater::setvi(bool,bool) Already using NEW VisibilityIterator.
20-Apr-2026 14:58:37	test_tool_calibrater.py::calibrater_test::test_selectVisField
20-Apr-2026 14:58:37	Check that the field is properly selected by selectvis
20-Apr-2026 14:58:37	PASSED
20-Apr-2026 14:58:37
20-Apr-2026 14:58:38	2026-04-20 18:58:38 INFO calibrater::open **Using NEW VI2-driven calibrater tool**
20-Apr-2026 14:58:38	2026-04-20 18:58:38 INFO calibrater::open Opening MS: gaincaltest2.ms for calibration.
20-Apr-2026 14:58:38	2026-04-20 18:58:38 INFO Clearing all model records in MS header.
20-Apr-2026 14:58:38	2026-04-20 18:58:38 INFO VisSetUtil::addScrCols Adding MODEL_DATA and CORRECTED_DATA column(s).
20-Apr-2026 14:58:40	2026-04-20 18:58:40 INFO VisSetUtil::initScrCols Initializing MODEL_DATA to (unity).
20-Apr-2026 14:58:40	2026-04-20 18:58:41 INFO VisSetUtil::initScrCols Initialized 328860 rows.
20-Apr-2026 14:58:40	2026-04-20 18:58:41 INFO Calibrater:: Initializing nominal selection to the whole MS.
20-Apr-2026 14:58:40	2026-04-20 18:58:41 INFO calibrater::setdata Beginning selectvis--(MSSelection version)-------
20-Apr-2026 14:58:40	2026-04-20 18:58:41 INFO calibrater::reset Reseting solve/apply state
20-Apr-2026 14:58:40	2026-04-20 18:58:41 INFO Calibrater::selectvis Performing selection on MeasurementSet
20-Apr-2026 14:58:40	2026-04-20 18:58:41 INFO Calibrater::selectvis+ Selecting on intent: 'AMPLI'
20-Apr-2026 14:58:40	2026-04-20 18:58:41 INFO Calibrater::selectvis Selection did not drop any rows
20-Apr-2026 14:58:40	2026-04-20 18:58:41 INFO Calibrater::selectvis Frequency selection: Selecting all channels in all spws.
20-Apr-2026 14:58:40	2026-04-20 18:58:41 INFO calibrater::setdata chanmode=none nchan=1 start=0 step=1 mStart='0km/s' mStep='0km/s' msSelect=''
20-Apr-2026 14:58:40	2026-04-20 18:58:41 INFO calibrater::setapply Beginning setapply--(MSSelection version)-------
20-Apr-2026 14:58:40	2026-04-20 18:58:41 INFO Calibrater::setapply(type, applypar) Arranging to APPLY:
20-Apr-2026 14:58:40	2026-04-20 18:58:41 INFO Calibrater::setapply(type, applypar) . G Jones: table=gaincaltest2.ms.G0 select= interp=linear spwmap=[-1] calWt=false
20-Apr-2026 14:58:40	2026-04-20 18:58:41 INFO calibrater::correct Beginning correct---------------------------
20-Apr-2026 14:58:40	2026-04-20 18:58:41 INFO Calibrater::correct2 (VI2/VB2) The following calibration terms are arranged for apply:
20-Apr-2026 14:58:40	2026-04-20 18:58:41 INFO Calibrater::correct2 (VI2/VB2) . G Jones: table=gaincaltest2.ms.G0 select= interp=linear spwmap=[-1] calWt=false
20-Apr-2026 14:58:44	2026-04-20 18:58:44 INFO calibrater::correct Finished correcting.
20-Apr-2026 14:58:44	2026-04-20 18:58:44 WARN calibrater::setvi(bool,bool) Already using NEW VisibilityIterator.
20-Apr-2026 14:58:44	test_tool_calibrater.py::calibrater_test::test_selectVisIntent
20-Apr-2026 14:58:44	Check that the intent is properly selected by selectvis
20-Apr-2026 14:58:44	PASSED
20-Apr-2026 14:58:44
20-Apr-2026 14:58:45	2026-04-20 18:58:46 INFO calibrater::open **Using NEW VI2-driven calibrater tool**
20-Apr-2026 14:58:45	2026-04-20 18:58:46 INFO calibrater::open Opening MS: gaincaltest2.ms for calibration.
20-Apr-2026 14:58:45	2026-04-20 18:58:46 INFO Clearing all model records in MS header.
20-Apr-2026 14:58:45	2026-04-20 18:58:46 INFO VisSetUtil::addScrCols Adding MODEL_DATA and CORRECTED_DATA column(s).
20-Apr-2026 14:58:47	2026-04-20 18:58:47 INFO VisSetUtil::initScrCols Initializing MODEL_DATA to (unity).
20-Apr-2026 14:58:47	2026-04-20 18:58:48 INFO VisSetUtil::initScrCols Initialized 328860 rows.
20-Apr-2026 14:58:47	2026-04-20 18:58:48 INFO Calibrater:: Initializing nominal selection to the whole MS.
20-Apr-2026 14:58:47	2026-04-20 18:58:48 INFO calibrater::setdata Beginning selectvis--(MSSelection version)-------
20-Apr-2026 14:58:47	2026-04-20 18:58:48 INFO calibrater::reset Reseting solve/apply state
20-Apr-2026 14:58:47	2026-04-20 18:58:48 INFO Calibrater::selectvis Performing selection on MeasurementSet
20-Apr-2026 14:58:47	2026-04-20 18:58:48 INFO Calibrater::selectvis+ Selecting by observation IDs: '0'
20-Apr-2026 14:58:47	2026-04-20 18:58:48 INFO Calibrater::selectvis By selection 328860 rows are reduced to 318870
20-Apr-2026 14:58:47	2026-04-20 18:58:48 INFO Calibrater::selectvis Frequency selection: Selecting all channels in all spws.
20-Apr-2026 14:58:47	2026-04-20 18:58:48 INFO calibrater::setdata chanmode=none nchan=1 start=0 step=1 mStart='0km/s' mStep='0km/s' msSelect=''
20-Apr-2026 14:58:47	2026-04-20 18:58:48 INFO calibrater::setapply Beginning setapply--(MSSelection version)-------
20-Apr-2026 14:58:47	2026-04-20 18:58:48 INFO Calibrater::setapply(type, applypar) Arranging to APPLY:
20-Apr-2026 14:58:47	2026-04-20 18:58:48 INFO Calibrater::setapply(type, applypar) . G Jones: table=gaincaltest2.ms.G0 select= interp=linear spwmap=[-1] calWt=false
20-Apr-2026 14:58:47	2026-04-20 18:58:48 INFO calibrater::correct Beginning correct---------------------------
20-Apr-2026 14:58:47	2026-04-20 18:58:48 INFO Calibrater::correct2 (VI2/VB2) The following calibration terms are arranged for apply:
20-Apr-2026 14:58:47	2026-04-20 18:58:48 INFO Calibrater::correct2 (VI2/VB2) . G Jones: table=gaincaltest2.ms.G0 select= interp=linear spwmap=[-1] calWt=false
20-Apr-2026 14:58:51	2026-04-20 18:58:52 INFO calibrater::correct Finished correcting.
20-Apr-2026 14:58:51	2026-04-20 18:58:52 WARN calibrater::setvi(bool,bool) Already using NEW VisibilityIterator.
20-Apr-2026 14:58:51	test_tool_calibrater.py::calibrater_test::test_selectVisObs
20-Apr-2026 14:58:51	PASSED
20-Apr-2026 14:58:51
20-Apr-2026 14:58:52	2026-04-20 18:58:53 INFO calibrater::open **Using NEW VI2-driven calibrater tool**
20-Apr-2026 14:58:52	2026-04-20 18:58:53 INFO calibrater::open Opening MS: gaincaltest2.ms for calibration.
20-Apr-2026 14:58:52	2026-04-20 18:58:53 INFO Clearing all model records in MS header.
20-Apr-2026 14:58:52	2026-04-20 18:58:53 INFO VisSetUtil::addScrCols Adding MODEL_DATA and CORRECTED_DATA column(s).
20-Apr-2026 14:58:54	2026-04-20 18:58:55 INFO VisSetUtil::initScrCols Initializing MODEL_DATA to (unity).
20-Apr-2026 14:58:54	2026-04-20 18:58:55 INFO VisSetUtil::initScrCols Initialized 328860 rows.
20-Apr-2026 14:58:54	2026-04-20 18:58:55 INFO Calibrater:: Initializing nominal selection to the whole MS.
20-Apr-2026 14:58:54	2026-04-20 18:58:55 INFO calibrater::setdata Beginning selectvis--(MSSelection version)-------
20-Apr-2026 14:58:54	2026-04-20 18:58:55 INFO calibrater::reset Reseting solve/apply state
20-Apr-2026 14:58:54	2026-04-20 18:58:55 INFO Calibrater::selectvis Performing selection on MeasurementSet
20-Apr-2026 14:58:54	2026-04-20 18:58:55 INFO Calibrater::selectvis+ Selecting on scan: '2'
20-Apr-2026 14:58:54	2026-04-20 18:58:55 INFO Calibrater::selectvis By selection 328860 rows are reduced to 15660
20-Apr-2026 14:58:54	2026-04-20 18:58:55 INFO Calibrater::selectvis Frequency selection: Selecting all channels in all spws.
20-Apr-2026 14:58:54	2026-04-20 18:58:55 INFO calibrater::setdata chanmode=none nchan=1 start=0 step=1 mStart='0km/s' mStep='0km/s' msSelect=''
20-Apr-2026 14:58:54	2026-04-20 18:58:55 INFO calibrater::setapply Beginning setapply--(MSSelection version)-------
20-Apr-2026 14:58:54	2026-04-20 18:58:55 INFO Calibrater::setapply(type, applypar) Arranging to APPLY:
20-Apr-2026 14:58:54	2026-04-20 18:58:55 INFO Calibrater::setapply(type, applypar) . G Jones: table=gaincaltest2.ms.G0 select= interp=linear spwmap=[-1] calWt=false
20-Apr-2026 14:58:54	2026-04-20 18:58:55 INFO calibrater::correct Beginning correct---------------------------
20-Apr-2026 14:58:54	2026-04-20 18:58:55 INFO Calibrater::correct2 (VI2/VB2) The following calibration terms are arranged for apply:
20-Apr-2026 14:58:54	2026-04-20 18:58:55 INFO Calibrater::correct2 (VI2/VB2) . G Jones: table=gaincaltest2.ms.G0 select= interp=linear spwmap=[-1] calWt=false
20-Apr-2026 14:58:55	2026-04-20 18:58:55 INFO calibrater::correct Finished correcting.
20-Apr-2026 14:58:56	2026-04-20 18:58:56 WARN calibrater::setvi(bool,bool) Already using NEW VisibilityIterator.
20-Apr-2026 14:58:56	test_tool_calibrater.py::calibrater_test::test_selectVisScan
20-Apr-2026 14:58:56	Check tht the scan is properly selected by selectvis
20-Apr-2026 14:58:56	PASSED
20-Apr-2026 14:58:56
20-Apr-2026 14:58:57	2026-04-20 18:58:57 INFO calibrater::open **Using NEW VI2-driven calibrater tool**
20-Apr-2026 14:58:57	2026-04-20 18:58:57 INFO calibrater::open Opening MS: gaincaltest2.ms for calibration.
20-Apr-2026 14:58:57	2026-04-20 18:58:57 INFO Clearing all model records in MS header.
20-Apr-2026 14:58:57	2026-04-20 18:58:57 INFO VisSetUtil::addScrCols Adding MODEL_DATA and CORRECTED_DATA column(s).
20-Apr-2026 14:58:58	2026-04-20 18:58:59 INFO VisSetUtil::initScrCols Initializing MODEL_DATA to (unity).
20-Apr-2026 14:58:59	2026-04-20 18:58:59 INFO VisSetUtil::initScrCols Initialized 328860 rows.
20-Apr-2026 14:58:59	2026-04-20 18:58:59 INFO Calibrater:: Initializing nominal selection to the whole MS.
20-Apr-2026 14:58:59	2026-04-20 18:58:59 INFO calibrater::setdata Beginning selectvis--(MSSelection version)-------
20-Apr-2026 14:58:59	2026-04-20 18:58:59 INFO calibrater::reset Reseting solve/apply state
20-Apr-2026 14:58:59	2026-04-20 18:58:59 INFO Calibrater::selectvis Performing selection on MeasurementSet
20-Apr-2026 14:58:59	2026-04-20 18:58:59 INFO Calibrater::selectvis+ Selecting on spw: '0'
20-Apr-2026 14:58:59	2026-04-20 18:58:59 INFO Calibrater::selectvis By selection 328860 rows are reduced to 82215
20-Apr-2026 14:58:59	2026-04-20 18:58:59 INFO Calibrater::selectvis Frequency selection:
20-Apr-2026 14:58:59	2026-04-20 18:58:59 INFO Calibrater::selectvis . Spw 0:0~7 (8 channels, step by 1)
20-Apr-2026 14:58:59	2026-04-20 18:58:59 INFO calibrater::setdata chanmode=none nchan=1 start=0 step=1 mStart='0km/s' mStep='0km/s' msSelect=''
20-Apr-2026 14:58:59	2026-04-20 18:58:59 INFO calibrater::setapply Beginning setapply--(MSSelection version)-------
20-Apr-2026 14:58:59	2026-04-20 18:58:59 INFO Calibrater::setapply(type, applypar) Arranging to APPLY:
20-Apr-2026 14:58:59	2026-04-20 18:58:59 INFO Calibrater::setapply(type, applypar) . G Jones: table=gaincaltest2.ms.G0 select= interp=linear spwmap=[-1] calWt=false
20-Apr-2026 14:58:59	2026-04-20 18:58:59 INFO calibrater::correct Beginning correct---------------------------
20-Apr-2026 14:58:59	2026-04-20 18:58:59 INFO Calibrater::correct2 (VI2/VB2) The following calibration terms are arranged for apply:
20-Apr-2026 14:58:59	2026-04-20 18:58:59 INFO Calibrater::correct2 (VI2/VB2) . G Jones: table=gaincaltest2.ms.G0 select= interp=linear spwmap=[-1] calWt=false
20-Apr-2026 14:59:00	2026-04-20 18:59:00 INFO calibrater::correct Finished correcting.
20-Apr-2026 14:59:01	2026-04-20 18:59:01 WARN calibrater::setvi(bool,bool) Already using NEW VisibilityIterator.
20-Apr-2026 14:59:01	test_tool_calibrater.py::calibrater_test::test_selectVisSpw
20-Apr-2026 14:59:01	Check that spw is properly selected by selectvis
20-Apr-2026 14:59:01	PASSED
20-Apr-2026 14:59:01
20-Apr-2026 14:59:02	2026-04-20 18:59:02 INFO calibrater::open **Using NEW VI2-driven calibrater tool**
20-Apr-2026 14:59:02	2026-04-20 18:59:02 INFO calibrater::open Opening MS: gaincaltest2.ms for calibration.
20-Apr-2026 14:59:02	2026-04-20 18:59:02 INFO Clearing all model records in MS header.
20-Apr-2026 14:59:02	2026-04-20 18:59:02 INFO VisSetUtil::addScrCols Adding MODEL_DATA and CORRECTED_DATA column(s).
20-Apr-2026 14:59:04	2026-04-20 18:59:04 INFO VisSetUtil::initScrCols Initializing MODEL_DATA to (unity).
20-Apr-2026 14:59:04	2026-04-20 18:59:04 INFO VisSetUtil::initScrCols Initialized 328860 rows.
20-Apr-2026 14:59:04	2026-04-20 18:59:04 INFO Calibrater:: Initializing nominal selection to the whole MS.
20-Apr-2026 14:59:04	2026-04-20 18:59:04 INFO calibrater::setdata Beginning selectvis--(MSSelection version)-------
20-Apr-2026 14:59:04	2026-04-20 18:59:04 INFO calibrater::reset Reseting solve/apply state
20-Apr-2026 14:59:04	2026-04-20 18:59:04 INFO Calibrater::selectvis Performing selection on MeasurementSet
20-Apr-2026 14:59:04	2026-04-20 18:59:04 INFO Calibrater::selectvis+ Selecting on time: '>04:38:23'
20-Apr-2026 14:59:04	2026-04-20 18:59:04 INFO Calibrater::selectvis By selection 328860 rows are reduced to 313200
20-Apr-2026 14:59:04	2026-04-20 18:59:04 INFO Calibrater::selectvis Frequency selection: Selecting all channels in all spws.
20-Apr-2026 14:59:04	2026-04-20 18:59:04 INFO calibrater::setdata chanmode=none nchan=1 start=0 step=1 mStart='0km/s' mStep='0km/s' msSelect=''
20-Apr-2026 14:59:04	2026-04-20 18:59:04 INFO calibrater::setapply Beginning setapply--(MSSelection version)-------
20-Apr-2026 14:59:04	2026-04-20 18:59:04 INFO Calibrater::setapply(type, applypar) Arranging to APPLY:
20-Apr-2026 14:59:04	2026-04-20 18:59:05 INFO Calibrater::setapply(type, applypar) . G Jones: table=gaincaltest2.ms.G0 select= interp=linear spwmap=[-1] calWt=false
20-Apr-2026 14:59:04	2026-04-20 18:59:05 INFO calibrater::correct Beginning correct---------------------------
20-Apr-2026 14:59:04	2026-04-20 18:59:05 INFO Calibrater::correct2 (VI2/VB2) The following calibration terms are arranged for apply:
20-Apr-2026 14:59:04	2026-04-20 18:59:05 INFO Calibrater::correct2 (VI2/VB2) . G Jones: table=gaincaltest2.ms.G0 select= interp=linear spwmap=[-1] calWt=false
20-Apr-2026 14:59:08	2026-04-20 18:59:08 INFO calibrater::correct Finished correcting.
20-Apr-2026 14:59:08	2026-04-20 18:59:09 WARN calibrater::setvi(bool,bool) Already using NEW VisibilityIterator.
20-Apr-2026 14:59:08	test_tool_calibrater.py::calibrater_test::test_selectVisTime
20-Apr-2026 14:59:08	Check that time is properly selected by selectvis
20-Apr-2026 14:59:08	PASSED
20-Apr-2026 14:59:08
20-Apr-2026 14:59:09	2026-04-20 18:59:09 INFO calibrater::open **Using NEW VI2-driven calibrater tool**
20-Apr-2026 14:59:09	2026-04-20 18:59:09 INFO calibrater::open Opening MS: gaincaltest2.ms for calibration.
20-Apr-2026 14:59:09	2026-04-20 18:59:09 INFO Clearing all model records in MS header.
20-Apr-2026 14:59:09	2026-04-20 18:59:09 INFO VisSetUtil::addScrCols Adding MODEL_DATA and CORRECTED_DATA column(s).
20-Apr-2026 14:59:11	2026-04-20 18:59:11 INFO VisSetUtil::initScrCols Initializing MODEL_DATA to (unity).
20-Apr-2026 14:59:11	2026-04-20 18:59:11 INFO VisSetUtil::initScrCols Initialized 328860 rows.
20-Apr-2026 14:59:11	2026-04-20 18:59:11 INFO Calibrater:: Initializing nominal selection to the whole MS.
20-Apr-2026 14:59:11	2026-04-20 18:59:11 INFO calibrater::setdata Beginning selectvis--(MSSelection version)-------
20-Apr-2026 14:59:11	2026-04-20 18:59:11 INFO calibrater::reset Reseting solve/apply state
20-Apr-2026 14:59:11	2026-04-20 18:59:11 INFO Calibrater::selectvis Performing selection on MeasurementSet
20-Apr-2026 14:59:11	2026-04-20 18:59:11 INFO Calibrater::selectvis+ Selecting on uvrange: '> 500000lambda'
20-Apr-2026 14:59:12	2026-04-20 18:59:12 INFO Calibrater::selectvis By selection 328860 rows are reduced to 103321
20-Apr-2026 14:59:12	2026-04-20 18:59:12 INFO Calibrater::selectvis Frequency selection: Selecting all channels in all spws.
20-Apr-2026 14:59:12	2026-04-20 18:59:12 INFO calibrater::setdata chanmode=none nchan=1 start=0 step=1 mStart='0km/s' mStep='0km/s' msSelect=''
20-Apr-2026 14:59:12	2026-04-20 18:59:12 INFO calibrater::setapply Beginning setapply--(MSSelection version)-------
20-Apr-2026 14:59:12	2026-04-20 18:59:12 INFO Calibrater::setapply(type, applypar) Arranging to APPLY:
20-Apr-2026 14:59:12	2026-04-20 18:59:12 INFO Calibrater::setapply(type, applypar) . G Jones: table=gaincaltest2.ms.G0 select= interp=linear spwmap=[-1] calWt=false
20-Apr-2026 14:59:12	2026-04-20 18:59:12 INFO calibrater::correct Beginning correct---------------------------
20-Apr-2026 14:59:12	2026-04-20 18:59:12 INFO Calibrater::correct2 (VI2/VB2) The following calibration terms are arranged for apply:
20-Apr-2026 14:59:12	2026-04-20 18:59:12 INFO Calibrater::correct2 (VI2/VB2) . G Jones: table=gaincaltest2.ms.G0 select= interp=linear spwmap=[-1] calWt=false
20-Apr-2026 14:59:14	2026-04-20 18:59:15 INFO calibrater::correct Finished correcting.
20-Apr-2026 14:59:15	2026-04-20 18:59:15 WARN calibrater::setvi(bool,bool) Already using NEW VisibilityIterator.
20-Apr-2026 14:59:15	test_tool_calibrater.py::calibrater_test::test_selectVisUVrange
20-Apr-2026 14:59:15	Check that selectvis properly selects for uvrange
20-Apr-2026 14:59:15	PASSED
20-Apr-2026 14:59:15
20-Apr-2026 14:59:15	2026-04-20 18:59:16 INFO calibrater::open **Using NEW VI2-driven calibrater tool**
20-Apr-2026 14:59:15	2026-04-20 18:59:16 INFO calibrater::open Opening MS: gaincaltest2.ms for calibration.
20-Apr-2026 14:59:15	2026-04-20 18:59:16 INFO Clearing all model records in MS header.
20-Apr-2026 14:59:15	2026-04-20 18:59:16 INFO VisSetUtil::addScrCols Adding MODEL_DATA and CORRECTED_DATA column(s).
20-Apr-2026 14:59:17	2026-04-20 18:59:17 INFO VisSetUtil::initScrCols Initializing MODEL_DATA to (unity).
20-Apr-2026 14:59:17	2026-04-20 18:59:18 INFO VisSetUtil::initScrCols Initialized 328860 rows.
20-Apr-2026 14:59:17	2026-04-20 18:59:18 INFO Calibrater:: Initializing nominal selection to the whole MS.
20-Apr-2026 14:59:17	2026-04-20 18:59:18 INFO calibrater::parsecallibfile Beginning parsecallibfile-)-------
20-Apr-2026 14:59:17	2026-04-20 18:59:18 INFO calibrater::setcallib Beginning setcallib---------
20-Apr-2026 14:59:17	2026-04-20 18:59:18 INFO Calibrater::setcallib2(callib) Arranging to APPLY:
20-Apr-2026 14:59:17	2026-04-20 18:59:18 INFO . G Jones: table=gaincaltest2.ms.G0 (by cal library) calWt=true
20-Apr-2026 14:59:17	2026-04-20 18:59:18 INFO . 0:
20-Apr-2026 14:59:17	2026-04-20 18:59:18 INFO + MS: obs= scan= fld= intent= spw=
20-Apr-2026 14:59:17	2026-04-20 18:59:18 INFO + CT: tinterp=linear finterp=
20-Apr-2026 14:59:17	2026-04-20 18:59:18 INFO + obsmap=[] scanmap=[] fldmap=[]
20-Apr-2026 14:59:17	2026-04-20 18:59:18 INFO + spwmap=[] antmap=[]
20-Apr-2026 14:59:17	2026-04-20 18:59:18 INFO calibrater::corrupt Beginning corrupt---------------------------
20-Apr-2026 14:59:17	2026-04-20 18:59:18 INFO Calibrater::corrupt2 (VI2/VB2) The following calibration terms are arranged for apply:
20-Apr-2026 14:59:17	2026-04-20 18:59:18 INFO Calibrater::corrupt2 (VI2/VB2) . G Jones: table=gaincaltest2.ms.G0 (by cal library) calWt=true
20-Apr-2026 14:59:21	2026-04-20 18:59:21 INFO calibrater::corrupt Finished corrupting.
20-Apr-2026 14:59:22	2026-04-20 18:59:22 WARN calibrater::setvi(bool,bool) Already using NEW VisibilityIterator.
20-Apr-2026 14:59:22	test_tool_calibrater.py::calibrater_test::test_setCalLib
20-Apr-2026 14:59:22	Check that a provided cal table can be used to corrupt the MODEL_DATA
20-Apr-2026 14:59:22	PASSED
20-Apr-2026 14:59:22
20-Apr-2026 14:59:22	2026-04-20 18:59:23 INFO calibrater::open **Using NEW VI2-driven calibrater tool**
20-Apr-2026 14:59:22	2026-04-20 18:59:23 INFO calibrater::open Opening MS: gaincaltest2.ms for calibration.
20-Apr-2026 14:59:22	2026-04-20 18:59:23 INFO Clearing all model records in MS header.
20-Apr-2026 14:59:22	2026-04-20 18:59:23 INFO VisSetUtil::addScrCols Adding MODEL_DATA and CORRECTED_DATA column(s).
20-Apr-2026 14:59:24	2026-04-20 18:59:24 INFO VisSetUtil::initScrCols Initializing MODEL_DATA to (unity).
20-Apr-2026 14:59:24	2026-04-20 18:59:25 INFO VisSetUtil::initScrCols Initialized 328860 rows.
20-Apr-2026 14:59:24	2026-04-20 18:59:25 INFO Calibrater:: Initializing nominal selection to the whole MS.
20-Apr-2026 14:59:24	2026-04-20 18:59:25 INFO Calibrater::setCorrDepFlags Setting correlation dependent flags = True
20-Apr-2026 14:59:24	2026-04-20 18:59:25 WARN calibrater::setvi(bool,bool) Already using NEW VisibilityIterator.
20-Apr-2026 14:59:24	test_tool_calibrater.py::calibrater_test::test_setCorrDepFlags
20-Apr-2026 14:59:24	Check that corrdepflags will be checked
20-Apr-2026 14:59:24	PASSED
20-Apr-2026 14:59:24
20-Apr-2026 14:59:25	2026-04-20 18:59:25 INFO calibrater::open **Using NEW VI2-driven calibrater tool**
20-Apr-2026 14:59:25	2026-04-20 18:59:25 INFO calibrater::open Opening MS: ngc5921.ms for calibration.
20-Apr-2026 14:59:25	2026-04-20 18:59:25 INFO Clearing all model records in MS header.
20-Apr-2026 14:59:25	2026-04-20 18:59:25 INFO VisSetUtil::addScrCols Adding MODEL_DATA and CORRECTED_DATA column(s).
20-Apr-2026 14:59:25	2026-04-20 18:59:25 INFO VisSetUtil::initScrCols Initializing MODEL_DATA to (unity).
20-Apr-2026 14:59:25	2026-04-20 18:59:25 INFO VisSetUtil::initScrCols Initialized 22653 rows.
20-Apr-2026 14:59:25	2026-04-20 18:59:25 INFO Calibrater:: Initializing nominal selection to the whole MS.
20-Apr-2026 14:59:25	2026-04-20 18:59:25 INFO calibrater::smooth Beginning smooth--(MSSelection version)-------
20-Apr-2026 14:59:25	2026-04-20 18:59:25 INFO Calibrater::smooth Beginning smoothing/interpolating method.
20-Apr-2026 14:59:25	2026-04-20 18:59:25 WARN Found pre-v4.1 caltable (/home/casatest/casa6/casatestutils/nosedir/test_tool_calibrater/ngc5921.gcal); attempting to update...
20-Apr-2026 14:59:25	2026-04-20 18:59:25 WARN + SUCCEEDED: trivial OBSERVATION/OBSERVATION_ID have been added.
20-Apr-2026 14:59:25	2026-04-20 18:59:26 INFO Calibrater::smooth Storing result in testcalout.cal
20-Apr-2026 14:59:25	2026-04-20 18:59:26 INFO Writing solutions to table: testcalout.cal
20-Apr-2026 14:59:25	2026-04-20 18:59:26 WARN calibrater::setvi(bool,bool) Already using NEW VisibilityIterator.
20-Apr-2026 14:59:25	test_tool_calibrater.py::calibrater_test::test_smoothedCalTables
20-Apr-2026 14:59:25	Check that the smooth command creates a smoothed cal table
20-Apr-2026 14:59:25	PASSED
20-Apr-2026 14:59:25
20-Apr-2026 14:59:26	2026-04-20 18:59:26 WARN calibrater::setvi(bool,bool) Forcing use of OLD VisibilityIterator.
20-Apr-2026 14:59:26	2026-04-20 18:59:26 INFO calibrater::open **Using OLD VI-driven calibrater tool**
20-Apr-2026 14:59:26	2026-04-20 18:59:26 INFO calibrater::open Opening MS: ngc5921.ms for calibration.
20-Apr-2026 14:59:26	2026-04-20 18:59:26 INFO Clearing all model records in MS header.
20-Apr-2026 14:59:26	2026-04-20 18:59:26 INFO VisSetUtil::addScrCols Adding MODEL_DATA and CORRECTED_DATA column(s).
20-Apr-2026 14:59:26	2026-04-20 18:59:26 INFO VisSetUtil::initScrCols Initializing MODEL_DATA to (unity).
20-Apr-2026 14:59:26	2026-04-20 18:59:26 INFO VisSetUtil::initScrCols Initialized 22653 rows.
20-Apr-2026 14:59:26	2026-04-20 18:59:26 INFO Calibrater:: Initializing nominal selection to the whole MS.
20-Apr-2026 14:59:26	2026-04-20 18:59:26 INFO calibrater::setsolvebandpoly Beginning setsolvebandpoly--(MSSelection version)-------
20-Apr-2026 14:59:26	2026-04-20 18:59:26 INFO Calibrater::setsolvebandpoly Arranging to SOLVE:
20-Apr-2026 14:59:26	2026-04-20 18:59:26 INFO Calibrater::setsolvebandpoly . BPOLY: table=bpoly append=false solint=inf,none refantmode='flex' refant='none' minsnr=0 apmode= solnorm=true normtype=MEAN
20-Apr-2026 14:59:26	2026-04-20 18:59:26 INFO calibrater::solve Beginning solve-----------------------------
20-Apr-2026 14:59:26	2026-04-20 18:59:26 INFO Calibrater::solve The following calibration terms are arranged for apply:
20-Apr-2026 14:59:26	2026-04-20 18:59:26 INFO Calibrater::solve . (None)
20-Apr-2026 14:59:26	2026-04-20 18:59:26 INFO Calibrater::solve The following calibration term is arranged for solve:
20-Apr-2026 14:59:26	2026-04-20 18:59:26 INFO Calibrater::solve . BPOLY: table=bpoly append=false solint=inf,none refantmode='flex' refant='none' minsnr=0 apmode= solnorm=true normtype=MEAN
20-Apr-2026 14:59:26	2026-04-20 18:59:26 INFO Calibrater::solve Solving for BPOLY
20-Apr-2026 14:59:26	2026-04-20 18:59:26 INFO For solint = inf, found 7 solution intervals.
20-Apr-2026 14:59:26	2026-04-20 18:59:26 INFO BJonesPoly::selfSolveOne() THIS IS THE NEW MULTI-SPW-FLEXIBLE VERSION
20-Apr-2026 14:59:26	2026-04-20 18:59:26 INFO BJonesPoly::selfSolveOne() Fitting bandpass amplitude and phase polynomials.
20-Apr-2026 14:59:26	2026-04-20 18:59:26 INFO BJonesPoly::selfSolveOne() Polynomial degree for amplitude is 5
20-Apr-2026 14:59:26	2026-04-20 18:59:26 INFO BJonesPoly::selfSolveOne() Polynomial degree for phase is 7
20-Apr-2026 14:59:26	2026-04-20 18:59:26 INFO BJonesPoly::selfSolveOne() Spectral grid for fit will have 63 points spaced by 24.4141 kHz.
20-Apr-2026 14:59:26	2026-04-20 18:59:26 INFO BJonesPoly::selfSolveOne() Polynomial solution will be valid over frequency range: 1.41267e+09-1.41418e+09 Hz.
20-Apr-2026 14:59:26	2026-04-20 18:59:26 INFO BJonesPoly::selfSolveOne() Total bandwidth: 1538.09 kHz.
20-Apr-2026 14:59:26	2026-04-20 18:59:26 INFO BJonesPoly::selfSolveOne() Found data for 351 baselines among 27 antennas.
20-Apr-2026 14:59:26	2026-04-20 18:59:26 INFO BJonesPoly::selfSolveOne() Fitting amplitude polynomial.
20-Apr-2026 14:59:26	2026-04-20 18:59:27 INFO BJonesPoly::selfSolveOne() Per-baseline RMS log(Amp) statistics: (min/mean/max) = 0.059507/0.0681762/0.0765806
20-Apr-2026 14:59:26	2026-04-20 18:59:27 INFO BJonesPoly::selfSolveOne() Fitting phase polynomial.
20-Apr-2026 14:59:26	2026-04-20 18:59:27 INFO BJonesPoly::selfSolveOne() Per baseline RMS phase (deg) statistics: (min/mean/max) = 0.336529/0.750193/1.6779
20-Apr-2026 14:59:26	2026-04-20 18:59:27 INFO BJonesPoly::selfSolveOne() Fitting amplitude polynomial.
20-Apr-2026 14:59:26	2026-04-20 18:59:27 INFO BJonesPoly::selfSolveOne() Per-baseline RMS log(Amp) statistics: (min/mean/max) = 0.0630839/0.0689061/0.0756384
20-Apr-2026 14:59:26	2026-04-20 18:59:27 INFO BJonesPoly::selfSolveOne() Fitting phase polynomial.
20-Apr-2026 14:59:27	2026-04-20 18:59:27 INFO BJonesPoly::selfSolveOne() Per baseline RMS phase (deg) statistics: (min/mean/max) = 0.279482/0.74979/1.59355
20-Apr-2026 14:59:27	2026-04-20 18:59:27 INFO BJonesPoly::selfSolveOne() Normalizing antenna-based solutions.
20-Apr-2026 14:59:27	2026-04-20 18:59:27 INFO BJonesPoly::updateCalTable() Storing calibration in table bpoly
20-Apr-2026 14:59:27	2026-04-20 18:59:27 INFO BJonesPoly::selfSolveOne() THIS IS THE NEW MULTI-SPW-FLEXIBLE VERSION
20-Apr-2026 14:59:27	2026-04-20 18:59:27 INFO BJonesPoly::selfSolveOne() Fitting bandpass amplitude and phase polynomials.
20-Apr-2026 14:59:27	2026-04-20 18:59:27 INFO BJonesPoly::selfSolveOne() Polynomial degree for amplitude is 5
20-Apr-2026 14:59:27	2026-04-20 18:59:27 INFO BJonesPoly::selfSolveOne() Polynomial degree for phase is 7
20-Apr-2026 14:59:27	2026-04-20 18:59:27 INFO BJonesPoly::selfSolveOne() Spectral grid for fit will have 63 points spaced by 24.4141 kHz.
20-Apr-2026 14:59:27	2026-04-20 18:59:27 INFO BJonesPoly::selfSolveOne() Polynomial solution will be valid over frequency range: 1.41267e+09-1.41418e+09 Hz.
20-Apr-2026 14:59:27	2026-04-20 18:59:27 INFO BJonesPoly::selfSolveOne() Total bandwidth: 1538.09 kHz.
20-Apr-2026 14:59:27	2026-04-20 18:59:27 INFO BJonesPoly::selfSolveOne() Found data for 351 baselines among 27 antennas.
20-Apr-2026 14:59:27	2026-04-20 18:59:27 INFO BJonesPoly::selfSolveOne() Fitting amplitude polynomial.
20-Apr-2026 14:59:27	2026-04-20 18:59:27 INFO BJonesPoly::selfSolveOne() Per-baseline RMS log(Amp) statistics: (min/mean/max) = 0.0672607/0.089081/0.111106
20-Apr-2026 14:59:27	2026-04-20 18:59:27 INFO BJonesPoly::selfSolveOne() Fitting phase polynomial.
20-Apr-2026 14:59:27	2026-04-20 18:59:28 INFO BJonesPoly::selfSolveOne() Per baseline RMS phase (deg) statistics: (min/mean/max) = 2.31075/3.32219/4.29305
20-Apr-2026 14:59:27	2026-04-20 18:59:28 INFO BJonesPoly::selfSolveOne() Fitting amplitude polynomial.
20-Apr-2026 14:59:27	2026-04-20 18:59:28 INFO BJonesPoly::selfSolveOne() Per-baseline RMS log(Amp) statistics: (min/mean/max) = 0.0652822/0.0889198/0.116912
20-Apr-2026 14:59:27	2026-04-20 18:59:28 INFO BJonesPoly::selfSolveOne() Fitting phase polynomial.
20-Apr-2026 14:59:27	2026-04-20 18:59:28 INFO BJonesPoly::selfSolveOne() Per baseline RMS phase (deg) statistics: (min/mean/max) = 2.44269/3.26616/4.3519
20-Apr-2026 14:59:27	2026-04-20 18:59:28 INFO BJonesPoly::selfSolveOne() Normalizing antenna-based solutions.
20-Apr-2026 14:59:27	2026-04-20 18:59:28 INFO BJonesPoly::updateCalTable() Storing calibration in table bpoly
20-Apr-2026 14:59:27	2026-04-20 18:59:28 INFO BJonesPoly::selfSolveOne() THIS IS THE NEW MULTI-SPW-FLEXIBLE VERSION
20-Apr-2026 14:59:27	2026-04-20 18:59:28 INFO BJonesPoly::selfSolveOne() Fitting bandpass amplitude and phase polynomials.
20-Apr-2026 14:59:27	2026-04-20 18:59:28 INFO BJonesPoly::selfSolveOne() Polynomial degree for amplitude is 5
20-Apr-2026 14:59:27	2026-04-20 18:59:28 INFO BJonesPoly::selfSolveOne() Polynomial degree for phase is 7
20-Apr-2026 14:59:27	2026-04-20 18:59:28 INFO BJonesPoly::selfSolveOne() Spectral grid for fit will have 63 points spaced by 24.4141 kHz.
20-Apr-2026 14:59:27	2026-04-20 18:59:28 INFO BJonesPoly::selfSolveOne() Polynomial solution will be valid over frequency range: 1.41267e+09-1.41418e+09 Hz.
20-Apr-2026 14:59:27	2026-04-20 18:59:28 INFO BJonesPoly::selfSolveOne() Total bandwidth: 1538.09 kHz.
20-Apr-2026 14:59:27	2026-04-20 18:59:28 INFO BJonesPoly::selfSolveOne() Found data for 351 baselines among 27 antennas.
20-Apr-2026 14:59:27	2026-04-20 18:59:28 INFO BJonesPoly::selfSolveOne() Fitting amplitude polynomial.
20-Apr-2026 14:59:27	2026-04-20 18:59:28 INFO BJonesPoly::selfSolveOne() Per-baseline RMS log(Amp) statistics: (min/mean/max) = 0.350681/0.587724/0.894558
20-Apr-2026 14:59:27	2026-04-20 18:59:28 INFO BJonesPoly::selfSolveOne() Fitting phase polynomial.
20-Apr-2026 14:59:30	2026-04-20 18:59:31 INFO BJonesPoly::selfSolveOne() Per baseline RMS phase (deg) statistics: (min/mean/max) = 21.296/59.0077/111.454
20-Apr-2026 14:59:30	2026-04-20 18:59:31 INFO BJonesPoly::selfSolveOne() Fitting amplitude polynomial.
20-Apr-2026 14:59:30	2026-04-20 18:59:31 INFO BJonesPoly::selfSolveOne() Per-baseline RMS log(Amp) statistics: (min/mean/max) = 0.354236/0.581733/0.988903
20-Apr-2026 14:59:30	2026-04-20 18:59:31 INFO BJonesPoly::selfSolveOne() Fitting phase polynomial.
20-Apr-2026 14:59:33	2026-04-20 18:59:33 INFO BJonesPoly::selfSolveOne() Per baseline RMS phase (deg) statistics: (min/mean/max) = 17.2419/56.3249/117.264
20-Apr-2026 14:59:33	2026-04-20 18:59:33 INFO BJonesPoly::selfSolveOne() Normalizing antenna-based solutions.
20-Apr-2026 14:59:33	2026-04-20 18:59:33 INFO BJonesPoly::updateCalTable() Storing calibration in table bpoly
20-Apr-2026 14:59:33	2026-04-20 18:59:34 INFO BJonesPoly::selfSolveOne() THIS IS THE NEW MULTI-SPW-FLEXIBLE VERSION
20-Apr-2026 14:59:33	2026-04-20 18:59:34 INFO BJonesPoly::selfSolveOne() Fitting bandpass amplitude and phase polynomials.
20-Apr-2026 14:59:33	2026-04-20 18:59:34 INFO BJonesPoly::selfSolveOne() Polynomial degree for amplitude is 5
20-Apr-2026 14:59:33	2026-04-20 18:59:34 INFO BJonesPoly::selfSolveOne() Polynomial degree for phase is 7
20-Apr-2026 14:59:33	2026-04-20 18:59:34 INFO BJonesPoly::selfSolveOne() Spectral grid for fit will have 63 points spaced by 24.4141 kHz.
20-Apr-2026 14:59:33	2026-04-20 18:59:34 INFO BJonesPoly::selfSolveOne() Polynomial solution will be valid over frequency range: 1.41267e+09-1.41418e+09 Hz.
20-Apr-2026 14:59:33	2026-04-20 18:59:34 INFO BJonesPoly::selfSolveOne() Total bandwidth: 1538.09 kHz.
20-Apr-2026 14:59:33	2026-04-20 18:59:34 INFO BJonesPoly::selfSolveOne() Found data for 351 baselines among 27 antennas.
20-Apr-2026 14:59:33	2026-04-20 18:59:34 INFO BJonesPoly::selfSolveOne() Fitting amplitude polynomial.
20-Apr-2026 14:59:33	2026-04-20 18:59:34 INFO BJonesPoly::selfSolveOne() Per-baseline RMS log(Amp) statistics: (min/mean/max) = 0.0850169/0.113968/0.15276
20-Apr-2026 14:59:33	2026-04-20 18:59:34 INFO BJonesPoly::selfSolveOne() Fitting phase polynomial.
20-Apr-2026 14:59:33	2026-04-20 18:59:34 INFO BJonesPoly::selfSolveOne() Per baseline RMS phase (deg) statistics: (min/mean/max) = 3.67561/5.33243/8.17296
20-Apr-2026 14:59:33	2026-04-20 18:59:34 INFO BJonesPoly::selfSolveOne() Fitting amplitude polynomial.
20-Apr-2026 14:59:33	2026-04-20 18:59:34 INFO BJonesPoly::selfSolveOne() Per-baseline RMS log(Amp) statistics: (min/mean/max) = 0.0784236/0.114345/0.159908
20-Apr-2026 14:59:33	2026-04-20 18:59:34 INFO BJonesPoly::selfSolveOne() Fitting phase polynomial.
20-Apr-2026 14:59:34	2026-04-20 18:59:34 INFO BJonesPoly::selfSolveOne() Per baseline RMS phase (deg) statistics: (min/mean/max) = 3.46392/5.27232/7.20673
20-Apr-2026 14:59:34	2026-04-20 18:59:34 INFO BJonesPoly::selfSolveOne() Normalizing antenna-based solutions.
20-Apr-2026 14:59:34	2026-04-20 18:59:34 INFO BJonesPoly::updateCalTable() Storing calibration in table bpoly
20-Apr-2026 14:59:34	2026-04-20 18:59:34 INFO BJonesPoly::selfSolveOne() THIS IS THE NEW MULTI-SPW-FLEXIBLE VERSION
20-Apr-2026 14:59:34	2026-04-20 18:59:34 INFO BJonesPoly::selfSolveOne() Fitting bandpass amplitude and phase polynomials.
20-Apr-2026 14:59:34	2026-04-20 18:59:34 INFO BJonesPoly::selfSolveOne() Polynomial degree for amplitude is 5
20-Apr-2026 14:59:34	2026-04-20 18:59:34 INFO BJonesPoly::selfSolveOne() Polynomial degree for phase is 7
20-Apr-2026 14:59:34	2026-04-20 18:59:34 INFO BJonesPoly::selfSolveOne() Spectral grid for fit will have 63 points spaced by 24.4141 kHz.
20-Apr-2026 14:59:34	2026-04-20 18:59:34 INFO BJonesPoly::selfSolveOne() Polynomial solution will be valid over frequency range: 1.41267e+09-1.41418e+09 Hz.
20-Apr-2026 14:59:34	2026-04-20 18:59:34 INFO BJonesPoly::selfSolveOne() Total bandwidth: 1538.09 kHz.
20-Apr-2026 14:59:34	2026-04-20 18:59:34 INFO BJonesPoly::selfSolveOne() Found data for 351 baselines among 27 antennas.
20-Apr-2026 14:59:34	2026-04-20 18:59:34 INFO BJonesPoly::selfSolveOne() Fitting amplitude polynomial.
20-Apr-2026 14:59:34	2026-04-20 18:59:34 INFO BJonesPoly::selfSolveOne() Per-baseline RMS log(Amp) statistics: (min/mean/max) = 0.0703936/0.102501/0.131676
20-Apr-2026 14:59:34	2026-04-20 18:59:34 INFO BJonesPoly::selfSolveOne() Fitting phase polynomial.
20-Apr-2026 14:59:34	2026-04-20 18:59:35 INFO BJonesPoly::selfSolveOne() Per baseline RMS phase (deg) statistics: (min/mean/max) = 2.98728/4.47977/5.84264
20-Apr-2026 14:59:34	2026-04-20 18:59:35 INFO BJonesPoly::selfSolveOne() Fitting amplitude polynomial.
20-Apr-2026 14:59:34	2026-04-20 18:59:35 INFO BJonesPoly::selfSolveOne() Per-baseline RMS log(Amp) statistics: (min/mean/max) = 0.0751114/0.102994/0.138529
20-Apr-2026 14:59:34	2026-04-20 18:59:35 INFO BJonesPoly::selfSolveOne() Fitting phase polynomial.
20-Apr-2026 14:59:34	2026-04-20 18:59:35 INFO BJonesPoly::selfSolveOne() Per baseline RMS phase (deg) statistics: (min/mean/max) = 3.18629/4.47068/5.8941
20-Apr-2026 14:59:34	2026-04-20 18:59:35 INFO BJonesPoly::selfSolveOne() Normalizing antenna-based solutions.
20-Apr-2026 14:59:34	2026-04-20 18:59:35 INFO BJonesPoly::updateCalTable() Storing calibration in table bpoly
20-Apr-2026 14:59:35	2026-04-20 18:59:35 INFO BJonesPoly::selfSolveOne() THIS IS THE NEW MULTI-SPW-FLEXIBLE VERSION
20-Apr-2026 14:59:35	2026-04-20 18:59:35 INFO BJonesPoly::selfSolveOne() Fitting bandpass amplitude and phase polynomials.
20-Apr-2026 14:59:35	2026-04-20 18:59:35 INFO BJonesPoly::selfSolveOne() Polynomial degree for amplitude is 5
20-Apr-2026 14:59:35	2026-04-20 18:59:35 INFO BJonesPoly::selfSolveOne() Polynomial degree for phase is 7
20-Apr-2026 14:59:35	2026-04-20 18:59:35 INFO BJonesPoly::selfSolveOne() Spectral grid for fit will have 63 points spaced by 24.4141 kHz.
20-Apr-2026 14:59:35	2026-04-20 18:59:35 INFO BJonesPoly::selfSolveOne() Polynomial solution will be valid over frequency range: 1.41267e+09-1.41418e+09 Hz.
20-Apr-2026 14:59:35	2026-04-20 18:59:35 INFO BJonesPoly::selfSolveOne() Total bandwidth: 1538.09 kHz.
20-Apr-2026 14:59:35	2026-04-20 18:59:35 INFO BJonesPoly::selfSolveOne() Found data for 351 baselines among 27 antennas.
20-Apr-2026 14:59:35	2026-04-20 18:59:35 INFO BJonesPoly::selfSolveOne() Fitting amplitude polynomial.
20-Apr-2026 14:59:35	2026-04-20 18:59:35 INFO BJonesPoly::selfSolveOne() Per-baseline RMS log(Amp) statistics: (min/mean/max) = 0.350626/0.604424/0.974388
20-Apr-2026 14:59:35	2026-04-20 18:59:35 INFO BJonesPoly::selfSolveOne() Fitting phase polynomial.
20-Apr-2026 14:59:37	2026-04-20 18:59:38 INFO BJonesPoly::selfSolveOne() Per baseline RMS phase (deg) statistics: (min/mean/max) = 21.2542/59.3511/120.719
20-Apr-2026 14:59:37	2026-04-20 18:59:38 INFO BJonesPoly::selfSolveOne() Fitting amplitude polynomial.
20-Apr-2026 14:59:37	2026-04-20 18:59:38 INFO BJonesPoly::selfSolveOne() Per-baseline RMS log(Amp) statistics: (min/mean/max) = 0.382806/0.598119/0.941571
20-Apr-2026 14:59:37	2026-04-20 18:59:38 INFO BJonesPoly::selfSolveOne() Fitting phase polynomial.
20-Apr-2026 14:59:40	2026-04-20 18:59:40 INFO BJonesPoly::selfSolveOne() Per baseline RMS phase (deg) statistics: (min/mean/max) = 20.0637/57.2112/118.101
20-Apr-2026 14:59:40	2026-04-20 18:59:40 INFO BJonesPoly::selfSolveOne() Normalizing antenna-based solutions.
20-Apr-2026 14:59:40	2026-04-20 18:59:40 INFO BJonesPoly::updateCalTable() Storing calibration in table bpoly
20-Apr-2026 14:59:40	2026-04-20 18:59:40 INFO BJonesPoly::selfSolveOne() THIS IS THE NEW MULTI-SPW-FLEXIBLE VERSION
20-Apr-2026 14:59:40	2026-04-20 18:59:40 INFO BJonesPoly::selfSolveOne() Fitting bandpass amplitude and phase polynomials.
20-Apr-2026 14:59:40	2026-04-20 18:59:40 INFO BJonesPoly::selfSolveOne() Polynomial degree for amplitude is 5
20-Apr-2026 14:59:40	2026-04-20 18:59:40 INFO BJonesPoly::selfSolveOne() Polynomial degree for phase is 7
20-Apr-2026 14:59:40	2026-04-20 18:59:40 INFO BJonesPoly::selfSolveOne() Spectral grid for fit will have 63 points spaced by 24.4141 kHz.
20-Apr-2026 14:59:40	2026-04-20 18:59:40 INFO BJonesPoly::selfSolveOne() Polynomial solution will be valid over frequency range: 1.41267e+09-1.41418e+09 Hz.
20-Apr-2026 14:59:40	2026-04-20 18:59:40 INFO BJonesPoly::selfSolveOne() Total bandwidth: 1538.09 kHz.
20-Apr-2026 14:59:40	2026-04-20 18:59:40 INFO BJonesPoly::selfSolveOne() Found data for 351 baselines among 27 antennas.
20-Apr-2026 14:59:40	2026-04-20 18:59:40 INFO BJonesPoly::selfSolveOne() Fitting amplitude polynomial.
20-Apr-2026 14:59:40	2026-04-20 18:59:40 INFO BJonesPoly::selfSolveOne() Per-baseline RMS log(Amp) statistics: (min/mean/max) = 0.0750931/0.0978998/0.125897
20-Apr-2026 14:59:40	2026-04-20 18:59:40 INFO BJonesPoly::selfSolveOne() Fitting phase polynomial.
20-Apr-2026 14:59:40	2026-04-20 18:59:41 INFO BJonesPoly::selfSolveOne() Per baseline RMS phase (deg) statistics: (min/mean/max) = 2.72932/3.98787/5.33715
20-Apr-2026 14:59:40	2026-04-20 18:59:41 INFO BJonesPoly::selfSolveOne() Fitting amplitude polynomial.
20-Apr-2026 14:59:40	2026-04-20 18:59:41 INFO BJonesPoly::selfSolveOne() Per-baseline RMS log(Amp) statistics: (min/mean/max) = 0.0658572/0.0972125/0.140794
20-Apr-2026 14:59:40	2026-04-20 18:59:41 INFO BJonesPoly::selfSolveOne() Fitting phase polynomial.
20-Apr-2026 14:59:41	2026-04-20 18:59:41 INFO BJonesPoly::selfSolveOne() Per baseline RMS phase (deg) statistics: (min/mean/max) = 2.97943/3.97841/5.72903
20-Apr-2026 14:59:41	2026-04-20 18:59:41 INFO BJonesPoly::selfSolveOne() Normalizing antenna-based solutions.
20-Apr-2026 14:59:41	2026-04-20 18:59:41 INFO BJonesPoly::updateCalTable() Storing calibration in table bpoly
20-Apr-2026 14:59:41	2026-04-20 18:59:41 INFO Calibrater::solve Found good BPOLY solutions in 7 slots.
20-Apr-2026 14:59:41	2026-04-20 18:59:41 INFO calibrater::solve Finished solving.
20-Apr-2026 14:59:41	2026-04-20 18:59:41 WARN calibrater::setvi(bool,bool) Forcing use of NEW VisibilityIterator.
20-Apr-2026 14:59:41	test_tool_calibrater.py::calibrater_test::test_solveBandpass
20-Apr-2026 14:59:41	Check that solve band poly creates the output table
20-Apr-2026 14:59:41	PASSED
20-Apr-2026 14:59:41
20-Apr-2026 14:59:41	2026-04-20 18:59:42 WARN calibrater::setvi(bool,bool) Forcing use of OLD VisibilityIterator.
20-Apr-2026 14:59:41	2026-04-20 18:59:42 INFO calibrater::open **Using OLD VI-driven calibrater tool**
20-Apr-2026 14:59:41	2026-04-20 18:59:42 INFO calibrater::open Opening MS: ngc5921.ms for calibration.
20-Apr-2026 14:59:41	2026-04-20 18:59:42 INFO Clearing all model records in MS header.
20-Apr-2026 14:59:41	2026-04-20 18:59:42 INFO VisSetUtil::addScrCols Adding MODEL_DATA and CORRECTED_DATA column(s).
20-Apr-2026 14:59:41	2026-04-20 18:59:42 INFO VisSetUtil::initScrCols Initializing MODEL_DATA to (unity).
20-Apr-2026 14:59:41	2026-04-20 18:59:42 INFO VisSetUtil::initScrCols Initialized 22653 rows.
20-Apr-2026 14:59:41	2026-04-20 18:59:42 INFO Calibrater:: Initializing nominal selection to the whole MS.
20-Apr-2026 14:59:41	2026-04-20 18:59:42 INFO calibrater::setsolvegainspline Beginning setsolvegainspline--(MSSelection version)-------
20-Apr-2026 14:59:41	2026-04-20 18:59:42 INFO Calibrater::setsolvegainspline Arranging to SOLVE:
20-Apr-2026 14:59:41	2026-04-20 18:59:42 INFO Calibrater::setsolvegainspline . GSPLINE: table=gainspline append=false solint=inf refantmode='flex' refant='none' minsnr=0 apmode=AMP solnorm=false
20-Apr-2026 14:59:41	2026-04-20 18:59:42 INFO calibrater::solve Beginning solve-----------------------------
20-Apr-2026 14:59:41	2026-04-20 18:59:42 INFO Calibrater::solve The following calibration terms are arranged for apply:
20-Apr-2026 14:59:41	2026-04-20 18:59:42 INFO Calibrater::solve . (None)
20-Apr-2026 14:59:41	2026-04-20 18:59:42 INFO Calibrater::solve The following calibration term is arranged for solve:
20-Apr-2026 14:59:41	2026-04-20 18:59:42 INFO Calibrater::solve . GSPLINE: table=gainspline append=false solint=inf refantmode='flex' refant='none' minsnr=0 apmode=AMP solnorm=false
20-Apr-2026 14:59:41	2026-04-20 18:59:42 INFO GJonesSpline::solve() Fitting time-dependent cubic splines.
20-Apr-2026 14:59:41	2026-04-20 18:59:42 INFO GJonesSpline::solve() Solving for phase splines with splinetime= 10800
20-Apr-2026 14:59:41	2026-04-20 18:59:42 INFO GJonesSpline::solve() Solving for amplitude splines with splinetime= 10800
20-Apr-2026 14:59:41	2026-04-20 18:59:42 INFO GJonesSpline::solve() Accumulating data for: field= 1331+30500002_0, spw= 0, nchan= 63
20-Apr-2026 14:59:42	2026-04-20 18:59:42 INFO GJonesSpline::solve() Accumulating data for: field= 1445+09900002_0, spw= 0, nchan= 63
20-Apr-2026 14:59:42	2026-04-20 18:59:42 INFO GJonesSpline::solve() Accumulating data for: field= N5921_2, spw= 0, nchan= 63
20-Apr-2026 14:59:42	2026-04-20 18:59:42 INFO GJonesSpline::solve() Number of timestamps in data = 60
20-Apr-2026 14:59:42	2026-04-20 18:59:42 INFO GJonesSpline::getKnots() Gridded splinetime = 5280 sec.
20-Apr-2026 14:59:42	2026-04-20 18:59:42 INFO GJonesSpline::solve() Number of cubic spline control points = 4
20-Apr-2026 14:59:42	2026-04-20 18:59:42 INFO GJonesSpline::solve() Number of cubic spline knots = 8
20-Apr-2026 14:59:42	2026-04-20 18:59:42 INFO GJonesSpline::solve() Number of cubic spline segments = 1
20-Apr-2026 14:59:42	2026-04-20 18:59:42 INFO GJonesSpline::solve() Fitting amplitude spline.
20-Apr-2026 14:59:42	test_tool_calibrater.py::calibrater_test::test_solveGainspline DPBTRF ;problem leading minor 23
20-Apr-2026 14:59:42	DPBTRF ;problem leading minor 23
20-Apr-2026 14:59:42	2026-04-20 18:59:42 INFO GJonesSpline::solve() Searching for and correcting phase-wraps on each baseline.
20-Apr-2026 14:59:42	2026-04-20 18:59:42 INFO GJonesSpline::solve() Fitting phase spline.
20-Apr-2026 14:59:42	DPBTRF ;problem leading minor 22
20-Apr-2026 14:59:42	DPBTRF ;problem leading minor 22
20-Apr-2026 14:59:42	2026-04-20 18:59:42 INFO GJonesSpline::updateCalTable Storing solutions in table gainspline
20-Apr-2026 14:59:42	2026-04-20 18:59:42 INFO calibrater::solve Finished solving.
20-Apr-2026 14:59:42	2026-04-20 18:59:42 WARN calibrater::setvi(bool,bool) Forcing use of NEW VisibilityIterator.
20-Apr-2026 14:59:42
20-Apr-2026 14:59:42	Check that solve gain spline creates the output table
20-Apr-2026 14:59:42	PASSED
20-Apr-2026 14:59:42
20-Apr-2026 14:59:42	2026-04-20 18:59:43 INFO calibrater::open **Using NEW VI2-driven calibrater tool**
20-Apr-2026 14:59:42	2026-04-20 18:59:43 INFO calibrater::open Opening MS: gaincaltest2.ms for calibration.
20-Apr-2026 14:59:42	2026-04-20 18:59:43 INFO Clearing all model records in MS header.
20-Apr-2026 14:59:42	2026-04-20 18:59:43 INFO VisSetUtil::addScrCols Adding MODEL_DATA and CORRECTED_DATA column(s).
20-Apr-2026 14:59:44	2026-04-20 18:59:44 INFO VisSetUtil::initScrCols Initializing MODEL_DATA to (unity).
20-Apr-2026 14:59:44	2026-04-20 18:59:45 INFO VisSetUtil::initScrCols Initialized 328860 rows.
20-Apr-2026 14:59:44	2026-04-20 18:59:45 INFO Calibrater:: Initializing nominal selection to the whole MS.
20-Apr-2026 14:59:44	2026-04-20 18:59:45 INFO calibrater::specifycal Beginning specifycal-----------------------
20-Apr-2026 14:59:44	2026-04-20 18:59:45 INFO Creating G Jones table from specified parameters.
20-Apr-2026 14:59:44	2026-04-20 18:59:45 INFO Generating 'G' corrections.
20-Apr-2026 14:59:44	2026-04-20 18:59:45 INFO Specified parameter(s) (per spw and pol) repeated on all antennas.
20-Apr-2026 14:59:44	2026-04-20 18:59:45 INFO Specified parameter(s) (per spw and antenna) repeated on all polarizations.
20-Apr-2026 14:59:44	2026-04-20 18:59:45 INFO spwId=1 antId=<all> polId=<all> parameter= 3 (ip0,ip1 = [0, 0, 0],[1, 0, 9])
20-Apr-2026 14:59:44	2026-04-20 18:59:45 INFO Writing solutions to table: testcalout.cal
20-Apr-2026 14:59:44	2026-04-20 18:59:45 WARN calibrater::setvi(bool,bool) Already using NEW VisibilityIterator.
20-Apr-2026 14:59:44	test_tool_calibrater.py::calibrater_test::test_specifyCal
20-Apr-2026 14:59:44	Check that specifycal can set values for specific spws and antennas
20-Apr-2026 14:59:44	PASSED
20-Apr-2026 14:59:44
20-Apr-2026 14:59:45	2026-04-20 18:59:45 WARN calibrater::setvi(bool,bool) Forcing use of OLD VisibilityIterator.
20-Apr-2026 14:59:45	2026-04-20 18:59:45 INFO calibrater::open **Using OLD VI-driven calibrater tool**
20-Apr-2026 14:59:45	2026-04-20 18:59:45 INFO calibrater::open Opening MS: gaincaltest2.ms for calibration.
20-Apr-2026 14:59:45	2026-04-20 18:59:45 INFO Clearing all model records in MS header.
20-Apr-2026 14:59:45	2026-04-20 18:59:45 INFO VisSetUtil::addScrCols Adding MODEL_DATA and CORRECTED_DATA column(s).
20-Apr-2026 14:59:47	2026-04-20 18:59:47 INFO VisSetUtil::initScrCols Initializing MODEL_DATA to (unity).
20-Apr-2026 14:59:47	2026-04-20 18:59:47 INFO VisSetUtil::initScrCols Initialized 328860 rows.
20-Apr-2026 14:59:47	2026-04-20 18:59:47 INFO Calibrater:: Initializing nominal selection to the whole MS.
20-Apr-2026 14:59:47	2026-04-20 18:59:48 INFO calibrater::setapply Beginning setapply--(MSSelection version)-------
20-Apr-2026 14:59:47	2026-04-20 18:59:48 INFO Calibrater::setapply(type, applypar) Arranging to APPLY:
20-Apr-2026 14:59:47	2026-04-20 18:59:48 INFO Calibrater::setapply(type, applypar) . G Jones: table=gaincaltest2.ms.G0 select= interp=linear spwmap=[-1] calWt=false
20-Apr-2026 14:59:47	2026-04-20 18:59:48 INFO calibrater::setsolve Beginning setsolve--(MSSelection version)-------
20-Apr-2026 14:59:47	2026-04-20 18:59:48 INFO Calibrater::setsolve Arranging to SOLVE:
20-Apr-2026 14:59:47	2026-04-20 18:59:48 INFO Calibrater::setsolve . Mf Mueller: table=output.ms append=false solint=inf,none refantmode='flex' refant='none' minsnr=0 apmode=AP solnorm=false
20-Apr-2026 14:59:47	2026-04-20 18:59:48 INFO Calibrater::state The following calibration terms are arranged for apply:
20-Apr-2026 14:59:47	2026-04-20 18:59:48 INFO Calibrater::state . G Jones: table=gaincaltest2.ms.G0 select= interp=linear spwmap=[-1] calWt=false
20-Apr-2026 14:59:47	2026-04-20 18:59:48 INFO Calibrater::state The following calibration term is arranged for solve:
20-Apr-2026 14:59:47	2026-04-20 18:59:48 INFO Calibrater::state . Mf Mueller: table=output.ms append=false solint=inf,none refantmode='flex' refant='none' minsnr=0 apmode=AP solnorm=false
20-Apr-2026 14:59:47	2026-04-20 18:59:48 INFO calibrater::solve Beginning solve-----------------------------
20-Apr-2026 14:59:47	2026-04-20 18:59:48 INFO Calibrater::solve The following calibration terms are arranged for apply:
20-Apr-2026 14:59:47	2026-04-20 18:59:48 INFO Calibrater::solve . G Jones: table=gaincaltest2.ms.G0 select= interp=linear spwmap=[-1] calWt=false
20-Apr-2026 14:59:47	2026-04-20 18:59:48 INFO Calibrater::solve The following calibration term is arranged for solve:
20-Apr-2026 14:59:47	2026-04-20 18:59:48 INFO Calibrater::solve . Mf Mueller: table=output.ms append=false solint=inf,none refantmode='flex' refant='none' minsnr=0 apmode=AP solnorm=false
20-Apr-2026 14:59:47	2026-04-20 18:59:48 INFO Solving for Mf Mueller
20-Apr-2026 14:59:47	2026-04-20 18:59:48 INFO For solint = inf, found 84 solution intervals.
20-Apr-2026 14:59:49	2026-04-20 18:59:50 INFO Found good Mf Mueller solutions in 84 intervals.
20-Apr-2026 14:59:49	2026-04-20 18:59:50 INFO Writing solutions to table: output.ms
20-Apr-2026 14:59:49	2026-04-20 18:59:50 INFO calibrater::solve Finished solving.
20-Apr-2026 14:59:49	2026-04-20 18:59:50 WARN calibrater::setvi(bool,bool) Forcing use of NEW VisibilityIterator.
20-Apr-2026 14:59:50	test_tool_calibrater.py::calibrater_test::test_standardPath
20-Apr-2026 14:59:50	open setapply setsolve state solve close
20-Apr-2026 14:59:50	PASSED
20-Apr-2026 14:59:50
20-Apr-2026 14:59:50	2026-04-20 18:59:50 INFO calibrater::open **Using NEW VI2-driven calibrater tool**
20-Apr-2026 14:59:50	2026-04-20 18:59:50 INFO calibrater::open Opening MS: gaincaltest2.ms for calibration.
20-Apr-2026 14:59:50	2026-04-20 18:59:50 INFO Clearing all model records in MS header.
20-Apr-2026 14:59:50	2026-04-20 18:59:50 INFO VisSetUtil::addScrCols Adding MODEL_DATA and CORRECTED_DATA column(s).
20-Apr-2026 14:59:52	2026-04-20 18:59:52 INFO VisSetUtil::initScrCols Initializing MODEL_DATA to (unity).
20-Apr-2026 14:59:52	2026-04-20 18:59:52 INFO VisSetUtil::initScrCols Initialized 328860 rows.
20-Apr-2026 14:59:52	2026-04-20 18:59:52 INFO Calibrater:: Initializing nominal selection to the whole MS.
20-Apr-2026 14:59:52	2026-04-20 18:59:52 INFO name:: No table opened.
20-Apr-2026 14:59:52	2026-04-20 18:59:52 INFO showcache:: The Table Cache has the following 16 entries:
20-Apr-2026 14:59:52	2026-04-20 18:59:52 INFO showcache:: 0: "/home/casatest/casa6/casatestutils/nosedir/test_tool_calibrater/gaincaltest2.ms"
20-Apr-2026 14:59:52	2026-04-20 18:59:52 INFO showcache:: 1: "/home/casatest/casa6/casatestutils/nosedir/test_tool_calibrater/gaincaltest2.ms/ANTENNA"
20-Apr-2026 14:59:52	2026-04-20 18:59:52 INFO showcache:: 2: "/home/casatest/casa6/casatestutils/nosedir/test_tool_calibrater/gaincaltest2.ms/DATA_DESCRIPTION"
20-Apr-2026 14:59:52	2026-04-20 18:59:52 INFO showcache:: 3: "/home/casatest/casa6/casatestutils/nosedir/test_tool_calibrater/gaincaltest2.ms/FEED"
20-Apr-2026 14:59:52	2026-04-20 18:59:52 INFO showcache:: 4: "/home/casatest/casa6/casatestutils/nosedir/test_tool_calibrater/gaincaltest2.ms/FIELD"
20-Apr-2026 14:59:52	2026-04-20 18:59:52 INFO showcache:: 5: "/home/casatest/casa6/casatestutils/nosedir/test_tool_calibrater/gaincaltest2.ms/FLAG_CMD"
20-Apr-2026 14:59:52	2026-04-20 18:59:52 INFO showcache:: 6: "/home/casatest/casa6/casatestutils/nosedir/test_tool_calibrater/gaincaltest2.ms/HISTORY"
20-Apr-2026 14:59:52	2026-04-20 18:59:52 INFO showcache:: 7: "/home/casatest/casa6/casatestutils/nosedir/test_tool_calibrater/gaincaltest2.ms/OBSERVATION"
20-Apr-2026 14:59:52	2026-04-20 18:59:52 INFO showcache:: 8: "/home/casatest/casa6/casatestutils/nosedir/test_tool_calibrater/gaincaltest2.ms/POINTING"
20-Apr-2026 14:59:52	2026-04-20 18:59:52 INFO showcache:: 9: "/home/casatest/casa6/casatestutils/nosedir/test_tool_calibrater/gaincaltest2.ms/POLARIZATION"
20-Apr-2026 14:59:52	2026-04-20 18:59:52 INFO showcache:: 10: "/home/casatest/casa6/casatestutils/nosedir/test_tool_calibrater/gaincaltest2.ms/PROCESSOR"
20-Apr-2026 14:59:52	2026-04-20 18:59:52 INFO showcache:: 11: "/home/casatest/casa6/casatestutils/nosedir/test_tool_calibrater/gaincaltest2.ms/SOURCE"
20-Apr-2026 14:59:52	2026-04-20 18:59:52 INFO showcache:: 12: "/home/casatest/casa6/casatestutils/nosedir/test_tool_calibrater/gaincaltest2.ms/SPECTRAL_WINDOW"
20-Apr-2026 14:59:52	2026-04-20 18:59:52 INFO showcache:: 13: "/home/casatest/casa6/casatestutils/nosedir/test_tool_calibrater/gaincaltest2.ms/STATE"
20-Apr-2026 14:59:52	2026-04-20 18:59:52 INFO showcache:: 14: "/home/casatest/casa6/casatestutils/nosedir/test_tool_calibrater/gaincaltest2.ms/SYSCAL"
20-Apr-2026 14:59:52	2026-04-20 18:59:52 INFO showcache:: 15: "/home/casatest/casa6/casatestutils/nosedir/test_tool_calibrater/gaincaltest2.ms/WEATHER"
20-Apr-2026 14:59:52	2026-04-20 18:59:52 INFO name:: No table opened.
20-Apr-2026 14:59:52	2026-04-20 18:59:52 INFO showcache:: The Table Cache is empty.
20-Apr-2026 14:59:52	2026-04-20 18:59:52 WARN calibrater::setvi(bool,bool) Already using NEW VisibilityIterator.
20-Apr-2026 14:59:52	test_tool_calibrater.py::calibrater_test::test_takesMs
20-Apr-2026 14:59:52	Check that the calibrater tool can open and close an MS
20-Apr-2026 14:59:52	PASSED
20-Apr-2026 14:59:52
20-Apr-2026 14:59:52	2026-04-20 18:59:53 INFO calibrater::open **Using NEW VI2-driven calibrater tool**
20-Apr-2026 14:59:52	2026-04-20 18:59:53 INFO calibrater::open Opening MS: gaincaltest2.ms for calibration.
20-Apr-2026 14:59:52	2026-04-20 18:59:53 INFO Clearing all model records in MS header.
20-Apr-2026 14:59:52	2026-04-20 18:59:53 INFO VisSetUtil::addScrCols Adding MODEL_DATA and CORRECTED_DATA column(s).
20-Apr-2026 14:59:54	2026-04-20 18:59:55 INFO VisSetUtil::initScrCols Initializing MODEL_DATA to (unity).
20-Apr-2026 14:59:55	2026-04-20 18:59:55 INFO VisSetUtil::initScrCols Initialized 328860 rows.
20-Apr-2026 14:59:55	2026-04-20 18:59:55 INFO Calibrater:: Initializing nominal selection to the whole MS.
20-Apr-2026 14:59:55	2026-04-20 18:59:55 INFO calibrater::setapply Beginning setapply--(MSSelection version)-------
20-Apr-2026 14:59:55	2026-04-20 18:59:55 INFO Calibrater::setapply(type, applypar) Arranging to APPLY:
20-Apr-2026 14:59:55	2026-04-20 18:59:55 INFO Calibrater::setapply(type, applypar) . G Jones: table=gaincaltest2.ms.G0 select= interp=linear spwmap=[-1] calWt=false
20-Apr-2026 14:59:55	2026-04-20 18:59:55 INFO calibrater::correct Beginning correct---------------------------
20-Apr-2026 14:59:55	2026-04-20 18:59:55 INFO Calibrater::correct2 (VI2/VB2) The following calibration terms are arranged for apply:
20-Apr-2026 14:59:55	2026-04-20 18:59:55 INFO Calibrater::correct2 (VI2/VB2) . G Jones: table=gaincaltest2.ms.G0 select= interp=linear spwmap=[-1] calWt=false
20-Apr-2026 14:59:58	2026-04-20 18:59:59 INFO calibrater::correct Finished correcting.
20-Apr-2026 14:59:58	2026-04-20 18:59:59 WARN calibrater::setvi(bool,bool) Already using NEW VisibilityIterator.
20-Apr-2026 14:59:59	test_tool_calibrater.py::calibrater_test::test_writeToCorrected
20-Apr-2026 14:59:59	Check that the tool writes to the CORRECTED_DATA column
20-Apr-2026 14:59:59	PASSED
20-Apr-2026 14:59:59
20-Apr-2026 14:59:59	- generated xml file: /home/casatest/casa6/casatestutils/nosedir/xml/test_tool_calibrater/nose.xml -
20-Apr-2026 14:59:59	================== 24 passed, 1 warning in 132.54s (0:02:12) ===================
20-Apr-2026 14:59:59
20-Apr-2026 14:59:59
20-Apr-2026 14:59:59	Setting Working Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_agentflagger/
20-Apr-2026 14:59:59	Test Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_agentflagger
20-Apr-2026 14:59:59
20-Apr-2026 14:59:59	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/
20-Apr-2026 14:59:59
20-Apr-2026 14:59:59	Setting Working Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_image_regrid/
20-Apr-2026 14:59:59	Test Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_image_regrid
20-Apr-2026 14:59:59
20-Apr-2026 14:59:59	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/
20-Apr-2026 14:59:59
20-Apr-2026 14:59:59	Setting Working Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_image_collapse/
20-Apr-2026 14:59:59	Test Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_image_collapse
20-Apr-2026 14:59:59
20-Apr-2026 14:59:59	Running Command: pytest --junitxml=/home/casatest/casa6/casatestutils/nosedir/xml/test_tool_image_collapse/nose.xml -s --disable-pytest-warnings --verbose -ra --tb=short /home/casatest/casa6/casatestutils/nosedir/test_tool_image_collapse/
20-Apr-2026 14:59:59
20-Apr-2026 14:59:59	Setting Working Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_linearmosaic/
20-Apr-2026 14:59:59	Test Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_linearmosaic
20-Apr-2026 14:59:59
20-Apr-2026 14:59:59	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/
20-Apr-2026 14:59:59
20-Apr-2026 14:59:59	Setting Working Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_quanta/
20-Apr-2026 14:59:59	Test Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_quanta
20-Apr-2026 14:59:59
20-Apr-2026 14:59:59	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/
20-Apr-2026 14:59:59
20-Apr-2026 14:59:59	Setting Working Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_imagepol/
20-Apr-2026 14:59:59	Test Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_imagepol
20-Apr-2026 14:59:59
20-Apr-2026 14:59:59	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/
20-Apr-2026 14:59:59
20-Apr-2026 14:59:59	Setting Working Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_ms_createmultims/
20-Apr-2026 14:59:59	Test Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_ms_createmultims
20-Apr-2026 14:59:59
20-Apr-2026 14:59:59	Running Command: pytest --junitxml=/home/casatest/casa6/casatestutils/nosedir/xml/test_tool_ms_createmultims/nose.xml -s --disable-pytest-warnings --verbose -ra --tb=short /home/casatest/casa6/casatestutils/nosedir/test_tool_ms_createmultims/
20-Apr-2026 14:59:59
20-Apr-2026 14:59:59	Setting Working Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_ms_statwt/
20-Apr-2026 14:59:59	Test Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_ms_statwt
20-Apr-2026 14:59:59
20-Apr-2026 14:59:59	Running Command: pytest --junitxml=/home/casatest/casa6/casatestutils/nosedir/xml/test_tool_ms_statwt/nose.xml -s --disable-pytest-warnings --verbose -ra --tb=short /home/casatest/casa6/casatestutils/nosedir/test_tool_ms_statwt/
20-Apr-2026 14:59:59
20-Apr-2026 14:59:59	Setting Working Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_calanalysis/
20-Apr-2026 14:59:59	Test Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_calanalysis
20-Apr-2026 14:59:59
20-Apr-2026 14:59:59	Running Command: pytest --junitxml=/home/casatest/casa6/casatestutils/nosedir/xml/test_tool_calanalysis/nose.xml -s --disable-pytest-warnings --verbose -ra --tb=short /home/casatest/casa6/casatestutils/nosedir/test_tool_calanalysis/
20-Apr-2026 14:59:59
20-Apr-2026 14:59:59	Setting Working Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_ms/
20-Apr-2026 14:59:59	Test Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_ms
20-Apr-2026 14:59:59
20-Apr-2026 14:59:59	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/
20-Apr-2026 14:59:59
20-Apr-2026 14:59:59	Setting Working Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_logsink/
20-Apr-2026 14:59:59	Test Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_logsink
20-Apr-2026 14:59:59
20-Apr-2026 14:59:59	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/
20-Apr-2026 14:59:59
20-Apr-2026 14:59:59	Setting Working Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_image/
20-Apr-2026 14:59:59	Test Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_image
20-Apr-2026 14:59:59
20-Apr-2026 14:59:59	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/
20-Apr-2026 14:59:59
20-Apr-2026 14:59:59	Setting Working Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_msmetadata/
20-Apr-2026 14:59:59	Test Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_msmetadata
20-Apr-2026 14:59:59
20-Apr-2026 14:59:59	Running Command: pytest --junitxml=/home/casatest/casa6/casatestutils/nosedir/xml/test_tool_msmetadata/nose.xml -s --disable-pytest-warnings --verbose -ra --tb=short /home/casatest/casa6/casatestutils/nosedir/test_tool_msmetadata/
20-Apr-2026 14:59:59
20-Apr-2026 14:59:59	Setting Working Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_image_statistics/
20-Apr-2026 14:59:59	Test Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_image_statistics
20-Apr-2026 14:59:59
20-Apr-2026 14:59:59	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/
20-Apr-2026 14:59:59
20-Apr-2026 14:59:59	Setting Working Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_regionmanager/
20-Apr-2026 14:59:59	Test Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_regionmanager
20-Apr-2026 14:59:59
20-Apr-2026 14:59:59	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/
20-Apr-2026 14:59:59
20-Apr-2026 14:59:59	Setting Working Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_synthesisutils/
20-Apr-2026 14:59:59	Test Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_synthesisutils
20-Apr-2026 14:59:59
20-Apr-2026 14:59:59	Running Command: pytest --junitxml=/home/casatest/casa6/casatestutils/nosedir/xml/test_tool_synthesisutils/nose.xml -s --disable-pytest-warnings --verbose -ra --tb=short /home/casatest/casa6/casatestutils/nosedir/test_tool_synthesisutils/
20-Apr-2026 14:59:59
20-Apr-2026 14:59:59	Setting Working Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_simulator/
20-Apr-2026 14:59:59	Test Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_simulator
20-Apr-2026 14:59:59
20-Apr-2026 14:59:59	Running Command: pytest --junitxml=/home/casatest/casa6/casatestutils/nosedir/xml/test_tool_simulator/nose.xml -s --disable-pytest-warnings --verbose -ra --tb=short /home/casatest/casa6/casatestutils/nosedir/test_tool_simulator/
20-Apr-2026 14:59:59
20-Apr-2026 14:59:59	Setting Working Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_calibrater/
20-Apr-2026 14:59:59	Test Directory: /home/casatest/casa6/casatestutils/nosedir/test_tool_calibrater
20-Apr-2026 14:59:59
20-Apr-2026 14:59:59	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/
20-Apr-2026 15:00:03	total 77448
20-Apr-2026 15:00:03	-rw-r--r-- 1 casaci 15001 160658 Apr 20 18:22 casatestutils-6.7.5.18-py3-none-any.whl
20-Apr-2026 15:00:03	-rw-r--r-- 1 casaci 15001 78972194 Apr 20 18:22 casatools-6.7.5.18-cp313-cp313-manylinux_2_28_x86_64.whl
20-Apr-2026 15:00:03	-rw-r--r-- 1 casaci root 4340 Apr 20 19:00 test_tool_agentflagger.xml
20-Apr-2026 15:00:03	-rw-r--r-- 1 casaci root 1006 Apr 20 19:00 test_tool_calanalysis.xml
20-Apr-2026 15:00:03	-rw-r--r-- 1 casaci root 2658 Apr 20 19:00 test_tool_calibrater.xml
20-Apr-2026 15:00:03	-rw-r--r-- 1 casaci root 687 Apr 20 19:00 test_tool_componentlist.xml
20-Apr-2026 15:00:03	-rw-r--r-- 1 casaci root 7467 Apr 20 19:00 test_tool_coordsys.xml
20-Apr-2026 15:00:03	-rw-r--r-- 1 casaci root 12935 Apr 20 19:00 test_tool_image.xml
20-Apr-2026 15:00:03	-rw-r--r-- 1 casaci root 2220 Apr 20 19:00 test_tool_image_collapse.xml
20-Apr-2026 15:00:03	-rw-r--r-- 1 casaci root 1048 Apr 20 19:00 test_tool_image_deviation.xml
20-Apr-2026 15:00:03	-rw-r--r-- 1 casaci root 2576 Apr 20 19:00 test_tool_image_fitprofile.xml
20-Apr-2026 15:00:03	-rw-r--r-- 1 casaci root 1178 Apr 20 19:00 test_tool_image_pbcor.xml
20-Apr-2026 15:00:03	-rw-r--r-- 1 casaci root 883 Apr 20 19:00 test_tool_image_pv.xml
20-Apr-2026 15:00:03	-rw-r--r-- 1 casaci root 1006 Apr 20 19:00 test_tool_image_rebin.xml
20-Apr-2026 15:00:03	-rw-r--r-- 1 casaci root 1336 Apr 20 19:00 test_tool_image_regrid.xml
20-Apr-2026 15:00:03	-rw-r--r-- 1 casaci root 1642 Apr 20 19:00 test_tool_image_statistics.xml
20-Apr-2026 15:00:03	-rw-r--r-- 1 casaci root 765 Apr 20 19:00 test_tool_image_subimage.xml
20-Apr-2026 15:00:03	-rw-r--r-- 1 casaci root 890 Apr 20 19:00 test_tool_image_transpose.xml
20-Apr-2026 15:00:03	-rw-r--r-- 1 casaci root 1966 Apr 20 19:00 test_tool_imagepol.xml
20-Apr-2026 15:00:03	-rw-r--r-- 1 casaci root 839 Apr 20 19:00 test_tool_linearmosaic.xml
20-Apr-2026 15:00:03	-rw-r--r-- 1 casaci root 669 Apr 20 19:00 test_tool_logsink.xml
20-Apr-2026 15:00:03	-rw-r--r-- 1 casaci root 549 Apr 20 19:00 test_tool_measures.xml
20-Apr-2026 15:00:03	-rw-r--r-- 1 casaci root 5224 Apr 20 19:00 test_tool_ms.xml
20-Apr-2026 15:00:03	-rw-r--r-- 1 casaci root 367 Apr 20 19:00 test_tool_ms_createmultims.xml
20-Apr-2026 15:00:03	-rw-r--r-- 1 casaci root 2095 Apr 20 19:00 test_tool_ms_statwt.xml
20-Apr-2026 15:00:03	-rw-r--r-- 1 casaci root 8633 Apr 20 19:00 test_tool_msmetadata.xml
20-Apr-2026 15:00:03	-rw-r--r-- 1 casaci root 361 Apr 20 19:00 test_tool_msuvbinner.xml
20-Apr-2026 15:00:03	-rw-r--r-- 1 casaci root 1171 Apr 20 19:00 test_tool_quanta.xml
20-Apr-2026 15:00:03	-rw-r--r-- 1 casaci root 3977 Apr 20 19:00 test_tool_regionmanager.xml
20-Apr-2026 15:00:03	-rw-r--r-- 1 casaci root 2072 Apr 20 19:00 test_tool_sdm.xml
20-Apr-2026 15:00:03	-rw-r--r-- 1 casaci root 2097 Apr 20 19:00 test_tool_sdm_toms.xml
20-Apr-2026 15:00:03	-rw-r--r-- 1 casaci root 670 Apr 20 19:00 test_tool_simulator.xml
20-Apr-2026 15:00:03	-rw-r--r-- 1 casaci root 1717 Apr 20 19:00 test_tool_synthesisutils.xml
20-Apr-2026 15:00:03	-rw-r--r-- 1 casaci root 1462 Apr 20 19:00 test_tool_table.xml
20-Apr-2026 15:00:03	-rw-r--r-- 1 casaci root 1717 Apr 20 19:00 test_tool_vpmanager.xml
20-Apr-2026 15:00:03	Finished task 'Test wheel' with result: Success
20-Apr-2026 15:00:03	Substituting variable: ${bamboo.agentId} with 149651458
20-Apr-2026 15:00:03	Starting task 'Tar work directory' of type 'com.atlassian.bamboo.plugins.scripttask:task.builder.script'
20-Apr-2026 15:00:03	Beginning to execute external process for build 'CASASPECS - Release 6.7.5 Test 3.13 - Test Tools Many Linux 2.28 Rocky 8.10 Py3.13 #3 (CASASPECS-RELEASE675TESTPY313-TTOMLPY313-3)' ... running command line: /export/home/cbt-el7-2/bamboohome/temp/CASASPECS-RELEASE675TESTPY313-TTOMLPY313-3-ScriptBuildTask-6642559814125857837.sh ... in: /export/home/cbt-el7-2/bamboohome/xml-data/build-dir/CASASPECS-RELEASE675TESTPY313-TTOMLPY313
20-Apr-2026 15:00:03	Package working directory
20-Apr-2026 15:00:03	tar: nosedir: Cannot stat: No such file or directory
20-Apr-2026 15:00:03	tar: Exiting with failure status due to previous errors
20-Apr-2026 15:00:04	total 77452
20-Apr-2026 15:00:04	-rw-r--r-- 1 casaci 15001 160658 Apr 20 18:22 casatestutils-6.7.5.18-py3-none-any.whl
20-Apr-2026 15:00:04	-rw-r--r-- 1 casaci 15001 78972194 Apr 20 18:22 casatools-6.7.5.18-cp313-cp313-manylinux_2_28_x86_64.whl
20-Apr-2026 15:00:04	-rw-r--r-- 1 casaci root 4340 Apr 20 19:00 test_tool_agentflagger.xml
20-Apr-2026 15:00:04	-rw-r--r-- 1 casaci root 1006 Apr 20 19:00 test_tool_calanalysis.xml
20-Apr-2026 15:00:04	-rw-r--r-- 1 casaci root 2658 Apr 20 19:00 test_tool_calibrater.xml
20-Apr-2026 15:00:04	-rw-r--r-- 1 casaci root 687 Apr 20 19:00 test_tool_componentlist.xml
20-Apr-2026 15:00:04	-rw-r--r-- 1 casaci root 7467 Apr 20 19:00 test_tool_coordsys.xml
20-Apr-2026 15:00:04	-rw-r--r-- 1 casaci root 12935 Apr 20 19:00 test_tool_image.xml
20-Apr-2026 15:00:04	-rw-r--r-- 1 casaci root 2220 Apr 20 19:00 test_tool_image_collapse.xml
20-Apr-2026 15:00:04	-rw-r--r-- 1 casaci root 1048 Apr 20 19:00 test_tool_image_deviation.xml
20-Apr-2026 15:00:04	-rw-r--r-- 1 casaci root 2576 Apr 20 19:00 test_tool_image_fitprofile.xml
20-Apr-2026 15:00:04	-rw-r--r-- 1 casaci root 1178 Apr 20 19:00 test_tool_image_pbcor.xml
20-Apr-2026 15:00:04	-rw-r--r-- 1 casaci root 883 Apr 20 19:00 test_tool_image_pv.xml
20-Apr-2026 15:00:04	-rw-r--r-- 1 casaci root 1006 Apr 20 19:00 test_tool_image_rebin.xml
20-Apr-2026 15:00:04	-rw-r--r-- 1 casaci root 1336 Apr 20 19:00 test_tool_image_regrid.xml
20-Apr-2026 15:00:04	-rw-r--r-- 1 casaci root 1642 Apr 20 19:00 test_tool_image_statistics.xml
20-Apr-2026 15:00:04	-rw-r--r-- 1 casaci root 765 Apr 20 19:00 test_tool_image_subimage.xml
20-Apr-2026 15:00:04	-rw-r--r-- 1 casaci root 890 Apr 20 19:00 test_tool_image_transpose.xml
20-Apr-2026 15:00:04	-rw-r--r-- 1 casaci root 1966 Apr 20 19:00 test_tool_imagepol.xml
20-Apr-2026 15:00:04	-rw-r--r-- 1 casaci root 839 Apr 20 19:00 test_tool_linearmosaic.xml
20-Apr-2026 15:00:04	-rw-r--r-- 1 casaci root 669 Apr 20 19:00 test_tool_logsink.xml
20-Apr-2026 15:00:04	-rw-r--r-- 1 casaci root 549 Apr 20 19:00 test_tool_measures.xml
20-Apr-2026 15:00:04	-rw-r--r-- 1 casaci root 5224 Apr 20 19:00 test_tool_ms.xml
20-Apr-2026 15:00:04	-rw-r--r-- 1 casaci root 367 Apr 20 19:00 test_tool_ms_createmultims.xml
20-Apr-2026 15:00:04	-rw-r--r-- 1 casaci root 2095 Apr 20 19:00 test_tool_ms_statwt.xml
20-Apr-2026 15:00:04	-rw-r--r-- 1 casaci root 8633 Apr 20 19:00 test_tool_msmetadata.xml
20-Apr-2026 15:00:04	-rw-r--r-- 1 casaci root 361 Apr 20 19:00 test_tool_msuvbinner.xml
20-Apr-2026 15:00:04	-rw-r--r-- 1 casaci root 1171 Apr 20 19:00 test_tool_quanta.xml
20-Apr-2026 15:00:04	-rw-r--r-- 1 casaci root 3977 Apr 20 19:00 test_tool_regionmanager.xml
20-Apr-2026 15:00:04	-rw-r--r-- 1 casaci root 2072 Apr 20 19:00 test_tool_sdm.xml
20-Apr-2026 15:00:04	-rw-r--r-- 1 casaci root 2097 Apr 20 19:00 test_tool_sdm_toms.xml
20-Apr-2026 15:00:04	-rw-r--r-- 1 casaci root 670 Apr 20 19:00 test_tool_simulator.xml
20-Apr-2026 15:00:04	-rw-r--r-- 1 casaci root 1717 Apr 20 19:00 test_tool_synthesisutils.xml
20-Apr-2026 15:00:04	-rw-r--r-- 1 casaci root 1462 Apr 20 19:00 test_tool_table.xml
20-Apr-2026 15:00:04	-rw-r--r-- 1 casaci root 1717 Apr 20 19:00 test_tool_vpmanager.xml
20-Apr-2026 15:00:04	-rw-r--r-- 1 casaci root 45 Apr 20 19:00 work-manylinux228-3.13.tar.gz
20-Apr-2026 15:00:04	Done packaging working directory
20-Apr-2026 15:00:04	Finished task 'Tar work directory' with result: Success
20-Apr-2026 15:00:04	Starting task 'Parse tests' of type 'com.atlassian.bamboo.plugins.testresultparser:task.testresultparser.junit'
20-Apr-2026 15:00:04	Parsing test results under /export/home/cbt-el7-2/bamboohome/xml-data/build-dir/CASASPECS-RELEASE675TESTPY313-TTOMLPY313...
20-Apr-2026 15:00:04	Finished task 'Parse tests' with result: Success
20-Apr-2026 15:00:04	Substituting variable: ${bamboo.agentId} with 149651458
20-Apr-2026 15:00:04	Starting task 'Upload wheel' of type 'com.atlassian.bamboo.plugins.scripttask:task.builder.script'
20-Apr-2026 15:00:04	Beginning to execute external process for build 'CASASPECS - Release 6.7.5 Test 3.13 - Test Tools Many Linux 2.28 Rocky 8.10 Py3.13 #3 (CASASPECS-RELEASE675TESTPY313-TTOMLPY313-3)' ... running command line: /export/home/cbt-el7-2/bamboohome/temp/CASASPECS-RELEASE675TESTPY313-TTOMLPY313-3-ScriptBuildTask-3196794376651196019.sh ... in: /export/home/cbt-el7-2/bamboohome/xml-data/build-dir/CASASPECS-RELEASE675TESTPY313-TTOMLPY313
20-Apr-2026 15:00:07	Collecting twine
20-Apr-2026 15:00:07	Downloading twine-6.2.0-py3-none-any.whl (42 kB)
20-Apr-2026 15:00:07	━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 42.7/42.7 kB 2.7 MB/s eta 0:00:00
20-Apr-2026 15:00:08	Collecting packaging>=24.0
20-Apr-2026 15:00:08	Downloading packaging-26.1-py3-none-any.whl (95 kB)
20-Apr-2026 15:00:08	━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 95.8/95.8 kB 6.9 MB/s eta 0:00:00
20-Apr-2026 15:00:08	Collecting id
20-Apr-2026 15:00:08	Downloading id-1.6.1-py3-none-any.whl (14 kB)
20-Apr-2026 15:00:08	Collecting rfc3986>=1.4.0
20-Apr-2026 15:00:08	Downloading rfc3986-2.0.0-py2.py3-none-any.whl (31 kB)
20-Apr-2026 15:00:08	Collecting keyring>=21.2.0
20-Apr-2026 15:00:08	Downloading keyring-25.7.0-py3-none-any.whl (39 kB)
20-Apr-2026 15:00:08	Collecting requests-toolbelt!=0.9.0,>=0.8.0
20-Apr-2026 15:00:08	Downloading requests_toolbelt-1.0.0-py2.py3-none-any.whl (54 kB)
20-Apr-2026 15:00:08	━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 54.5/54.5 kB 9.6 MB/s eta 0:00:00
20-Apr-2026 15:00:08	Collecting urllib3>=1.26.0
20-Apr-2026 15:00:08	Downloading urllib3-2.6.3-py3-none-any.whl (131 kB)
20-Apr-2026 15:00:08	━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 131.6/131.6 kB 10.4 MB/s eta 0:00:00
20-Apr-2026 15:00:08	Collecting rich>=12.0.0
20-Apr-2026 15:00:08	Downloading rich-15.0.0-py3-none-any.whl (310 kB)
20-Apr-2026 15:00:08	━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 310.7/310.7 kB 12.9 MB/s eta 0:00:00
20-Apr-2026 15:00:08	Collecting requests>=2.20
20-Apr-2026 15:00:08	Downloading requests-2.33.1-py3-none-any.whl (64 kB)
20-Apr-2026 15:00:08	━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 64.9/64.9 kB 11.3 MB/s eta 0:00:00
20-Apr-2026 15:00:08	Collecting readme-renderer>=35.0
20-Apr-2026 15:00:08	Downloading readme_renderer-44.0-py3-none-any.whl (13 kB)
20-Apr-2026 15:00:08	Collecting jaraco.classes
20-Apr-2026 15:00:08	Downloading jaraco.classes-3.4.0-py3-none-any.whl (6.8 kB)
20-Apr-2026 15:00:09	Collecting jeepney>=0.4.2
20-Apr-2026 15:00:09	Downloading jeepney-0.9.0-py3-none-any.whl (49 kB)
20-Apr-2026 15:00:09	━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 49.0/49.0 kB 8.1 MB/s eta 0:00:00
20-Apr-2026 15:00:09	Collecting importlib_metadata>=4.11.4
20-Apr-2026 15:00:09	Downloading importlib_metadata-9.0.0-py3-none-any.whl (27 kB)
20-Apr-2026 15:00:09	Collecting SecretStorage>=3.2
20-Apr-2026 15:00:09	Downloading secretstorage-3.5.0-py3-none-any.whl (15 kB)
20-Apr-2026 15:00:09	Collecting jaraco.context
20-Apr-2026 15:00:09	Downloading jaraco_context-6.1.2-py3-none-any.whl (7.9 kB)
20-Apr-2026 15:00:09	Collecting jaraco.functools
20-Apr-2026 15:00:09	Downloading jaraco_functools-4.4.0-py3-none-any.whl (10 kB)
20-Apr-2026 15:00:09	Collecting nh3>=0.2.14
20-Apr-2026 15:00:09	Downloading nh3-0.3.4-cp38-abi3-manylinux_2_17_x86_64.manylinux2014_x86_64.whl (804 kB)
20-Apr-2026 15:00:09	━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 805.0/805.0 kB 19.6 MB/s eta 0:00:00
20-Apr-2026 15:00:09	Collecting Pygments>=2.5.1
20-Apr-2026 15:00:09	Downloading pygments-2.20.0-py3-none-any.whl (1.2 MB)
20-Apr-2026 15:00:09	━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 26.1 MB/s eta 0:00:00
20-Apr-2026 15:00:09	Collecting docutils>=0.21.2
20-Apr-2026 15:00:09	Downloading docutils-0.22.4-py3-none-any.whl (633 kB)
20-Apr-2026 15:00:09	━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 633.2/633.2 kB 32.8 MB/s eta 0:00:00
20-Apr-2026 15:00:09	Collecting idna<4,>=2.5
20-Apr-2026 15:00:09	Downloading idna-3.11-py3-none-any.whl (71 kB)
20-Apr-2026 15:00:09	━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 71.0/71.0 kB 12.9 MB/s eta 0:00:00
20-Apr-2026 15:00:09	Collecting certifi>=2023.5.7
20-Apr-2026 15:00:09	Downloading certifi-2026.2.25-py3-none-any.whl (153 kB)
20-Apr-2026 15:00:09	━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 153.7/153.7 kB 22.5 MB/s eta 0:00:00
20-Apr-2026 15:00:10	Collecting charset_normalizer<4,>=2
20-Apr-2026 15:00:10	Downloading charset_normalizer-3.4.7-cp310-cp310-manylinux2014_x86_64.manylinux_2_17_x86_64.manylinux_2_28_x86_64.whl (216 kB)
20-Apr-2026 15:00:10	━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 216.9/216.9 kB 21.7 MB/s eta 0:00:00
20-Apr-2026 15:00:10	Collecting markdown-it-py>=2.2.0
20-Apr-2026 15:00:10	Downloading markdown_it_py-4.0.0-py3-none-any.whl (87 kB)
20-Apr-2026 15:00:10	━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 87.3/87.3 kB 12.2 MB/s eta 0:00:00
20-Apr-2026 15:00:10	Collecting zipp>=3.20
20-Apr-2026 15:00:10	Downloading zipp-3.23.1-py3-none-any.whl (10 kB)
20-Apr-2026 15:00:10	Collecting mdurl~=0.1
20-Apr-2026 15:00:10	Downloading mdurl-0.1.2-py3-none-any.whl (10.0 kB)
20-Apr-2026 15:00:11	Collecting cryptography>=2.0
20-Apr-2026 15:00:11	Downloading cryptography-46.0.7-cp38-abi3-manylinux_2_28_x86_64.whl (4.5 MB)
20-Apr-2026 15:00:11	━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 4.5/4.5 MB 31.3 MB/s eta 0:00:00
20-Apr-2026 15:00:12	Collecting more-itertools
20-Apr-2026 15:00:12	Downloading more_itertools-11.0.2-py3-none-any.whl (71 kB)
20-Apr-2026 15:00:12	━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 71.9/71.9 kB 14.0 MB/s eta 0:00:00
20-Apr-2026 15:00:12	Collecting backports.tarfile
20-Apr-2026 15:00:12	Downloading backports.tarfile-1.2.0-py3-none-any.whl (30 kB)
20-Apr-2026 15:00:12	Collecting cffi>=2.0.0
20-Apr-2026 15:00:12	Downloading cffi-2.0.0-cp310-cp310-manylinux2014_x86_64.manylinux_2_17_x86_64.whl (216 kB)
20-Apr-2026 15:00:12	━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 216.5/216.5 kB 21.1 MB/s eta 0:00:00
20-Apr-2026 15:00:12	Collecting typing-extensions>=4.13.2
20-Apr-2026 15:00:12	Downloading typing_extensions-4.15.0-py3-none-any.whl (44 kB)
20-Apr-2026 15:00:12	━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 44.6/44.6 kB 7.7 MB/s eta 0:00:00
20-Apr-2026 15:00:12	Collecting pycparser
20-Apr-2026 15:00:12	Downloading pycparser-3.0-py3-none-any.whl (48 kB)
20-Apr-2026 15:00:13	━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 48.2/48.2 kB 9.7 MB/s eta 0:00:00
20-Apr-2026 15:00:13	Installing collected packages: zipp, urllib3, typing-extensions, rfc3986, Pygments, pycparser, packaging, nh3, more-itertools, mdurl, jeepney, idna, docutils, charset_normalizer, certifi, backports.tarfile, requests, readme-renderer, markdown-it-py, jaraco.functools, jaraco.context, jaraco.classes, importlib_metadata, id, cffi, rich, requests-toolbelt, cryptography, SecretStorage, keyring, twine
20-Apr-2026 15:00:16	Successfully installed Pygments-2.20.0 SecretStorage-3.5.0 backports.tarfile-1.2.0 certifi-2026.2.25 cffi-2.0.0 charset_normalizer-3.4.7 cryptography-46.0.7 docutils-0.22.4 id-1.6.1 idna-3.11 importlib_metadata-9.0.0 jaraco.classes-3.4.0 jaraco.context-6.1.2 jaraco.functools-4.4.0 jeepney-0.9.0 keyring-25.7.0 markdown-it-py-4.0.0 mdurl-0.1.2 more-itertools-11.0.2 nh3-0.3.4 packaging-26.1 pycparser-3.0 readme-renderer-44.0 requests-2.33.1 requests-toolbelt-1.0.0 rfc3986-2.0.0 rich-15.0.0 twine-6.2.0 typing-extensions-4.15.0 urllib3-2.6.3 zipp-3.23.1
20-Apr-2026 15:00:16	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
20-Apr-2026 15:00:17
20-Apr-2026 15:00:17	[notice] A new release of pip is available: 23.0.1 -> 26.0.1
20-Apr-2026 15:00:17	[notice] To update, run: pip3 install --upgrade pip
20-Apr-2026 15:00:17	Cloning into 'casa-build-utils'...
20-Apr-2026 15:00:18	Uploading distributions to
20-Apr-2026 15:00:18	https://casa-pip.nrao.edu:443/repository/casa-test-wheel/
20-Apr-2026 15:00:19	Uploading casatools-6.7.5.18-cp313-cp313-manylinux_2_28_x86_64.whl
20-Apr-2026 15:00:19
20-Apr-2026 15:00:19	0% ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 0.0/79.0 MB • --:-- • ?
20-Apr-2026 15:00:20	1% ╸━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.1/79.0 MB • 00:05 • 17.7 MB/s
20-Apr-2026 15:00:20	4% ━╸━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 3.1/79.0 MB • 00:05 • 18.4 MB/s
20-Apr-2026 15:00:20	7% ━━╸━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 5.8/79.0 MB • 00:04 • 21.3 MB/s
20-Apr-2026 15:00:20	12% ━━━━╸━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 9.3/79.0 MB • 00:03 • 24.9 MB/s
20-Apr-2026 15:00:20	16% ━━━━━━╺━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 12.5/79.0 MB • 00:03 • 25.9 MB/s
20-Apr-2026 15:00:20	20% ━━━━━━━╸━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 15.7/79.0 MB • 00:03 • 26.8 MB/s
20-Apr-2026 15:00:20	22% ━━━━━━━━╸━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 17.4/79.0 MB • 00:03 • 25.4 MB/s
20-Apr-2026 15:00:20	24% ━━━━━━━━━╸━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 19.0/79.0 MB • 00:03 • 24.8 MB/s
20-Apr-2026 15:00:20	29% ━━━━━━━━━━━╺━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 22.5/79.0 MB • 00:03 • 26.2 MB/s
20-Apr-2026 15:00:21	31% ━━━━━━━━━━━━╺━━━━━━━━━━━━━━━━━━━━━━━━━━━ 24.5/79.0 MB • 00:03 • 24.3 MB/s
20-Apr-2026 15:00:21	37% ━━━━━━━━━━━━━━╸━━━━━━━━━━━━━━━━━━━━━━━━━ 29.1/79.0 MB • 00:02 • 26.4 MB/s
20-Apr-2026 15:00:21	39% ━━━━━━━━━━━━━━━╸━━━━━━━━━━━━━━━━━━━━━━━━ 31.2/79.0 MB • 00:02 • 25.9 MB/s
20-Apr-2026 15:00:21	42% ━━━━━━━━━━━━━━━━╸━━━━━━━━━━━━━━━━━━━━━━━ 33.0/79.0 MB • 00:02 • 24.0 MB/s
20-Apr-2026 15:00:21	44% ━━━━━━━━━━━━━━━━━╺━━━━━━━━━━━━━━━━━━━━━━ 34.5/79.0 MB • 00:02 • 26.4 MB/s
20-Apr-2026 15:00:21	46% ━━━━━━━━━━━━━━━━━━╺━━━━━━━━━━━━━━━━━━━━━ 36.5/79.0 MB • 00:02 • 23.6 MB/s
20-Apr-2026 15:00:21	50% ━━━━━━━━━━━━━━━━━━━╸━━━━━━━━━━━━━━━━━━━━ 39.3/79.0 MB • 00:02 • 23.3 MB/s
20-Apr-2026 15:00:21	51% ━━━━━━━━━━━━━━━━━━━━╺━━━━━━━━━━━━━━━━━━━ 40.4/79.0 MB • 00:02 • 22.0 MB/s
20-Apr-2026 15:00:21	54% ━━━━━━━━━━━━━━━━━━━━━╸━━━━━━━━━━━━━━━━━━ 42.7/79.0 MB • 00:02 • 21.8 MB/s
20-Apr-2026 15:00:21	56% ━━━━━━━━━━━━━━━━━━━━━━╺━━━━━━━━━━━━━━━━━ 44.2/79.0 MB • 00:02 • 19.3 MB/s
20-Apr-2026 15:00:22	59% ━━━━━━━━━━━━━━━━━━━━━━━╸━━━━━━━━━━━━━━━━ 46.9/79.0 MB • 00:02 • 18.6 MB/s
20-Apr-2026 15:00:22	61% ━━━━━━━━━━━━━━━━━━━━━━━━╺━━━━━━━━━━━━━━━ 48.1/79.0 MB • 00:02 • 18.9 MB/s
20-Apr-2026 15:00:22	64% ━━━━━━━━━━━━━━━━━━━━━━━━━╺━━━━━━━━━━━━━━ 50.2/79.0 MB • 00:02 • 18.4 MB/s
20-Apr-2026 15:00:22	65% ━━━━━━━━━━━━━━━━━━━━━━━━━━╺━━━━━━━━━━━━━ 51.5/79.0 MB • 00:02 • 19.7 MB/s
20-Apr-2026 15:00:22	69% ━━━━━━━━━━━━━━━━━━━━━━━━━━━╺━━━━━━━━━━━━ 54.3/79.0 MB • 00:02 • 18.7 MB/s
20-Apr-2026 15:00:22	70% ━━━━━━━━━━━━━━━━━━━━━━━━━━━━╺━━━━━━━━━━━ 55.4/79.0 MB • 00:02 • 17.2 MB/s
20-Apr-2026 15:00:22	74% ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━╸━━━━━━━━━━ 58.6/79.0 MB • 00:02 • 18.5 MB/s
20-Apr-2026 15:00:22	78% ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━╺━━━━━━━━ 61.8/79.0 MB • 00:01 • 20.5 MB/s
20-Apr-2026 15:00:22	82% ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━╸━━━━━━━ 64.7/79.0 MB • 00:01 • 22.5 MB/s
20-Apr-2026 15:00:22	85% ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━╸━━━━━━ 67.1/79.0 MB • 00:01 • 22.5 MB/s
20-Apr-2026 15:00:23	89% ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━╸━━━━ 70.1/79.0 MB • 00:01 • 25.6 MB/s
20-Apr-2026 15:00:23	92% ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━╸━━━ 72.4/79.0 MB • 00:01 • 27.3 MB/s
20-Apr-2026 15:00:23	94% ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━╸━━ 74.6/79.0 MB • 00:01 • 25.9 MB/s
20-Apr-2026 15:00:23	98% ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━╺ 77.3/79.0 MB • 00:01 • 27.9 MB/s
20-Apr-2026 15:00:23	100% ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 79.0/79.0 MB • 00:03 • 25.2 MB/s
20-Apr-2026 15:00:23	100% ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 79.0/79.0 MB • 00:03 • 25.2 MB/s
20-Apr-2026 15:00:23	100% ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 79.0/79.0 MB • 00:03 • 25.2 MB/s
20-Apr-2026 15:00:23	100% ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 79.0/79.0 MB • 00:03 • 25.2 MB/s
20-Apr-2026 15:00:23	100% ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 79.0/79.0 MB • 00:03 • 25.2 MB/s
20-Apr-2026 15:00:24	Uploading distributions to
20-Apr-2026 15:00:24	https://casa-pip.nrao.edu:443/repository/casa-test-wheel/
20-Apr-2026 15:00:24	Uploading casatestutils-6.7.5.18-py3-none-any.whl
20-Apr-2026 15:00:24
20-Apr-2026 15:00:24	0% ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 0.0/174.0 kB • --:-- • ?
20-Apr-2026 15:00:24	100% ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 174.0/174.0 kB • 00:00 • 14.3 MB/s
20-Apr-2026 15:00:24	WARNING Error during upload. Retry with the --verbose option for more details.
20-Apr-2026 15:00:24	ERROR HTTPError: 400 Bad Request from
20-Apr-2026 15:00:24	https://casa-pip.nrao.edu:443/repository/casa-test-wheel/
20-Apr-2026 15:00:24	Repository does not allow updating assets: casa-test-wheel
20-Apr-2026 15:00:24	Finished task 'Upload wheel' with result: Success
20-Apr-2026 15:00:24	Substituting variable: ${bamboo.agentId} with 149651458
20-Apr-2026 15:00:24	Substituting variable: ${bamboo.agentId} with 149651458
20-Apr-2026 15:00:24	Starting task 'Cleanup' of type 'com.atlassian.bamboo.plugins.scripttask:task.builder.script'
20-Apr-2026 15:00:24	Beginning to execute external process for build 'CASASPECS - Release 6.7.5 Test 3.13 - Test Tools Many Linux 2.28 Rocky 8.10 Py3.13 #3 (CASASPECS-RELEASE675TESTPY313-TTOMLPY313-3)' ... running command line: /export/home/cbt-el7-2/bamboohome/temp/CASASPECS-RELEASE675TESTPY313-TTOMLPY313-3-ScriptBuildTask-345498847474164138.sh ... in: /export/home/cbt-el7-2/bamboohome/xml-data/build-dir/CASASPECS-RELEASE675TESTPY313-TTOMLPY313
20-Apr-2026 15:00:24	Starting cleanup
20-Apr-2026 15:00:37	wheel-container-test-149651458
20-Apr-2026 15:00:49	wheel-container-test-149651458
20-Apr-2026 15:00:49	Cleanup complete
20-Apr-2026 15:00:49	Finished task 'Cleanup' with result: Success
20-Apr-2026 15:00:49	Running post build plugin 'Docker Container Cleanup'
20-Apr-2026 15:00:49	Beginning to execute external process for build 'CASASPECS - Release 6.7.5 Test 3.13 - Test Tools Many Linux 2.28 Rocky 8.10 Py3.13 #3 (CASASPECS-RELEASE675TESTPY313-TTOMLPY313-3)' ... running command line: /usr/bin/docker rm -f wheel-container-test-149651458 ... in: /export/home/cbt-el7-2/bamboohome/xml-data/build-dir/CASASPECS-RELEASE675TESTPY313-TTOMLPY313
20-Apr-2026 15:00:49	Error response from daemon: No such container: wheel-container-test-149651458
20-Apr-2026 15:00:49	Running post build plugin 'NCover Results Collector'
20-Apr-2026 15:00:49	Running post build plugin 'Build Results Label Collector'
20-Apr-2026 15:00:49	Running post build plugin 'Clover Results Collector'
20-Apr-2026 15:00:49	Running post build plugin 'npm Cache Cleanup'
20-Apr-2026 15:00:49	Running post build plugin 'Artifact Copier'
20-Apr-2026 15:00:49	Publishing an artifact: Workdir
20-Apr-2026 15:00:49	Finished publishing of artifact Non required job artifact Http Compression On : [Workdir], patterns: [work*.tar.gz] anchored at: [wheeldirectory/] in 224.0 ms
20-Apr-2026 15:00:49	Publishing an artifact: XML Directories
20-Apr-2026 15:00:50	Finished publishing of artifact Non required job artifact Http Compression On : [XML Directories], patterns: [*/.xml] anchored at: [wheeldirectory/] in 565.5 ms
20-Apr-2026 15:00:50	Finalising the build...
20-Apr-2026 15:00:50	Stopping timer.
20-Apr-2026 15:00:50	Build CASASPECS-RELEASE675TESTPY313-TTOMLPY313-3 completed.
20-Apr-2026 15:00:50	Running on server: post build plugin 'Build Hanging Detection Configuration'
20-Apr-2026 15:00:50	Running on server: post build plugin 'NCover Results Collector'
20-Apr-2026 15:00:50	Running on server: post build plugin 'Build Labeller'
20-Apr-2026 15:00:50	Running on server: post build plugin 'Clover Delta Calculator'
20-Apr-2026 15:00:50	Running on server: post build plugin 'Maven Dependencies Postprocessor'
20-Apr-2026 15:00:50	All post build plugins have finished
20-Apr-2026 15:00:50	Generating build results summary...
20-Apr-2026 15:00:51	Saving build results to disk...
20-Apr-2026 15:00:51	Store variable context...
20-Apr-2026 15:00:51	Finished building CASASPECS-RELEASE675TESTPY313-TTOMLPY313-3.

Build: #3 was successful

Job: Test Tools Many Linux 2.28 Rocky 8.10 Py3.13 was successful

Stages & jobs

Default Stage

Build log

Build #3

Build: #3 was successful

Job: Test Tools Many Linux 2.28 Rocky 8.10 Py3.13 was successful

Stages & jobs

Default Stage

Build log