[11:41:23.296] INFO: *** Welcome to pxar ***
[11:41:23.296] INFO: *** Today: 2015/08/04
[11:41:23.296] INFO: readRocDacs: /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/dacParameters_C0.dat .. /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/dacParameters_C15.dat
[11:41:23.298] INFO: readTbmDacs: /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/tbmParameters_C0a.dat .. /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/tbmParameters_C0b.dat
[11:41:23.298] INFO: readMaskFile: /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/defaultMaskFile.dat
[11:41:23.298] INFO: readTrimFile: /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/trimParameters_C0.dat .. /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/trimParameters_C15.dat
[11:41:23.396] INFO: clk: 4
[11:41:23.396] INFO: ctr: 4
[11:41:23.396] INFO: sda: 19
[11:41:23.396] INFO: tin: 9
[11:41:23.396] INFO: level: 15
[11:41:23.396] INFO: triggerdelay: 0
[11:41:23.396] QUIET: Instanciating API for pxar prod-01+36~geb5ac3f
[11:41:23.396] INFO: Log level: INFO
[11:41:23.407] INFO: Found DTB DTB_WZ4WY6
[11:41:23.421] QUIET: Connection to board DTB_WZ4WY6 opened.
[11:41:23.424] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 175
HW version: DTB1.2
FW version: 4.0
SW version: 4.0
USB id: DTB_WZ4WY6
MAC address: 40D8551180AF
Hostname: pixelDTB175
Comment:
------------------------------------------------------
[11:41:23.427] INFO: RPC call hashes of host and DTB match: 447413373
[11:41:25.207] INFO: DUT info:
[11:41:25.207] INFO: The DUT currently contains the following objects:
[11:41:25.207] INFO: 2 TBM Cores tbm08c (2 ON)
[11:41:25.207] INFO: TBM Core alpha (0): 7 registers set
[11:41:25.207] INFO: TBM Core beta (1): 7 registers set
[11:41:25.207] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[11:41:25.207] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[11:41:25.207] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[11:41:25.207] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[11:41:25.207] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[11:41:25.207] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[11:41:25.207] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[11:41:25.207] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[11:41:25.207] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[11:41:25.207] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[11:41:25.207] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[11:41:25.207] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[11:41:25.207] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[11:41:25.207] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[11:41:25.207] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[11:41:25.207] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[11:41:25.207] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[11:41:25.609] INFO: enter 'restricted' command line mode
[11:41:25.609] INFO: enter test to run
[11:41:25.609] INFO: test: pretest no parameter change
[11:41:25.609] INFO: running: pretest
[11:41:25.619] INFO: ######################################################################
[11:41:25.619] INFO: PixTestPretest::doTest()
[11:41:25.619] INFO: ######################################################################
[11:41:25.621] INFO: ----------------------------------------------------------------------
[11:41:25.621] INFO: PixTestPretest::programROC()
[11:41:25.622] INFO: ----------------------------------------------------------------------
[11:41:43.645] INFO: PixTestPretest::programROC() done: ROCs are all programmable
[11:41:43.645] INFO: IA differences per ROC: 17.7 18.5 19.3 18.5 20.1 17.7 21.7 19.3 19.3 21.7 18.5 20.1 16.1 19.3 18.5 19.3
[11:41:43.742] INFO: ----------------------------------------------------------------------
[11:41:43.742] INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[11:41:43.742] INFO: ----------------------------------------------------------------------
[11:42:03.418] INFO: PixTestPretest::setVana() done, Module Ia 381.9 mA = 23.8688 mA/ROC
[11:42:03.422] INFO: ----------------------------------------------------------------------
[11:42:03.422] INFO: PixTestPretest::findWorkingPixel()
[11:42:03.422] INFO: ----------------------------------------------------------------------
[11:42:10.890] INFO: Test took 7458ms.
[11:42:11.235] INFO: Found working pixel in all ROCs: col/row = 12/22
[11:42:11.318] INFO: ----------------------------------------------------------------------
[11:42:11.318] INFO: PixTestPretest::setVthrCompCalDel()
[11:42:11.318] INFO: ----------------------------------------------------------------------
[11:42:18.811] INFO: Test took 7483ms.
[11:42:19.165] INFO: PixTestPretest::setVthrCompCalDel() done
[11:42:19.165] INFO: CalDel: 109 146 123 126 141 136 126 106 124 137 133 131 123 111 130 134
[11:42:19.165] INFO: VthrComp: 51 51 53 51 51 51 51 51 51 51 51 51 54 51 51 51
[11:42:19.170] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/dacParameters_C0.dat
[11:42:19.170] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/dacParameters_C1.dat
[11:42:19.171] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/dacParameters_C2.dat
[11:42:19.171] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/dacParameters_C3.dat
[11:42:19.171] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/dacParameters_C4.dat
[11:42:19.171] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/dacParameters_C5.dat
[11:42:19.172] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/dacParameters_C6.dat
[11:42:19.172] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/dacParameters_C7.dat
[11:42:19.172] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/dacParameters_C8.dat
[11:42:19.172] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/dacParameters_C9.dat
[11:42:19.173] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/dacParameters_C10.dat
[11:42:19.173] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/dacParameters_C11.dat
[11:42:19.173] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/dacParameters_C12.dat
[11:42:19.173] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/dacParameters_C13.dat
[11:42:19.174] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/dacParameters_C14.dat
[11:42:19.174] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/dacParameters_C15.dat
[11:42:19.174] INFO: PixTestPretest::doTest() done, duration: 53 seconds
[11:42:19.263] INFO: enter test to run
[11:42:19.263] INFO: test: fulltest no parameter change
[11:42:19.263] INFO: running: fulltest
[11:42:19.263] INFO: ######################################################################
[11:42:19.263] INFO: PixTestFullTest::doTest()
[11:42:19.263] INFO: ######################################################################
[11:42:19.264] INFO: ######################################################################
[11:42:19.264] INFO: PixTestAlive::doTest()
[11:42:19.264] INFO: ######################################################################
[11:42:19.266] INFO: ----------------------------------------------------------------------
[11:42:19.266] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[11:42:19.266] INFO: ----------------------------------------------------------------------
[11:42:22.870] INFO: Test took 3602ms.
[11:42:22.904] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:42:23.148] INFO: PixTestAlive::aliveTest() done
[11:42:23.148] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 5 0 0 0 0 0 0
[11:42:23.150] INFO: ----------------------------------------------------------------------
[11:42:23.150] INFO: PixTestAlive::maskTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[11:42:23.150] INFO: ----------------------------------------------------------------------
[11:42:25.985] INFO: Test took 2833ms.
[11:42:25.992] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:42:25.992] INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[11:42:26.241] INFO: PixTestAlive::maskTest() done
[11:42:26.241] INFO: number of mask-defect pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:42:26.243] INFO: ----------------------------------------------------------------------
[11:42:26.243] INFO: PixTestAlive::addressDecodingTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[11:42:26.243] INFO: ----------------------------------------------------------------------
[11:42:29.811] INFO: Test took 3565ms.
[11:42:29.840] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:42:30.096] INFO: PixTestAlive::addressDecodingTest() done
[11:42:30.096] INFO: number of address-decoding pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:42:30.096] INFO: PixTestAlive::doTest() done, duration: 10 seconds
[11:42:30.110] INFO: ######################################################################
[11:42:30.110] INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[11:42:30.110] INFO: ######################################################################
[11:42:30.114] INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (30/5) hits flags = 2 (plus default)
[11:42:30.138] INFO: dacScan step from 0 .. 29
[11:42:30.138] INFO: dacScan split into 1 runs with ntrig = 5
[11:42:30.138] INFO: run 1 of 1
[11:42:49.706] INFO: Test took 19568ms.
[11:42:49.768] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:42:49.768] INFO: dacScan step from 30 .. 59
[11:42:49.768] INFO: dacScan split into 1 runs with ntrig = 5
[11:42:49.768] INFO: run 1 of 1
[11:43:09.786] INFO: Test took 20017ms.
[11:43:09.888] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:43:09.897] INFO: dacScan step from 60 .. 89
[11:43:09.897] INFO: dacScan split into 1 runs with ntrig = 5
[11:43:09.897] INFO: run 1 of 1
[11:43:35.275] INFO: Test took 25378ms.
[11:43:35.688] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:43:35.779] INFO: dacScan step from 90 .. 119
[11:43:35.779] INFO: dacScan split into 1 runs with ntrig = 5
[11:43:35.779] INFO: run 1 of 1
[11:44:03.105] INFO: Test took 27325ms.
[11:44:03.590] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:44:03.700] INFO: dacScan step from 120 .. 149
[11:44:03.700] INFO: dacScan split into 1 runs with ntrig = 5
[11:44:03.700] INFO: run 1 of 1
[11:44:27.809] INFO: Test took 24109ms.
[11:44:28.158] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:45:09.267] INFO: PixTestBBMap::doTest() done, duration: 159 seconds
[11:45:09.267] INFO: number of dead bumps (per ROC): 0 0 0 0 0 0 0 0 0 3 0 0 0 0 0 0
[11:45:09.267] INFO: separation cut (per ROC): 113 92 118 108 108 97 116 146 118 102 93 96 103 116 109 133
[11:45:09.384] INFO: ######################################################################
[11:45:09.384] INFO: PixTestScurves::fullTest() ntrig = 50, dacs/step = -1, ntrig/step = 1
[11:45:09.384] INFO: ######################################################################
[11:45:09.385] INFO: ----------------------------------------------------------------------
[11:45:09.385] INFO: PixTestScurves::scurves(Vcal), ntrig = 50, dacs/step = -1, ntrig/step = 1
[11:45:09.385] INFO: ----------------------------------------------------------------------
[11:45:09.385] INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 0 .. 149 (-1/1) hits flags = 16 (plus default)
[11:45:09.400] INFO: dacScan split into 50 runs with ntrig = 1
[11:45:09.400] INFO: run 1 of 50
[11:45:58.276] INFO: Test took 48876ms.
[11:45:58.700] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:45:58.918] INFO: run 2 of 50
[11:46:47.782] INFO: Test took 48864ms.
[11:46:48.197] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:46:48.398] INFO: run 3 of 50
[11:47:37.262] INFO: Test took 48864ms.
[11:47:37.695] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:47:37.903] INFO: run 4 of 50
[11:48:26.779] INFO: Test took 48876ms.
[11:48:27.219] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:48:27.411] INFO: run 5 of 50
[11:49:16.270] INFO: Test took 48859ms.
[11:49:16.682] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:49:16.884] INFO: run 6 of 50
[11:50:05.667] INFO: Test took 48782ms.
[11:50:06.034] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:50:06.230] INFO: run 7 of 50
[11:50:55.071] INFO: Test took 48841ms.
[11:50:55.487] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:50:55.688] INFO: run 8 of 50
[11:51:44.532] INFO: Test took 48844ms.
[11:51:44.976] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:51:45.176] INFO: run 9 of 50
[11:52:34.052] INFO: Test took 48876ms.
[11:52:34.484] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:52:34.729] INFO: run 10 of 50
[11:53:23.595] INFO: Test took 48865ms.
[11:53:23.990] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:53:24.180] INFO: run 11 of 50
[11:54:13.078] INFO: Test took 48898ms.
[11:54:13.475] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:54:13.676] INFO: run 12 of 50
[11:55:02.640] INFO: Test took 48964ms.
[11:55:03.041] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:55:03.250] INFO: run 13 of 50
[11:55:52.223] INFO: Test took 48973ms.
[11:55:52.590] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:55:52.860] INFO: run 14 of 50
[11:56:41.780] INFO: Test took 48920ms.
[11:56:42.162] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:56:42.380] INFO: run 15 of 50
[11:57:31.332] INFO: Test took 48952ms.
[11:57:31.719] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:57:31.923] INFO: run 16 of 50
[11:58:20.893] INFO: Test took 48970ms.
[11:58:21.375] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:58:21.564] INFO: run 17 of 50
[11:59:10.565] INFO: Test took 49001ms.
[11:59:10.968] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:59:11.161] INFO: run 18 of 50
[12:00:00.079] INFO: Test took 48918ms.
[12:00:00.444] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:00:00.638] INFO: run 19 of 50
[12:00:49.631] INFO: Test took 48993ms.
[12:00:50.011] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:00:50.207] INFO: run 20 of 50
[12:01:39.262] INFO: Test took 49055ms.
[12:01:39.649] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:01:39.828] INFO: run 21 of 50
[12:02:28.770] INFO: Test took 48942ms.
[12:02:29.140] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:02:29.338] INFO: run 22 of 50
[12:03:18.362] INFO: Test took 49024ms.
[12:03:18.764] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:03:18.960] INFO: run 23 of 50
[12:04:08.061] INFO: Test took 49101ms.
[12:04:08.463] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:04:08.667] INFO: run 24 of 50
[12:04:57.795] INFO: Test took 49128ms.
[12:04:58.216] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:04:58.424] INFO: run 25 of 50
[12:05:47.427] INFO: Test took 49003ms.
[12:05:47.835] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:05:48.011] INFO: run 26 of 50
[12:06:36.960] INFO: Test took 48949ms.
[12:06:37.348] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:06:37.545] INFO: run 27 of 50
[12:07:26.611] INFO: Test took 49066ms.
[12:07:27.017] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:07:27.217] INFO: run 28 of 50
[12:08:16.311] INFO: Test took 49095ms.
[12:08:16.715] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:08:16.908] INFO: run 29 of 50
[12:09:06.025] INFO: Test took 49116ms.
[12:09:06.404] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:09:06.604] INFO: run 30 of 50
[12:09:55.742] INFO: Test took 49137ms.
[12:09:56.214] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:09:56.414] INFO: run 31 of 50
[12:10:45.466] INFO: Test took 49051ms.
[12:10:45.861] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:10:46.056] INFO: run 32 of 50
[12:11:35.206] INFO: Test took 49150ms.
[12:11:35.605] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:11:35.804] INFO: run 33 of 50
[12:12:24.981] INFO: Test took 49177ms.
[12:12:25.452] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:12:25.681] INFO: run 34 of 50
[12:13:14.955] INFO: Test took 49274ms.
[12:13:15.329] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:13:15.514] INFO: run 35 of 50
[12:14:04.771] INFO: Test took 49258ms.
[12:14:05.167] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:14:05.361] INFO: run 36 of 50
[12:14:54.600] INFO: Test took 49239ms.
[12:14:54.964] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:14:55.162] INFO: run 37 of 50
[12:15:44.406] INFO: Test took 49244ms.
[12:15:44.782] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:15:44.968] INFO: run 38 of 50
[12:16:34.235] INFO: Test took 49267ms.
[12:16:34.584] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:16:34.763] INFO: run 39 of 50
[12:17:24.067] INFO: Test took 49304ms.
[12:17:24.444] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:17:24.627] INFO: run 40 of 50
[12:18:13.765] INFO: Test took 49137ms.
[12:18:14.182] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:18:14.406] INFO: run 41 of 50
[12:19:03.717] INFO: Test took 49311ms.
[12:19:04.117] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:19:04.318] INFO: run 42 of 50
[12:19:53.621] INFO: Test took 49303ms.
[12:19:54.017] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:19:54.218] INFO: run 43 of 50
[12:20:43.539] INFO: Test took 49320ms.
[12:20:43.929] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:20:44.126] INFO: run 44 of 50
[12:21:33.506] INFO: Test took 49380ms.
[12:21:33.884] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:21:34.081] INFO: run 45 of 50
[12:22:23.338] INFO: Test took 49257ms.
[12:22:23.800] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:22:24.032] INFO: run 46 of 50
[12:23:13.379] INFO: Test took 49347ms.
[12:23:13.766] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:23:13.965] INFO: run 47 of 50
[12:24:03.304] INFO: Test took 49339ms.
[12:24:03.793] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:24:04.033] INFO: run 48 of 50
[12:24:53.414] INFO: Test took 49381ms.
[12:24:53.810] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:24:54.007] INFO: run 49 of 50
[12:25:43.317] INFO: Test took 49310ms.
[12:25:43.711] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:25:43.917] INFO: run 50 of 50
[12:26:32.978] INFO: Test took 49061ms.
[12:26:33.421] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:26:33.639] INFO: dumping ASCII scurve output file: SCurveData
[12:26:36.054] INFO: dumping ASCII scurve output file: SCurveData
[12:26:38.422] INFO: dumping ASCII scurve output file: SCurveData
[12:26:40.709] INFO: dumping ASCII scurve output file: SCurveData
[12:26:43.554] INFO: dumping ASCII scurve output file: SCurveData
[12:26:46.517] INFO: dumping ASCII scurve output file: SCurveData
[12:26:49.229] INFO: dumping ASCII scurve output file: SCurveData
[12:26:51.947] INFO: dumping ASCII scurve output file: SCurveData
[12:26:54.716] INFO: dumping ASCII scurve output file: SCurveData
[12:26:57.366] INFO: dumping ASCII scurve output file: SCurveData
[12:27:00.149] INFO: dumping ASCII scurve output file: SCurveData
[12:27:02.810] INFO: dumping ASCII scurve output file: SCurveData
[12:27:05.080] INFO: dumping ASCII scurve output file: SCurveData
[12:27:07.376] INFO: dumping ASCII scurve output file: SCurveData
[12:27:09.573] INFO: dumping ASCII scurve output file: SCurveData
[12:27:11.858] INFO: dumping ASCII scurve output file: SCurveData
[12:27:14.359] INFO: PixTestScurves::scurves() done
[12:27:14.359] INFO: Vcal mean: 93.75 84.66 109.02 92.44 94.97 90.25 92.26 108.96 99.01 86.12 84.71 86.20 102.54 105.94 94.94 95.91
[12:27:14.359] INFO: Vcal RMS: 5.15 5.99 5.43 5.38 5.86 6.10 5.58 6.04 7.09 5.86 5.21 5.30 6.21 5.61 6.09 5.59
[12:27:14.359] INFO: PixTestScurves::fullTest() done, duration: 2524 seconds
[12:27:14.461] INFO: ######################################################################
[12:27:14.461] INFO: PixTestTrim::doTest()
[12:27:14.461] INFO: ######################################################################
[12:27:14.463] INFO: ----------------------------------------------------------------------
[12:27:14.463] INFO: PixTestTrim::trimTest() ntrig = 10, vcal = 35
[12:27:14.463] INFO: ----------------------------------------------------------------------
[12:27:14.614] INFO: ---> VthrComp thr map (minimal VthrComp)
[12:27:14.614] INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 5 dacrange: 0 .. 159 (20/-1) hits flags = 16 (plus default)
[12:27:14.630] INFO: dacScan step from 0 .. 19
[12:27:14.630] INFO: dacScan split into 1 runs with ntrig = 5
[12:27:14.630] INFO: run 1 of 1
[12:27:28.897] INFO: Test took 14267ms.
[12:27:28.939] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:28.939] INFO: dacScan step from 20 .. 39
[12:27:28.939] INFO: dacScan split into 1 runs with ntrig = 5
[12:27:28.939] INFO: run 1 of 1
[12:27:43.139] INFO: Test took 14200ms.
[12:27:43.174] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:43.174] INFO: dacScan step from 40 .. 59
[12:27:43.174] INFO: dacScan split into 1 runs with ntrig = 5
[12:27:43.174] INFO: run 1 of 1
[12:27:57.482] INFO: Test took 14308ms.
[12:27:57.523] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:57.523] INFO: dacScan step from 60 .. 79
[12:27:57.523] INFO: dacScan split into 1 runs with ntrig = 5
[12:27:57.523] INFO: run 1 of 1
[12:28:11.814] INFO: Test took 14291ms.
[12:28:11.858] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:11.858] INFO: dacScan step from 80 .. 99
[12:28:11.858] INFO: dacScan split into 1 runs with ntrig = 5
[12:28:11.858] INFO: run 1 of 1
[12:28:26.196] INFO: Test took 14338ms.
[12:28:26.273] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:26.280] INFO: dacScan step from 100 .. 119
[12:28:26.280] INFO: dacScan split into 1 runs with ntrig = 5
[12:28:26.280] INFO: run 1 of 1
[12:28:43.267] INFO: Test took 16987ms.
[12:28:43.504] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:43.559] INFO: dacScan step from 120 .. 139
[12:28:43.559] INFO: dacScan split into 1 runs with ntrig = 5
[12:28:43.559] INFO: run 1 of 1
[12:29:01.273] INFO: Test took 17714ms.
[12:29:01.528] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:01.596] INFO: dacScan step from 140 .. 159
[12:29:01.596] INFO: dacScan split into 1 runs with ntrig = 5
[12:29:01.596] INFO: run 1 of 1
[12:29:16.867] INFO: Test took 15271ms.
[12:29:17.005] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:53.743] INFO: ROC 0 VthrComp = 98
[12:29:53.743] INFO: ROC 1 VthrComp = 82
[12:29:53.743] INFO: ROC 2 VthrComp = 106
[12:29:53.744] INFO: ROC 3 VthrComp = 96
[12:29:53.744] INFO: ROC 4 VthrComp = 94
[12:29:53.744] INFO: ROC 5 VthrComp = 87
[12:29:53.744] INFO: ROC 6 VthrComp = 92
[12:29:53.744] INFO: ROC 7 VthrComp = 106
[12:29:53.744] INFO: ROC 8 VthrComp = 97
[12:29:53.744] INFO: ROC 9 VthrComp = 92
[12:29:53.744] INFO: ROC 10 VthrComp = 87
[12:29:53.745] INFO: ROC 11 VthrComp = 89
[12:29:53.745] INFO: ROC 12 VthrComp = 98
[12:29:53.745] INFO: ROC 13 VthrComp = 107
[12:29:53.745] INFO: ROC 14 VthrComp = 96
[12:29:53.745] INFO: ROC 15 VthrComp = 96
[12:29:53.745] INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[12:29:53.745] INFO: ---> dac: vcal name: TrimThr1 ntrig: 5 dacrange: 0 .. 159 (20/-1) hits flags = 16 (plus default)
[12:29:53.760] INFO: dacScan step from 0 .. 19
[12:29:53.760] INFO: dacScan split into 1 runs with ntrig = 5
[12:29:53.760] INFO: run 1 of 1
[12:30:08.080] INFO: Test took 14320ms.
[12:30:08.123] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:30:08.123] INFO: dacScan step from 20 .. 39
[12:30:08.123] INFO: dacScan split into 1 runs with ntrig = 5
[12:30:08.123] INFO: run 1 of 1
[12:30:22.345] INFO: Test took 14221ms.
[12:30:22.400] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:30:22.408] INFO: dacScan step from 40 .. 59
[12:30:22.408] INFO: dacScan split into 1 runs with ntrig = 5
[12:30:22.408] INFO: run 1 of 1
[12:30:39.701] INFO: Test took 17293ms.
[12:30:39.959] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:30:40.030] INFO: dacScan step from 60 .. 79
[12:30:40.030] INFO: dacScan split into 1 runs with ntrig = 5
[12:30:40.030] INFO: run 1 of 1
[12:30:59.370] INFO: Test took 19340ms.
[12:30:59.674] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:30:59.755] INFO: dacScan step from 80 .. 99
[12:30:59.755] INFO: dacScan split into 1 runs with ntrig = 5
[12:30:59.755] INFO: run 1 of 1
[12:31:19.108] INFO: Test took 19353ms.
[12:31:19.409] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:31:19.483] INFO: dacScan step from 100 .. 119
[12:31:19.483] INFO: dacScan split into 1 runs with ntrig = 5
[12:31:19.483] INFO: run 1 of 1
[12:31:38.901] INFO: Test took 19418ms.
[12:31:39.168] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:31:39.235] INFO: dacScan step from 120 .. 139
[12:31:39.235] INFO: dacScan split into 1 runs with ntrig = 5
[12:31:39.235] INFO: run 1 of 1
[12:31:58.607] INFO: Test took 19372ms.
[12:31:58.922] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:31:59.010] INFO: dacScan step from 140 .. 159
[12:31:59.010] INFO: dacScan split into 1 runs with ntrig = 5
[12:31:59.010] INFO: run 1 of 1
[12:32:18.540] INFO: Test took 19530ms.
[12:32:18.876] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:33:03.248] INFO: roc 0 with ID = 0 has maximal Vcal 58.2413 for pixel 51/32 mean/min/max = 44.9001/31.4385/58.3617
[12:33:03.249] INFO: roc 1 with ID = 1 has maximal Vcal 64.8682 for pixel 24/6 mean/min/max = 48.3926/31.6616/65.1237
[12:33:03.249] INFO: roc 2 with ID = 2 has maximal Vcal 64.9041 for pixel 22/5 mean/min/max = 49.3185/33.7009/64.936
[12:33:03.249] INFO: roc 3 with ID = 3 has maximal Vcal 57.994 for pixel 0/78 mean/min/max = 44.7308/31.4198/58.0417
[12:33:03.250] INFO: roc 4 with ID = 4 has maximal Vcal 61.9971 for pixel 8/1 mean/min/max = 46.5478/30.9729/62.1227
[12:33:03.250] INFO: roc 5 with ID = 5 has maximal Vcal 63.1985 for pixel 27/0 mean/min/max = 47.4047/31.4176/63.3917
[12:33:03.251] INFO: roc 6 with ID = 6 has maximal Vcal 60.2997 for pixel 17/71 mean/min/max = 46.1468/31.8715/60.4221
[12:33:03.251] INFO: roc 7 with ID = 7 has maximal Vcal 65.6873 for pixel 3/70 mean/min/max = 49.6163/33.1879/66.0448
[12:33:03.252] INFO: roc 8 with ID = 8 has maximal Vcal 63.8 for pixel 23/9 mean/min/max = 47.1576/30.4871/63.8281
[12:33:03.252] INFO: roc 9 with ID = 9 has maximal Vcal 58.4227 for pixel 18/16 mean/min/max = 45.3657/32.1943/58.5371
[12:33:03.253] INFO: roc 10 with ID = 10 has maximal Vcal 58.6751 for pixel 5/1 mean/min/max = 45.532/32.216/58.848
[12:33:03.253] INFO: roc 11 with ID = 11 has maximal Vcal 60.2775 for pixel 0/77 mean/min/max = 46.0387/31.7956/60.2818
[12:33:03.254] INFO: roc 12 with ID = 12 has maximal Vcal 63.0734 for pixel 33/23 mean/min/max = 47.2482/31.163/63.3334
[12:33:03.254] INFO: roc 13 with ID = 13 has maximal Vcal 63.0863 for pixel 4/30 mean/min/max = 48.539/33.8516/63.2264
[12:33:03.255] INFO: roc 14 with ID = 14 has maximal Vcal 60.1865 for pixel 0/21 mean/min/max = 46.0181/31.7105/60.3258
[12:33:03.255] INFO: roc 15 with ID = 15 has maximal Vcal 60.0994 for pixel 35/73 mean/min/max = 45.7981/31.4707/60.1256
[12:33:03.256] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:34:25.062] INFO: Test took 81806ms.
[12:34:27.125] INFO: ---> dac: vcal name: TrimThr2 ntrig: 10 dacrange: 0 .. 199 (20/5) hits flags = 16 (plus default)
[12:34:27.142] INFO: dacScan step from 0 .. 19
[12:34:27.142] INFO: dacScan split into 2 runs with ntrig = 5
[12:34:27.142] INFO: run 1 of 2
[12:34:41.419] INFO: Test took 14277ms.
[12:34:41.477] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:34:41.480] INFO: run 2 of 2
[12:34:55.741] INFO: Test took 14261ms.
[12:34:55.795] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:34:55.798] INFO: dacScan step from 20 .. 39
[12:34:55.798] INFO: dacScan split into 2 runs with ntrig = 5
[12:34:55.798] INFO: run 1 of 2
[12:35:12.653] INFO: Test took 16855ms.
[12:35:12.895] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:35:12.950] INFO: run 2 of 2
[12:35:29.742] INFO: Test took 16791ms.
[12:35:29.953] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:35:30.005] INFO: dacScan step from 40 .. 59
[12:35:30.005] INFO: dacScan split into 2 runs with ntrig = 5
[12:35:30.005] INFO: run 1 of 2
[12:35:49.352] INFO: Test took 19347ms.
[12:35:49.634] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:35:49.705] INFO: run 2 of 2
[12:36:09.114] INFO: Test took 19409ms.
[12:36:09.417] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:36:09.493] INFO: dacScan step from 60 .. 79
[12:36:09.493] INFO: dacScan split into 2 runs with ntrig = 5
[12:36:09.493] INFO: run 1 of 2
[12:36:28.918] INFO: Test took 19425ms.
[12:36:29.222] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:36:29.297] INFO: run 2 of 2
[12:36:48.829] INFO: Test took 19532ms.
[12:36:49.148] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:36:49.234] INFO: dacScan step from 80 .. 99
[12:36:49.234] INFO: dacScan split into 2 runs with ntrig = 5
[12:36:49.234] INFO: run 1 of 2
[12:37:08.671] INFO: Test took 19437ms.
[12:37:08.969] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:37:09.049] INFO: run 2 of 2
[12:37:28.367] INFO: Test took 19317ms.
[12:37:28.663] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:37:28.737] INFO: dacScan step from 100 .. 119
[12:37:28.737] INFO: dacScan split into 2 runs with ntrig = 5
[12:37:28.737] INFO: run 1 of 2
[12:37:48.130] INFO: Test took 19393ms.
[12:37:48.477] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:37:48.559] INFO: run 2 of 2
[12:38:07.957] INFO: Test took 19398ms.
[12:38:08.262] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:38:08.334] INFO: dacScan step from 120 .. 139
[12:38:08.334] INFO: dacScan split into 2 runs with ntrig = 5
[12:38:08.334] INFO: run 1 of 2
[12:38:27.705] INFO: Test took 19371ms.
[12:38:28.031] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:38:28.110] INFO: run 2 of 2
[12:38:47.637] INFO: Test took 19527ms.
[12:38:47.925] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:38:47.997] INFO: dacScan step from 140 .. 159
[12:38:47.997] INFO: dacScan split into 2 runs with ntrig = 5
[12:38:47.997] INFO: run 1 of 2
[12:39:07.474] INFO: Test took 19477ms.
[12:39:07.793] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:39:07.876] INFO: run 2 of 2
[12:39:27.325] INFO: Test took 19449ms.
[12:39:27.620] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:39:27.691] INFO: dacScan step from 160 .. 179
[12:39:27.691] INFO: dacScan split into 2 runs with ntrig = 5
[12:39:27.691] INFO: run 1 of 2
[12:39:47.303] INFO: Test took 19611ms.
[12:39:47.621] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:39:47.699] INFO: run 2 of 2
[12:40:07.372] INFO: Test took 19673ms.
[12:40:07.663] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:40:07.751] INFO: dacScan step from 180 .. 199
[12:40:07.751] INFO: dacScan split into 2 runs with ntrig = 5
[12:40:07.751] INFO: run 1 of 2
[12:40:28.069] INFO: Test took 20318ms.
[12:40:28.405] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:40:28.495] INFO: run 2 of 2
[12:40:48.625] INFO: Test took 20130ms.
[12:40:48.965] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:41:32.880] INFO: ---> TrimStepCorr4 extremal thresholds: 0.002173 .. 255.000000
[12:41:33.023] INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 4 dacrange: 0 .. 255 (20/-1) hits flags = 16 (plus default)
[12:41:33.040] INFO: dacScan step from 0 .. 19
[12:41:33.040] INFO: dacScan split into 1 runs with ntrig = 4
[12:41:33.040] INFO: run 1 of 1
[12:41:45.941] INFO: Test took 12901ms.
[12:41:45.978] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:41:45.978] INFO: dacScan step from 20 .. 39
[12:41:45.978] INFO: dacScan split into 1 runs with ntrig = 4
[12:41:45.978] INFO: run 1 of 1
[12:41:59.884] INFO: Test took 13907ms.
[12:42:00.018] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:42:00.051] INFO: dacScan step from 40 .. 59
[12:42:00.051] INFO: dacScan split into 1 runs with ntrig = 4
[12:42:00.051] INFO: run 1 of 1
[12:42:17.025] INFO: Test took 16974ms.
[12:42:17.270] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:42:17.344] INFO: dacScan step from 60 .. 79
[12:42:17.344] INFO: dacScan split into 1 runs with ntrig = 4
[12:42:17.344] INFO: run 1 of 1
[12:42:34.606] INFO: Test took 17261ms.
[12:42:34.848] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:42:34.918] INFO: dacScan step from 80 .. 99
[12:42:34.919] INFO: dacScan split into 1 runs with ntrig = 4
[12:42:34.919] INFO: run 1 of 1
[12:42:52.074] INFO: Test took 17155ms.
[12:42:52.321] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:42:52.397] INFO: dacScan step from 100 .. 119
[12:42:52.397] INFO: dacScan split into 1 runs with ntrig = 4
[12:42:52.397] INFO: run 1 of 1
[12:43:09.677] INFO: Test took 17280ms.
[12:43:09.949] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:43:10.016] INFO: dacScan step from 120 .. 139
[12:43:10.016] INFO: dacScan split into 1 runs with ntrig = 4
[12:43:10.016] INFO: run 1 of 1
[12:43:27.345] INFO: Test took 17329ms.
[12:43:27.606] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:43:27.677] INFO: dacScan step from 140 .. 159
[12:43:27.677] INFO: dacScan split into 1 runs with ntrig = 4
[12:43:27.677] INFO: run 1 of 1
[12:43:44.976] INFO: Test took 17299ms.
[12:43:45.238] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:43:45.311] INFO: dacScan step from 160 .. 179
[12:43:45.311] INFO: dacScan split into 1 runs with ntrig = 4
[12:43:45.311] INFO: run 1 of 1
[12:44:02.733] INFO: Test took 17422ms.
[12:44:02.999] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:03.077] INFO: dacScan step from 180 .. 199
[12:44:03.077] INFO: dacScan split into 1 runs with ntrig = 4
[12:44:03.077] INFO: run 1 of 1
[12:44:21.384] INFO: Test took 18307ms.
[12:44:21.639] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:21.710] INFO: dacScan step from 200 .. 219
[12:44:21.710] INFO: dacScan split into 1 runs with ntrig = 4
[12:44:21.710] INFO: run 1 of 1
[12:44:38.905] INFO: Test took 17195ms.
[12:44:39.182] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:39.263] INFO: dacScan step from 220 .. 239
[12:44:39.263] INFO: dacScan split into 1 runs with ntrig = 4
[12:44:39.263] INFO: run 1 of 1
[12:44:56.381] INFO: Test took 17118ms.
[12:44:56.672] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:56.760] INFO: dacScan step from 240 .. 255
[12:44:56.760] INFO: dacScan split into 1 runs with ntrig = 4
[12:44:56.760] INFO: run 1 of 1
[12:45:10.753] INFO: Test took 13993ms.
[12:45:10.985] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:04.254] INFO: ---> TrimStepCorr2 extremal thresholds: 0.222552 .. 114.589940
[12:46:04.404] INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 4 dacrange: 0 .. 124 (20/-1) hits flags = 16 (plus default)
[12:46:04.417] INFO: dacScan step from 0 .. 19
[12:46:04.417] INFO: dacScan split into 1 runs with ntrig = 4
[12:46:04.417] INFO: run 1 of 1
[12:46:17.351] INFO: Test took 12934ms.
[12:46:17.391] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:17.391] INFO: dacScan step from 20 .. 39
[12:46:17.391] INFO: dacScan split into 1 runs with ntrig = 4
[12:46:17.391] INFO: run 1 of 1
[12:46:31.205] INFO: Test took 13814ms.
[12:46:31.334] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:31.367] INFO: dacScan step from 40 .. 59
[12:46:31.367] INFO: dacScan split into 1 runs with ntrig = 4
[12:46:31.367] INFO: run 1 of 1
[12:46:48.462] INFO: Test took 17095ms.
[12:46:48.754] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:48.845] INFO: dacScan step from 60 .. 79
[12:46:48.845] INFO: dacScan split into 1 runs with ntrig = 4
[12:46:48.845] INFO: run 1 of 1
[12:47:06.046] INFO: Test took 17201ms.
[12:47:06.329] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:47:06.410] INFO: dacScan step from 80 .. 99
[12:47:06.410] INFO: dacScan split into 1 runs with ntrig = 4
[12:47:06.410] INFO: run 1 of 1
[12:47:23.881] INFO: Test took 17471ms.
[12:47:24.169] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:47:24.250] INFO: dacScan step from 100 .. 119
[12:47:24.250] INFO: dacScan split into 1 runs with ntrig = 4
[12:47:24.250] INFO: run 1 of 1
[12:47:41.429] INFO: Test took 17179ms.
[12:47:41.710] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:47:41.791] INFO: dacScan step from 120 .. 124
[12:47:41.791] INFO: dacScan split into 1 runs with ntrig = 4
[12:47:41.791] INFO: run 1 of 1
[12:47:48.529] INFO: Test took 6738ms.
[12:47:48.599] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:48:27.883] INFO: ---> TrimStepCorr1a extremal thresholds: 1.500000 .. 89.068912
[12:48:28.025] INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 4 dacrange: 1 .. 99 (20/-1) hits flags = 16 (plus default)
[12:48:28.040] INFO: dacScan step from 1 .. 20
[12:48:28.040] INFO: dacScan split into 1 runs with ntrig = 4
[12:48:28.040] INFO: run 1 of 1
[12:48:40.928] INFO: Test took 12888ms.
[12:48:40.966] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:48:40.966] INFO: dacScan step from 21 .. 40
[12:48:40.966] INFO: dacScan split into 1 runs with ntrig = 4
[12:48:40.966] INFO: run 1 of 1
[12:48:55.066] INFO: Test took 14099ms.
[12:48:55.204] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:48:55.242] INFO: dacScan step from 41 .. 60
[12:48:55.242] INFO: dacScan split into 1 runs with ntrig = 4
[12:48:55.242] INFO: run 1 of 1
[12:49:12.613] INFO: Test took 17371ms.
[12:49:12.879] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:49:12.948] INFO: dacScan step from 61 .. 80
[12:49:12.948] INFO: dacScan split into 1 runs with ntrig = 4
[12:49:12.948] INFO: run 1 of 1
[12:49:30.170] INFO: Test took 17222ms.
[12:49:30.431] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:49:30.505] INFO: dacScan step from 81 .. 99
[12:49:30.505] INFO: dacScan split into 1 runs with ntrig = 4
[12:49:30.505] INFO: run 1 of 1
[12:49:46.976] INFO: Test took 16471ms.
[12:49:47.245] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:50:25.470] INFO: ---> TrimStepCorr1b extremal thresholds: 1.500000 .. 71.044895
[12:50:25.609] INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 4 dacrange: 1 .. 81 (20/-1) hits flags = 16 (plus default)
[12:50:25.623] INFO: dacScan step from 1 .. 20
[12:50:25.623] INFO: dacScan split into 1 runs with ntrig = 4
[12:50:25.623] INFO: run 1 of 1
[12:50:38.448] INFO: Test took 12825ms.
[12:50:38.492] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:50:38.492] INFO: dacScan step from 21 .. 40
[12:50:38.492] INFO: dacScan split into 1 runs with ntrig = 4
[12:50:38.492] INFO: run 1 of 1
[12:50:52.538] INFO: Test took 14045ms.
[12:50:52.663] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:50:52.699] INFO: dacScan step from 41 .. 60
[12:50:52.699] INFO: dacScan split into 1 runs with ntrig = 4
[12:50:52.699] INFO: run 1 of 1
[12:51:09.850] INFO: Test took 17152ms.
[12:51:10.110] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:51:10.180] INFO: dacScan step from 61 .. 80
[12:51:10.181] INFO: dacScan split into 1 runs with ntrig = 4
[12:51:10.181] INFO: run 1 of 1
[12:51:27.552] INFO: Test took 17371ms.
[12:51:27.828] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:51:27.898] INFO: dacScan step from 81 .. 81
[12:51:27.899] INFO: dacScan split into 1 runs with ntrig = 4
[12:51:27.899] INFO: run 1 of 1
[12:51:31.745] INFO: Test took 3846ms.
[12:51:31.762] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:52:01.230] INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[12:52:01.230] INFO: ---> dac: vcal name: TrimThrFinal ntrig: 10 dacrange: 15 .. 55 (20/5) hits flags = 16 (plus default)
[12:52:01.246] INFO: dacScan step from 15 .. 34
[12:52:01.246] INFO: dacScan split into 2 runs with ntrig = 5
[12:52:01.246] INFO: run 1 of 2
[12:52:15.559] INFO: Test took 14313ms.
[12:52:15.633] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:52:15.647] INFO: run 2 of 2
[12:52:29.946] INFO: Test took 14299ms.
[12:52:30.015] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:52:30.031] INFO: dacScan step from 35 .. 54
[12:52:30.031] INFO: dacScan split into 2 runs with ntrig = 5
[12:52:30.031] INFO: run 1 of 2
[12:52:49.162] INFO: Test took 19131ms.
[12:52:49.471] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:52:49.551] INFO: run 2 of 2
[12:53:08.870] INFO: Test took 19319ms.
[12:53:09.171] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:53:09.250] INFO: dacScan step from 55 .. 55
[12:53:09.250] INFO: dacScan split into 2 runs with ntrig = 5
[12:53:09.250] INFO: run 1 of 2
[12:53:13.198] INFO: Test took 3948ms.
[12:53:13.218] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:53:13.226] INFO: run 2 of 2
[12:53:17.180] INFO: Test took 3954ms.
[12:53:17.203] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:53:36.942] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/dacParameters35_C0.dat
[12:53:36.942] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/dacParameters35_C1.dat
[12:53:36.942] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/dacParameters35_C2.dat
[12:53:36.943] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/dacParameters35_C3.dat
[12:53:36.943] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/dacParameters35_C4.dat
[12:53:36.943] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/dacParameters35_C5.dat
[12:53:36.943] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/dacParameters35_C6.dat
[12:53:36.944] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/dacParameters35_C7.dat
[12:53:36.944] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/dacParameters35_C8.dat
[12:53:36.944] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/dacParameters35_C9.dat
[12:53:36.944] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/dacParameters35_C10.dat
[12:53:36.944] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/dacParameters35_C11.dat
[12:53:36.945] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/dacParameters35_C12.dat
[12:53:36.945] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/dacParameters35_C13.dat
[12:53:36.945] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/dacParameters35_C14.dat
[12:53:36.945] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/dacParameters35_C15.dat
[12:53:36.945] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/trimParameters35_C0.dat
[12:53:36.960] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/trimParameters35_C1.dat
[12:53:36.971] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/trimParameters35_C2.dat
[12:53:36.983] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/trimParameters35_C3.dat
[12:53:36.994] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/trimParameters35_C4.dat
[12:53:37.007] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/trimParameters35_C5.dat
[12:53:37.019] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/trimParameters35_C6.dat
[12:53:37.030] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/trimParameters35_C7.dat
[12:53:37.041] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/trimParameters35_C8.dat
[12:53:37.053] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/trimParameters35_C9.dat
[12:53:37.064] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/trimParameters35_C10.dat
[12:53:37.076] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/trimParameters35_C11.dat
[12:53:37.087] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/trimParameters35_C12.dat
[12:53:37.098] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/trimParameters35_C13.dat
[12:53:37.110] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/trimParameters35_C14.dat
[12:53:37.121] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/trimParameters35_C15.dat
[12:53:37.133] INFO: PixTestTrim::trimTest() done
[12:53:37.133] INFO: vtrim: 101 109 114 93 106 113 104 138 107 116 97 107 109 135 111 104
[12:53:37.133] INFO: vthrcomp: 98 82 106 96 94 87 92 106 97 92 87 89 98 107 96 96
[12:53:37.133] INFO: vcal mean: 35.05 35.11 35.12 35.05 35.08 35.08 35.07 35.04 35.00 35.02 35.02 35.07 35.07 35.05 35.06 35.05
[12:53:37.133] INFO: vcal RMS: 1.05 1.19 1.21 1.27 1.13 1.22 1.14 1.23 1.42 1.34 1.08 1.02 1.62 1.08 1.10 1.08
[12:53:37.133] INFO: bits mean: 9.75 9.72 9.20 10.08 9.90 10.02 9.84 9.04 9.90 10.15 9.72 9.65 9.86 9.30 9.83 9.90
[12:53:37.133] INFO: bits RMS: 2.69 2.43 2.35 2.53 2.52 2.39 2.48 2.46 2.56 2.30 2.57 2.61 2.51 2.29 2.60 2.52
[12:53:37.144] INFO: ----------------------------------------------------------------------
[12:53:37.144] INFO: PixTestTrim::trimBitTest() ntrig = 10, vtrims = 254 126 63 32
[12:53:37.144] INFO: ----------------------------------------------------------------------
[12:53:37.148] INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 10 dacrange: 0 .. 199 (20/5) hits flags = 16 (plus default)
[12:53:37.164] INFO: dacScan step from 0 .. 19
[12:53:37.164] INFO: dacScan split into 2 runs with ntrig = 5
[12:53:37.164] INFO: run 1 of 2
[12:53:51.309] INFO: Test took 14144ms.
[12:53:51.354] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:53:51.354] INFO: run 2 of 2
[12:54:05.598] INFO: Test took 14244ms.
[12:54:05.643] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:54:05.643] INFO: dacScan step from 20 .. 39
[12:54:05.643] INFO: dacScan split into 2 runs with ntrig = 5
[12:54:05.643] INFO: run 1 of 2
[12:54:19.880] INFO: Test took 14237ms.
[12:54:19.924] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:54:19.924] INFO: run 2 of 2
[12:54:34.054] INFO: Test took 14130ms.
[12:54:34.097] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:54:34.097] INFO: dacScan step from 40 .. 59
[12:54:34.097] INFO: dacScan split into 2 runs with ntrig = 5
[12:54:34.097] INFO: run 1 of 2
[12:54:48.190] INFO: Test took 14093ms.
[12:54:48.227] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:54:48.227] INFO: run 2 of 2
[12:55:02.387] INFO: Test took 14160ms.
[12:55:02.423] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:55:02.423] INFO: dacScan step from 60 .. 79
[12:55:02.423] INFO: dacScan split into 2 runs with ntrig = 5
[12:55:02.423] INFO: run 1 of 2
[12:55:16.547] INFO: Test took 14124ms.
[12:55:16.587] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:55:16.587] INFO: run 2 of 2
[12:55:30.722] INFO: Test took 14135ms.
[12:55:30.767] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:55:30.767] INFO: dacScan step from 80 .. 99
[12:55:30.767] INFO: dacScan split into 2 runs with ntrig = 5
[12:55:30.767] INFO: run 1 of 2
[12:55:44.924] INFO: Test took 14157ms.
[12:55:44.973] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:55:44.974] INFO: run 2 of 2
[12:55:59.172] INFO: Test took 14198ms.
[12:55:59.222] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:55:59.222] INFO: dacScan step from 100 .. 119
[12:55:59.222] INFO: dacScan split into 2 runs with ntrig = 5
[12:55:59.222] INFO: run 1 of 2
[12:56:14.188] INFO: Test took 14966ms.
[12:56:14.323] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:56:14.345] INFO: run 2 of 2
[12:56:29.450] INFO: Test took 15105ms.
[12:56:29.585] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:56:29.605] INFO: dacScan step from 120 .. 139
[12:56:29.605] INFO: dacScan split into 2 runs with ntrig = 5
[12:56:29.605] INFO: run 1 of 2
[12:56:47.562] INFO: Test took 17957ms.
[12:56:47.843] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:56:47.908] INFO: run 2 of 2
[12:57:05.886] INFO: Test took 17978ms.
[12:57:06.141] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:57:06.204] INFO: dacScan step from 140 .. 159
[12:57:06.204] INFO: dacScan split into 2 runs with ntrig = 5
[12:57:06.204] INFO: run 1 of 2
[12:57:25.696] INFO: Test took 19492ms.
[12:57:26.016] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:57:26.092] INFO: run 2 of 2
[12:57:45.547] INFO: Test took 19455ms.
[12:57:45.849] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:57:45.929] INFO: dacScan step from 160 .. 179
[12:57:45.929] INFO: dacScan split into 2 runs with ntrig = 5
[12:57:45.929] INFO: run 1 of 2
[12:58:05.780] INFO: Test took 19851ms.
[12:58:06.082] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:58:06.158] INFO: run 2 of 2
[12:58:25.916] INFO: Test took 19758ms.
[12:58:26.209] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:58:26.278] INFO: dacScan step from 180 .. 199
[12:58:26.278] INFO: dacScan split into 2 runs with ntrig = 5
[12:58:26.278] INFO: run 1 of 2
[12:58:46.740] INFO: Test took 20462ms.
[12:58:47.054] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:58:47.123] INFO: run 2 of 2
[12:59:07.452] INFO: Test took 20328ms.
[12:59:07.754] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:59:48.892] INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 10 dacrange: 0 .. 205 (20/5) hits flags = 16 (plus default)
[12:59:48.905] INFO: dacScan step from 0 .. 19
[12:59:48.905] INFO: dacScan split into 2 runs with ntrig = 5
[12:59:48.905] INFO: run 1 of 2
[13:00:03.035] INFO: Test took 14130ms.
[13:00:03.076] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:00:03.076] INFO: run 2 of 2
[13:00:17.247] INFO: Test took 14170ms.
[13:00:17.288] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:00:17.288] INFO: dacScan step from 20 .. 39
[13:00:17.288] INFO: dacScan split into 2 runs with ntrig = 5
[13:00:17.288] INFO: run 1 of 2
[13:00:31.527] INFO: Test took 14239ms.
[13:00:31.570] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:00:31.570] INFO: run 2 of 2
[13:00:45.660] INFO: Test took 14090ms.
[13:00:45.703] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:00:45.703] INFO: dacScan step from 40 .. 59
[13:00:45.703] INFO: dacScan split into 2 runs with ntrig = 5
[13:00:45.703] INFO: run 1 of 2
[13:00:59.818] INFO: Test took 14114ms.
[13:00:59.864] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:00:59.864] INFO: run 2 of 2
[13:01:14.140] INFO: Test took 14276ms.
[13:01:14.186] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:01:14.186] INFO: dacScan step from 60 .. 79
[13:01:14.186] INFO: dacScan split into 2 runs with ntrig = 5
[13:01:14.186] INFO: run 1 of 2
[13:01:28.313] INFO: Test took 14127ms.
[13:01:28.354] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:01:28.354] INFO: run 2 of 2
[13:01:42.462] INFO: Test took 14108ms.
[13:01:42.509] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:01:42.509] INFO: dacScan step from 80 .. 99
[13:01:42.509] INFO: dacScan split into 2 runs with ntrig = 5
[13:01:42.509] INFO: run 1 of 2
[13:01:56.795] INFO: Test took 14286ms.
[13:01:56.861] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:01:56.865] INFO: run 2 of 2
[13:02:11.135] INFO: Test took 14270ms.
[13:02:11.199] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:02:11.203] INFO: dacScan step from 100 .. 119
[13:02:11.203] INFO: dacScan split into 2 runs with ntrig = 5
[13:02:11.203] INFO: run 1 of 2
[13:02:27.821] INFO: Test took 16617ms.
[13:02:28.042] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:02:28.087] INFO: run 2 of 2
[13:02:44.819] INFO: Test took 16732ms.
[13:02:45.018] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:02:45.060] INFO: dacScan step from 120 .. 139
[13:02:45.060] INFO: dacScan split into 2 runs with ntrig = 5
[13:02:45.060] INFO: run 1 of 2
[13:03:04.083] INFO: Test took 19023ms.
[13:03:04.399] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:03:04.474] INFO: run 2 of 2
[13:03:23.493] INFO: Test took 19018ms.
[13:03:23.800] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:03:23.873] INFO: dacScan step from 140 .. 159
[13:03:23.873] INFO: dacScan split into 2 runs with ntrig = 5
[13:03:23.873] INFO: run 1 of 2
[13:03:43.294] INFO: Test took 19421ms.
[13:03:43.606] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:03:43.684] INFO: run 2 of 2
[13:04:03.065] INFO: Test took 19381ms.
[13:04:03.400] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:04:03.488] INFO: dacScan step from 160 .. 179
[13:04:03.488] INFO: dacScan split into 2 runs with ntrig = 5
[13:04:03.488] INFO: run 1 of 2
[13:04:23.130] INFO: Test took 19642ms.
[13:04:23.427] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:04:23.502] INFO: run 2 of 2
[13:04:43.205] INFO: Test took 19703ms.
[13:04:43.518] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:04:43.595] INFO: dacScan step from 180 .. 199
[13:04:43.595] INFO: dacScan split into 2 runs with ntrig = 5
[13:04:43.595] INFO: run 1 of 2
[13:05:03.983] INFO: Test took 20388ms.
[13:05:04.301] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:05:04.381] INFO: run 2 of 2
[13:05:24.815] INFO: Test took 20433ms.
[13:05:25.133] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:05:25.216] INFO: dacScan step from 200 .. 205
[13:05:25.216] INFO: dacScan split into 2 runs with ntrig = 5
[13:05:25.216] INFO: run 1 of 2
[13:05:33.316] INFO: Test took 8100ms.
[13:05:33.411] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:05:33.439] INFO: run 2 of 2
[13:05:41.588] INFO: Test took 8149ms.
[13:05:41.686] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:06:25.377] INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 10 dacrange: 0 .. 196 (20/5) hits flags = 16 (plus default)
[13:06:25.394] INFO: dacScan step from 0 .. 19
[13:06:25.394] INFO: dacScan split into 2 runs with ntrig = 5
[13:06:25.394] INFO: run 1 of 2
[13:06:39.537] INFO: Test took 14142ms.
[13:06:39.585] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:06:39.585] INFO: run 2 of 2
[13:06:53.748] INFO: Test took 14163ms.
[13:06:53.795] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:06:53.795] INFO: dacScan step from 20 .. 39
[13:06:53.795] INFO: dacScan split into 2 runs with ntrig = 5
[13:06:53.795] INFO: run 1 of 2
[13:07:08.096] INFO: Test took 14301ms.
[13:07:08.145] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:07:08.145] INFO: run 2 of 2
[13:07:22.463] INFO: Test took 14318ms.
[13:07:22.510] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:07:22.510] INFO: dacScan step from 40 .. 59
[13:07:22.510] INFO: dacScan split into 2 runs with ntrig = 5
[13:07:22.511] INFO: run 1 of 2
[13:07:36.731] INFO: Test took 14220ms.
[13:07:36.773] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:07:36.773] INFO: run 2 of 2
[13:07:51.046] INFO: Test took 14274ms.
[13:07:51.086] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:07:51.087] INFO: dacScan step from 60 .. 79
[13:07:51.087] INFO: dacScan split into 2 runs with ntrig = 5
[13:07:51.087] INFO: run 1 of 2
[13:08:05.371] INFO: Test took 14284ms.
[13:08:05.410] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:08:05.410] INFO: run 2 of 2
[13:08:19.686] INFO: Test took 14275ms.
[13:08:19.725] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:08:19.725] INFO: dacScan step from 80 .. 99
[13:08:19.725] INFO: dacScan split into 2 runs with ntrig = 5
[13:08:19.725] INFO: run 1 of 2
[13:08:34.111] INFO: Test took 14386ms.
[13:08:34.174] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:08:34.179] INFO: run 2 of 2
[13:08:48.623] INFO: Test took 14443ms.
[13:08:48.691] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:08:48.695] INFO: dacScan step from 100 .. 119
[13:08:48.695] INFO: dacScan split into 2 runs with ntrig = 5
[13:08:48.695] INFO: run 1 of 2
[13:09:05.392] INFO: Test took 16697ms.
[13:09:05.601] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:09:05.645] INFO: run 2 of 2
[13:09:22.102] INFO: Test took 16457ms.
[13:09:22.318] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:09:22.364] INFO: dacScan step from 120 .. 139
[13:09:22.364] INFO: dacScan split into 2 runs with ntrig = 5
[13:09:22.364] INFO: run 1 of 2
[13:09:41.315] INFO: Test took 18951ms.
[13:09:41.617] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:09:41.700] INFO: run 2 of 2
[13:10:00.709] INFO: Test took 19009ms.
[13:10:01.021] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:10:01.106] INFO: dacScan step from 140 .. 159
[13:10:01.106] INFO: dacScan split into 2 runs with ntrig = 5
[13:10:01.106] INFO: run 1 of 2
[13:10:20.532] INFO: Test took 19426ms.
[13:10:20.833] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:10:20.908] INFO: run 2 of 2
[13:10:40.399] INFO: Test took 19491ms.
[13:10:40.728] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:10:40.798] INFO: dacScan step from 160 .. 179
[13:10:40.798] INFO: dacScan split into 2 runs with ntrig = 5
[13:10:40.798] INFO: run 1 of 2
[13:11:00.643] INFO: Test took 19844ms.
[13:11:00.969] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:11:01.052] INFO: run 2 of 2
[13:11:20.866] INFO: Test took 19814ms.
[13:11:21.181] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:11:21.256] INFO: dacScan step from 180 .. 196
[13:11:21.256] INFO: dacScan split into 2 runs with ntrig = 5
[13:11:21.256] INFO: run 1 of 2
[13:11:39.329] INFO: Test took 18073ms.
[13:11:39.597] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:11:39.667] INFO: run 2 of 2
[13:11:57.818] INFO: Test took 18151ms.
[13:11:58.102] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:12:39.863] INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 10 dacrange: 0 .. 167 (20/5) hits flags = 16 (plus default)
[13:12:39.878] INFO: dacScan step from 0 .. 19
[13:12:39.879] INFO: dacScan split into 2 runs with ntrig = 5
[13:12:39.879] INFO: run 1 of 2
[13:12:54.180] INFO: Test took 14301ms.
[13:12:54.227] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:12:54.227] INFO: run 2 of 2
[13:13:08.444] INFO: Test took 14217ms.
[13:13:08.488] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:13:08.488] INFO: dacScan step from 20 .. 39
[13:13:08.488] INFO: dacScan split into 2 runs with ntrig = 5
[13:13:08.488] INFO: run 1 of 2
[13:13:22.645] INFO: Test took 14156ms.
[13:13:22.695] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:13:22.695] INFO: run 2 of 2
[13:13:37.005] INFO: Test took 14310ms.
[13:13:37.042] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:13:37.043] INFO: dacScan step from 40 .. 59
[13:13:37.043] INFO: dacScan split into 2 runs with ntrig = 5
[13:13:37.043] INFO: run 1 of 2
[13:13:51.331] INFO: Test took 14288ms.
[13:13:51.369] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:13:51.369] INFO: run 2 of 2
[13:14:05.446] INFO: Test took 14076ms.
[13:14:05.486] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:14:05.486] INFO: dacScan step from 60 .. 79
[13:14:05.486] INFO: dacScan split into 2 runs with ntrig = 5
[13:14:05.486] INFO: run 1 of 2
[13:14:19.656] INFO: Test took 14170ms.
[13:14:19.698] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:14:19.698] INFO: run 2 of 2
[13:14:33.901] INFO: Test took 14203ms.
[13:14:33.946] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:14:33.946] INFO: dacScan step from 80 .. 99
[13:14:33.946] INFO: dacScan split into 2 runs with ntrig = 5
[13:14:33.946] INFO: run 1 of 2
[13:14:48.225] INFO: Test took 14279ms.
[13:14:48.293] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:14:48.299] INFO: run 2 of 2
[13:15:02.633] INFO: Test took 14334ms.
[13:15:02.701] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:15:02.706] INFO: dacScan step from 100 .. 119
[13:15:02.706] INFO: dacScan split into 2 runs with ntrig = 5
[13:15:02.706] INFO: run 1 of 2
[13:15:19.317] INFO: Test took 16611ms.
[13:15:19.545] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:15:19.592] INFO: run 2 of 2
[13:15:36.132] INFO: Test took 16540ms.
[13:15:36.359] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:15:36.405] INFO: dacScan step from 120 .. 139
[13:15:36.405] INFO: dacScan split into 2 runs with ntrig = 5
[13:15:36.405] INFO: run 1 of 2
[13:15:55.510] INFO: Test took 19105ms.
[13:15:55.813] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:15:55.888] INFO: run 2 of 2
[13:16:14.847] INFO: Test took 18959ms.
[13:16:15.170] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:16:15.246] INFO: dacScan step from 140 .. 159
[13:16:15.246] INFO: dacScan split into 2 runs with ntrig = 5
[13:16:15.246] INFO: run 1 of 2
[13:16:34.598] INFO: Test took 19352ms.
[13:16:34.912] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:16:34.985] INFO: run 2 of 2
[13:16:54.263] INFO: Test took 19277ms.
[13:16:54.600] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:16:54.682] INFO: dacScan step from 160 .. 167
[13:16:54.682] INFO: dacScan split into 2 runs with ntrig = 5
[13:16:54.682] INFO: run 1 of 2
[13:17:04.512] INFO: Test took 9830ms.
[13:17:04.646] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:17:04.680] INFO: run 2 of 2
[13:17:14.599] INFO: Test took 9919ms.
[13:17:14.730] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:17:51.214] INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 10 dacrange: 0 .. 166 (20/5) hits flags = 16 (plus default)
[13:17:51.229] INFO: dacScan step from 0 .. 19
[13:17:51.229] INFO: dacScan split into 2 runs with ntrig = 5
[13:17:51.229] INFO: run 1 of 2
[13:18:05.340] INFO: Test took 14111ms.
[13:18:05.390] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:18:05.391] INFO: run 2 of 2
[13:18:19.517] INFO: Test took 14126ms.
[13:18:19.564] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:18:19.564] INFO: dacScan step from 20 .. 39
[13:18:19.564] INFO: dacScan split into 2 runs with ntrig = 5
[13:18:19.564] INFO: run 1 of 2
[13:18:33.840] INFO: Test took 14276ms.
[13:18:33.889] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:18:33.889] INFO: run 2 of 2
[13:18:48.097] INFO: Test took 14208ms.
[13:18:48.143] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:18:48.143] INFO: dacScan step from 40 .. 59
[13:18:48.143] INFO: dacScan split into 2 runs with ntrig = 5
[13:18:48.143] INFO: run 1 of 2
[13:19:02.307] INFO: Test took 14164ms.
[13:19:02.351] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:19:02.351] INFO: run 2 of 2
[13:19:16.458] INFO: Test took 14107ms.
[13:19:16.502] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:19:16.502] INFO: dacScan step from 60 .. 79
[13:19:16.502] INFO: dacScan split into 2 runs with ntrig = 5
[13:19:16.502] INFO: run 1 of 2
[13:19:30.646] INFO: Test took 14143ms.
[13:19:30.688] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:19:30.688] INFO: run 2 of 2
[13:19:44.810] INFO: Test took 14122ms.
[13:19:44.852] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:19:44.852] INFO: dacScan step from 80 .. 99
[13:19:44.852] INFO: dacScan split into 2 runs with ntrig = 5
[13:19:44.852] INFO: run 1 of 2
[13:19:59.114] INFO: Test took 14261ms.
[13:19:59.176] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:19:59.179] INFO: run 2 of 2
[13:20:13.386] INFO: Test took 14207ms.
[13:20:13.445] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:20:13.450] INFO: dacScan step from 100 .. 119
[13:20:13.450] INFO: dacScan split into 2 runs with ntrig = 5
[13:20:13.450] INFO: run 1 of 2
[13:20:30.057] INFO: Test took 16607ms.
[13:20:30.270] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:20:30.316] INFO: run 2 of 2
[13:20:46.812] INFO: Test took 16496ms.
[13:20:47.016] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:20:47.056] INFO: dacScan step from 120 .. 139
[13:20:47.056] INFO: dacScan split into 2 runs with ntrig = 5
[13:20:47.057] INFO: run 1 of 2
[13:21:05.886] INFO: Test took 18829ms.
[13:21:06.193] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:21:06.267] INFO: run 2 of 2
[13:21:25.345] INFO: Test took 19078ms.
[13:21:25.642] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:21:25.715] INFO: dacScan step from 140 .. 159
[13:21:25.715] INFO: dacScan split into 2 runs with ntrig = 5
[13:21:25.715] INFO: run 1 of 2
[13:21:44.979] INFO: Test took 19264ms.
[13:21:45.275] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:21:45.354] INFO: run 2 of 2
[13:22:04.727] INFO: Test took 19373ms.
[13:22:05.030] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:22:05.104] INFO: dacScan step from 160 .. 166
[13:22:05.104] INFO: dacScan split into 2 runs with ntrig = 5
[13:22:05.104] INFO: run 1 of 2
[13:22:14.039] INFO: Test took 8934ms.
[13:22:14.157] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:22:14.187] INFO: run 2 of 2
[13:22:23.104] INFO: Test took 8917ms.
[13:22:23.207] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:22:58.526] INFO: PixTestTrim::trimBitTest() done
[13:22:58.528] INFO: PixTestTrim::doTest() done, duration: 3344 seconds
[13:22:59.505] INFO: ######################################################################
[13:22:59.505] INFO: PixTestPhOptimization::doTest() Ntrig = 10
[13:22:59.505] INFO: ######################################################################
[13:23:03.249] INFO: Test took 3743ms.
[13:23:03.285] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:23:07.180] INFO: Test took 3691ms.
[13:23:07.318] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:23:11.020] INFO: Test took 3683ms.
[13:23:11.165] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:23:14.876] INFO: Test took 3696ms.
[13:23:15.011] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:23:18.742] INFO: Test took 3717ms.
[13:23:18.877] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:23:22.576] INFO: Test took 3685ms.
[13:23:22.712] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:23:26.432] INFO: Test took 3705ms.
[13:23:26.564] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:23:30.307] INFO: Test took 3728ms.
[13:23:30.435] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:23:34.134] INFO: Test took 3684ms.
[13:23:34.269] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:23:38.008] INFO: Test took 3726ms.
[13:23:38.151] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:23:41.923] INFO: Test took 3757ms.
[13:23:42.045] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:23:45.754] INFO: Test took 3694ms.
[13:23:45.908] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:23:49.690] INFO: Test took 3768ms.
[13:23:49.837] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:23:53.520] INFO: Test took 3669ms.
[13:23:53.641] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:23:57.347] INFO: Test took 3692ms.
[13:23:57.490] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:24:01.193] INFO: Test took 3689ms.
[13:24:01.346] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:24:05.098] INFO: Test took 3735ms.
[13:24:05.235] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:24:08.961] INFO: Test took 3712ms.
[13:24:09.110] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:24:12.815] INFO: Test took 3689ms.
[13:24:12.958] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:24:12.971] INFO: The DUT currently contains the following objects:
[13:24:12.971] INFO: 2 TBM Cores tbm08c (2 ON)
[13:24:12.971] INFO: TBM Core alpha (0): 7 registers set
[13:24:12.971] INFO: TBM Core beta (1): 7 registers set
[13:24:12.971] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:24:12.971] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:12.971] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:12.971] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:12.971] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:12.971] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:12.971] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:12.971] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:12.971] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:12.971] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:12.971] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:12.971] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:12.971] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:12.971] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:12.971] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:12.971] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:12.971] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:14.070] INFO: Test took 1099ms.
[13:24:14.071] INFO: The DUT currently contains the following objects:
[13:24:14.071] INFO: 2 TBM Cores tbm08c (2 ON)
[13:24:14.071] INFO: TBM Core alpha (0): 7 registers set
[13:24:14.071] INFO: TBM Core beta (1): 7 registers set
[13:24:14.071] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:24:14.071] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:14.071] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:14.071] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:14.071] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:14.071] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:14.071] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:14.071] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:14.071] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:14.071] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:14.071] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:14.072] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:14.072] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:14.072] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:14.072] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:14.072] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:14.072] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:15.170] INFO: Test took 1098ms.
[13:24:15.173] INFO: The DUT currently contains the following objects:
[13:24:15.173] INFO: 2 TBM Cores tbm08c (2 ON)
[13:24:15.173] INFO: TBM Core alpha (0): 7 registers set
[13:24:15.173] INFO: TBM Core beta (1): 7 registers set
[13:24:15.173] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:24:15.173] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:15.173] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:15.173] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:15.173] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:15.173] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:15.173] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:15.173] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:15.173] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:15.173] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:15.173] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:15.173] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:15.173] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:15.173] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:15.173] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:15.173] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:15.173] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:16.276] INFO: Test took 1103ms.
[13:24:16.278] INFO: The DUT currently contains the following objects:
[13:24:16.278] INFO: 2 TBM Cores tbm08c (2 ON)
[13:24:16.278] INFO: TBM Core alpha (0): 7 registers set
[13:24:16.278] INFO: TBM Core beta (1): 7 registers set
[13:24:16.278] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:24:16.278] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:16.278] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:16.278] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:16.278] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:16.278] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:16.278] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:16.278] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:16.278] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:16.278] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:16.278] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:16.278] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:16.279] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:16.279] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:16.279] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:16.279] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:16.279] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:17.379] INFO: Test took 1100ms.
[13:24:17.381] INFO: The DUT currently contains the following objects:
[13:24:17.381] INFO: 2 TBM Cores tbm08c (2 ON)
[13:24:17.381] INFO: TBM Core alpha (0): 7 registers set
[13:24:17.381] INFO: TBM Core beta (1): 7 registers set
[13:24:17.381] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:24:17.381] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:17.381] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:17.381] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:17.381] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:17.381] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:17.381] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:17.381] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:17.381] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:17.381] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:17.381] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:17.381] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:17.381] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:17.381] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:17.381] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:17.381] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:17.381] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:18.481] INFO: Test took 1100ms.
[13:24:18.483] INFO: The DUT currently contains the following objects:
[13:24:18.483] INFO: 2 TBM Cores tbm08c (2 ON)
[13:24:18.483] INFO: TBM Core alpha (0): 7 registers set
[13:24:18.483] INFO: TBM Core beta (1): 7 registers set
[13:24:18.483] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:24:18.483] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:18.483] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:18.483] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:18.483] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:18.483] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:18.483] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:18.483] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:18.483] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:18.483] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:18.483] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:18.483] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:18.483] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:18.483] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:18.483] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:18.483] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:18.483] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:19.583] INFO: Test took 1100ms.
[13:24:19.585] INFO: The DUT currently contains the following objects:
[13:24:19.585] INFO: 2 TBM Cores tbm08c (2 ON)
[13:24:19.586] INFO: TBM Core alpha (0): 7 registers set
[13:24:19.586] INFO: TBM Core beta (1): 7 registers set
[13:24:19.586] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:24:19.586] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:19.586] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:19.586] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:19.586] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:19.586] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:19.586] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:19.586] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:19.586] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:19.586] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:19.586] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:19.586] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:19.586] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:19.586] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:19.586] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:19.586] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:19.586] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:20.687] INFO: Test took 1101ms.
[13:24:20.689] INFO: The DUT currently contains the following objects:
[13:24:20.689] INFO: 2 TBM Cores tbm08c (2 ON)
[13:24:20.689] INFO: TBM Core alpha (0): 7 registers set
[13:24:20.689] INFO: TBM Core beta (1): 7 registers set
[13:24:20.689] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:24:20.689] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:20.689] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:20.689] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:20.689] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:20.689] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:20.689] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:20.689] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:20.689] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:20.689] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:20.689] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:20.689] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:20.689] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:20.689] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:20.689] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:20.689] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:20.689] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:21.790] INFO: Test took 1101ms.
[13:24:21.792] INFO: The DUT currently contains the following objects:
[13:24:21.792] INFO: 2 TBM Cores tbm08c (2 ON)
[13:24:21.792] INFO: TBM Core alpha (0): 7 registers set
[13:24:21.792] INFO: TBM Core beta (1): 7 registers set
[13:24:21.792] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:24:21.792] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:21.792] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:21.792] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:21.792] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:21.792] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:21.792] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:21.792] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:21.792] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:21.792] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:21.792] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:21.792] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:21.792] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:21.792] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:21.792] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:21.792] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:21.792] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:22.893] INFO: Test took 1101ms.
[13:24:22.895] INFO: The DUT currently contains the following objects:
[13:24:22.895] INFO: 2 TBM Cores tbm08c (2 ON)
[13:24:22.895] INFO: TBM Core alpha (0): 7 registers set
[13:24:22.896] INFO: TBM Core beta (1): 7 registers set
[13:24:22.896] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:24:22.896] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:22.896] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:22.896] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:22.896] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:22.896] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:22.896] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:22.896] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:22.896] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:22.896] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:22.896] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:22.896] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:22.896] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:22.896] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:22.896] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:22.896] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:22.896] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:23.996] INFO: Test took 1100ms.
[13:24:23.998] INFO: The DUT currently contains the following objects:
[13:24:23.998] INFO: 2 TBM Cores tbm08c (2 ON)
[13:24:23.998] INFO: TBM Core alpha (0): 7 registers set
[13:24:23.998] INFO: TBM Core beta (1): 7 registers set
[13:24:23.998] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:24:23.998] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:23.998] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:23.998] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:23.998] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:23.998] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:23.998] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:23.999] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:23.999] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:23.999] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:23.999] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:23.999] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:23.999] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:23.999] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:23.999] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:23.999] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:23.999] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:25.099] INFO: Test took 1100ms.
[13:24:25.102] INFO: The DUT currently contains the following objects:
[13:24:25.102] INFO: 2 TBM Cores tbm08c (2 ON)
[13:24:25.102] INFO: TBM Core alpha (0): 7 registers set
[13:24:25.102] INFO: TBM Core beta (1): 7 registers set
[13:24:25.102] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:24:25.102] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:25.102] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:25.102] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:25.102] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:25.102] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:25.102] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:25.102] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:25.102] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:25.102] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:25.102] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:25.102] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:25.102] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:25.102] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:25.102] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:25.102] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:25.102] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:26.203] INFO: Test took 1101ms.
[13:24:26.206] INFO: The DUT currently contains the following objects:
[13:24:26.206] INFO: 2 TBM Cores tbm08c (2 ON)
[13:24:26.206] INFO: TBM Core alpha (0): 7 registers set
[13:24:26.206] INFO: TBM Core beta (1): 7 registers set
[13:24:26.206] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:24:26.206] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:26.206] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:26.206] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:26.206] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:26.206] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:26.206] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:26.206] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:26.206] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:26.206] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:26.206] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:26.206] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:26.206] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:26.206] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:26.206] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:26.206] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:26.206] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:27.305] INFO: Test took 1099ms.
[13:24:27.307] INFO: The DUT currently contains the following objects:
[13:24:27.307] INFO: 2 TBM Cores tbm08c (2 ON)
[13:24:27.307] INFO: TBM Core alpha (0): 7 registers set
[13:24:27.307] INFO: TBM Core beta (1): 7 registers set
[13:24:27.307] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:24:27.307] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:27.307] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:27.307] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:27.307] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:27.307] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:27.307] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:27.307] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:27.307] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:27.307] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:27.307] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:27.307] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:27.307] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:27.307] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:27.307] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:27.307] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:27.307] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:28.408] INFO: Test took 1102ms.
[13:24:28.411] INFO: The DUT currently contains the following objects:
[13:24:28.411] INFO: 2 TBM Cores tbm08c (2 ON)
[13:24:28.411] INFO: TBM Core alpha (0): 7 registers set
[13:24:28.411] INFO: TBM Core beta (1): 7 registers set
[13:24:28.411] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:24:28.411] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:28.411] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:28.411] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:28.411] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:28.411] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:28.411] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:28.411] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:28.411] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:28.411] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:28.411] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:28.411] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:28.411] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:28.411] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:28.411] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:28.411] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:28.411] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:29.511] INFO: Test took 1099ms.
[13:24:29.520] INFO: The DUT currently contains the following objects:
[13:24:29.520] INFO: 2 TBM Cores tbm08c (2 ON)
[13:24:29.520] INFO: TBM Core alpha (0): 7 registers set
[13:24:29.520] INFO: TBM Core beta (1): 7 registers set
[13:24:29.520] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:24:29.520] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:29.520] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:29.520] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:29.520] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:29.520] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:29.520] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:29.520] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:29.520] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:29.520] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:29.521] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:29.521] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:29.521] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:29.521] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:29.521] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:29.521] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:29.521] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:24:30.616] INFO: Test took 1095ms.
[13:24:30.623] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:27:42.376] INFO: Test took 191754ms.
[13:27:45.614] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:30:58.110] INFO: Test took 192496ms.
[13:31:01.340] INFO: safety margin for low PH: adding 0, margin is now 20
[13:31:01.350] INFO: safety margin for low PH: adding 0, margin is now 20
[13:31:01.360] INFO: safety margin for low PH: adding 0, margin is now 20
[13:31:01.370] INFO: safety margin for low PH: adding 0, margin is now 20
[13:31:01.380] INFO: safety margin for low PH: adding 0, margin is now 20
[13:31:01.391] INFO: safety margin for low PH: adding 0, margin is now 20
[13:31:01.401] INFO: safety margin for low PH: adding 0, margin is now 20
[13:31:01.412] INFO: safety margin for low PH: adding 0, margin is now 20
[13:31:01.423] INFO: safety margin for low PH: adding 0, margin is now 20
[13:31:01.433] INFO: safety margin for low PH: adding 0, margin is now 20
[13:31:01.445] INFO: safety margin for low PH: adding 0, margin is now 20
[13:31:01.454] INFO: safety margin for low PH: adding 0, margin is now 20
[13:31:01.465] INFO: safety margin for low PH: adding 0, margin is now 20
[13:31:01.476] INFO: safety margin for low PH: adding 0, margin is now 20
[13:31:01.486] INFO: safety margin for low PH: adding 0, margin is now 20
[13:31:01.496] INFO: safety margin for low PH: adding 0, margin is now 20
[13:31:01.582] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/dacParameters35_C0.dat
[13:31:01.583] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/dacParameters35_C1.dat
[13:31:01.583] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/dacParameters35_C2.dat
[13:31:01.584] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/dacParameters35_C3.dat
[13:31:01.584] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/dacParameters35_C4.dat
[13:31:01.584] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/dacParameters35_C5.dat
[13:31:01.585] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/dacParameters35_C6.dat
[13:31:01.585] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/dacParameters35_C7.dat
[13:31:01.585] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/dacParameters35_C8.dat
[13:31:01.586] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/dacParameters35_C9.dat
[13:31:01.586] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/dacParameters35_C10.dat
[13:31:01.586] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/dacParameters35_C11.dat
[13:31:01.587] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/dacParameters35_C12.dat
[13:31:01.587] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/dacParameters35_C13.dat
[13:31:01.587] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/dacParameters35_C14.dat
[13:31:01.588] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/dacParameters35_C15.dat
[13:31:05.315] INFO: Test took 3721ms.
[13:31:09.312] INFO: Test took 3630ms.
[13:31:13.403] INFO: Test took 3731ms.
[13:31:13.754] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:31:14.664] INFO: Test took 910ms.
[13:31:14.668] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:31:15.769] INFO: Test took 1101ms.
[13:31:15.775] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:31:16.876] INFO: Test took 1101ms.
[13:31:16.883] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:31:17.978] INFO: Test took 1095ms.
[13:31:17.982] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:31:19.082] INFO: Test took 1100ms.
[13:31:19.087] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:31:20.188] INFO: Test took 1101ms.
[13:31:20.194] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:31:21.296] INFO: Test took 1102ms.
[13:31:21.302] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:31:22.416] INFO: Test took 1114ms.
[13:31:22.423] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:31:23.522] INFO: Test took 1099ms.
[13:31:23.526] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:31:24.625] INFO: Test took 1099ms.
[13:31:24.630] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:31:25.730] INFO: Test took 1101ms.
[13:31:25.736] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:31:26.836] INFO: Test took 1100ms.
[13:31:26.839] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:31:27.938] INFO: Test took 1099ms.
[13:31:27.943] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:31:29.045] INFO: Test took 1103ms.
[13:31:29.050] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:31:30.149] INFO: Test took 1099ms.
[13:31:30.153] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:31:31.256] INFO: Test took 1104ms.
[13:31:31.263] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:31:32.361] INFO: Test took 1098ms.
[13:31:32.366] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:31:33.466] INFO: Test took 1100ms.
[13:31:33.472] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:31:34.573] INFO: Test took 1101ms.
[13:31:34.580] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:31:35.680] INFO: Test took 1100ms.
[13:31:35.684] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:31:36.786] INFO: Test took 1102ms.
[13:31:36.793] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:31:37.890] INFO: Test took 1098ms.
[13:31:37.894] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:31:38.994] INFO: Test took 1100ms.
[13:31:38.999] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:31:40.101] INFO: Test took 1103ms.
[13:31:40.108] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:31:41.204] INFO: Test took 1097ms.
[13:31:41.207] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:31:42.307] INFO: Test took 1100ms.
[13:31:42.313] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:31:43.414] INFO: Test took 1101ms.
[13:31:43.421] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:31:44.522] INFO: Test took 1102ms.
[13:31:44.528] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:31:45.629] INFO: Test took 1101ms.
[13:31:45.636] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:31:46.729] INFO: Test took 1094ms.
[13:31:46.733] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:31:47.832] INFO: Test took 1099ms.
[13:31:47.839] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:31:48.939] INFO: Test took 1101ms.
[13:31:49.544] INFO: PixTestPhOptimization::doTest() done, duration: 530 seconds
[13:31:49.544] INFO: PH scale (per ROC): 81 67 72 77 72 79 71 74 79 82 76 79 71 80 73 75
[13:31:49.544] INFO: PH offset (per ROC): 157 162 166 164 171 164 165 151 162 150 174 153 171 151 162 170
[13:31:49.752] INFO: ######################################################################
[13:31:49.752] INFO: PixTestGainPedestal::fullTest() ntrig = 10
[13:31:49.752] INFO: ######################################################################
[13:31:49.773] INFO: scanning low vcal = 10
[13:31:53.858] INFO: Test took 4085ms.
[13:31:53.868] INFO: scanning low vcal = 20
[13:31:57.914] INFO: Test took 4046ms.
[13:31:57.924] INFO: scanning low vcal = 30
[13:32:01.963] INFO: Test took 4039ms.
[13:32:01.979] INFO: scanning low vcal = 40
[13:32:06.502] INFO: Test took 4523ms.
[13:32:06.619] INFO: scanning low vcal = 50
[13:32:11.229] INFO: Test took 4610ms.
[13:32:11.365] INFO: scanning low vcal = 60
[13:32:15.968] INFO: Test took 4603ms.
[13:32:16.103] INFO: scanning low vcal = 70
[13:32:20.749] INFO: Test took 4646ms.
[13:32:20.874] INFO: scanning low vcal = 80
[13:32:25.485] INFO: Test took 4611ms.
[13:32:25.627] INFO: scanning low vcal = 90
[13:32:30.316] INFO: Test took 4689ms.
[13:32:30.451] INFO: scanning low vcal = 100
[13:32:35.108] INFO: Test took 4657ms.
[13:32:35.235] INFO: scanning low vcal = 110
[13:32:39.857] INFO: Test took 4622ms.
[13:32:39.981] INFO: scanning low vcal = 120
[13:32:44.593] INFO: Test took 4612ms.
[13:32:44.727] INFO: scanning low vcal = 130
[13:32:49.346] INFO: Test took 4619ms.
[13:32:49.474] INFO: scanning low vcal = 140
[13:32:54.131] INFO: Test took 4657ms.
[13:32:54.264] INFO: scanning low vcal = 150
[13:32:58.919] INFO: Test took 4655ms.
[13:32:59.047] INFO: scanning low vcal = 160
[13:33:03.660] INFO: Test took 4613ms.
[13:33:03.794] INFO: scanning low vcal = 170
[13:33:08.490] INFO: Test took 4696ms.
[13:33:08.619] INFO: scanning low vcal = 180
[13:33:13.288] INFO: Test took 4669ms.
[13:33:13.402] INFO: scanning low vcal = 190
[13:33:18.188] INFO: Test took 4786ms.
[13:33:18.328] INFO: scanning low vcal = 200
[13:33:23.007] INFO: Test took 4679ms.
[13:33:23.141] INFO: scanning low vcal = 210
[13:33:27.811] INFO: Test took 4670ms.
[13:33:27.935] INFO: scanning low vcal = 220
[13:33:32.535] INFO: Test took 4600ms.
[13:33:32.663] INFO: scanning low vcal = 230
[13:33:37.355] INFO: Test took 4691ms.
[13:33:37.485] INFO: scanning low vcal = 240
[13:33:42.114] INFO: Test took 4629ms.
[13:33:42.238] INFO: scanning low vcal = 250
[13:33:46.868] INFO: Test took 4630ms.
[13:33:46.994] INFO: scanning high vcal = 30 (= 210 in low range)
[13:33:51.645] INFO: Test took 4651ms.
[13:33:51.770] INFO: scanning high vcal = 50 (= 350 in low range)
[13:33:56.365] INFO: Test took 4595ms.
[13:33:56.491] INFO: scanning high vcal = 70 (= 490 in low range)
[13:34:01.139] INFO: Test took 4648ms.
[13:34:01.256] INFO: scanning high vcal = 90 (= 630 in low range)
[13:34:05.879] INFO: Test took 4623ms.
[13:34:05.991] INFO: scanning high vcal = 200 (= 1400 in low range)
[13:34:10.544] INFO: Test took 4553ms.
[13:34:11.336] INFO: PixTestGainPedestal::measure() done
[13:35:00.507] INFO: PixTestGainPedestal::fit() done
[13:35:00.507] INFO: non-linearity mean: 0.952 0.953 0.961 0.953 0.950 0.953 0.954 0.955 0.956 0.954 0.954 0.955 0.951 0.960 0.951 0.956
[13:35:00.507] INFO: non-linearity RMS: 0.007 0.007 0.008 0.006 0.008 0.007 0.006 0.007 0.008 0.005 0.007 0.006 0.007 0.005 0.007 0.006
[13:35:00.507] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/phCalibrationFitErr35_C0.dat
[13:35:00.533] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/phCalibrationFitErr35_C1.dat
[13:35:00.557] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/phCalibrationFitErr35_C2.dat
[13:35:00.582] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/phCalibrationFitErr35_C3.dat
[13:35:00.607] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/phCalibrationFitErr35_C4.dat
[13:35:00.632] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/phCalibrationFitErr35_C5.dat
[13:35:00.656] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/phCalibrationFitErr35_C6.dat
[13:35:00.680] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/phCalibrationFitErr35_C7.dat
[13:35:00.702] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/phCalibrationFitErr35_C8.dat
[13:35:00.725] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/phCalibrationFitErr35_C9.dat
[13:35:00.749] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/phCalibrationFitErr35_C10.dat
[13:35:00.775] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/phCalibrationFitErr35_C11.dat
[13:35:00.800] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/phCalibrationFitErr35_C12.dat
[13:35:00.825] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/phCalibrationFitErr35_C13.dat
[13:35:00.849] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/phCalibrationFitErr35_C14.dat
[13:35:00.874] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/phCalibrationFitErr35_C15.dat
[13:35:00.899] INFO: PixTestGainPedestal::doTest() done, duration: 191 seconds
[13:35:00.908] INFO: readReadbackCal: /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/readbackCal_C0.dat .. /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/readbackCal_C15.dat
[13:35:00.909] INFO: PixTestReadback::doTest() start.
[13:35:00.910] INFO: PixTestReadback::RES sent once
[13:35:17.505] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/readbackCal_C0.dat
[13:35:17.506] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/readbackCal_C1.dat
[13:35:17.506] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/readbackCal_C2.dat
[13:35:17.506] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/readbackCal_C3.dat
[13:35:17.506] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/readbackCal_C4.dat
[13:35:17.506] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/readbackCal_C5.dat
[13:35:17.506] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/readbackCal_C6.dat
[13:35:17.506] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/readbackCal_C7.dat
[13:35:17.506] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/readbackCal_C8.dat
[13:35:17.506] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/readbackCal_C9.dat
[13:35:17.506] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/readbackCal_C10.dat
[13:35:17.506] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/readbackCal_C11.dat
[13:35:17.506] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/readbackCal_C12.dat
[13:35:17.506] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/readbackCal_C13.dat
[13:35:17.506] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/readbackCal_C14.dat
[13:35:17.507] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/readbackCal_C15.dat
[13:35:17.554] INFO: PixTestPattern:: pg_setup set to default.
[13:35:17.555] INFO: PixTestReadback::RES sent once
[13:35:34.051] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/readbackCal_C0.dat
[13:35:34.051] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/readbackCal_C1.dat
[13:35:34.051] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/readbackCal_C2.dat
[13:35:34.051] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/readbackCal_C3.dat
[13:35:34.051] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/readbackCal_C4.dat
[13:35:34.051] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/readbackCal_C5.dat
[13:35:34.051] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/readbackCal_C6.dat
[13:35:34.051] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/readbackCal_C7.dat
[13:35:34.051] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/readbackCal_C8.dat
[13:35:34.051] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/readbackCal_C9.dat
[13:35:34.051] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/readbackCal_C10.dat
[13:35:34.052] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/readbackCal_C11.dat
[13:35:34.052] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/readbackCal_C12.dat
[13:35:34.052] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/readbackCal_C13.dat
[13:35:34.052] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/readbackCal_C14.dat
[13:35:34.052] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/readbackCal_C15.dat
[13:35:34.105] INFO: PixTestPattern:: pg_setup set to default.
[13:35:34.106] INFO: PixTestReadback::RES sent once
[13:35:46.866] INFO: PixTestPattern:: pg_setup set to default.
[13:35:46.867] INFO: Vbg will be calibrated using Vd calibration
[13:35:46.867] INFO: /*/*/*/*::: ROC 0: uncalibrated Vbg = 153.6calibrated Vbg = 1.20278 :::*/*/*/*/
[13:35:46.867] INFO: /*/*/*/*::: ROC 1: uncalibrated Vbg = 157.7calibrated Vbg = 1.21594 :::*/*/*/*/
[13:35:46.867] INFO: /*/*/*/*::: ROC 2: uncalibrated Vbg = 147.1calibrated Vbg = 1.21261 :::*/*/*/*/
[13:35:46.867] INFO: /*/*/*/*::: ROC 3: uncalibrated Vbg = 152.4calibrated Vbg = 1.21779 :::*/*/*/*/
[13:35:46.867] INFO: /*/*/*/*::: ROC 4: uncalibrated Vbg = 151.8calibrated Vbg = 1.21048 :::*/*/*/*/
[13:35:46.867] INFO: /*/*/*/*::: ROC 5: uncalibrated Vbg = 161.6calibrated Vbg = 1.21797 :::*/*/*/*/
[13:35:46.867] INFO: /*/*/*/*::: ROC 6: uncalibrated Vbg = 151.2calibrated Vbg = 1.22075 :::*/*/*/*/
[13:35:46.867] INFO: /*/*/*/*::: ROC 7: uncalibrated Vbg = 159.7calibrated Vbg = 1.2179 :::*/*/*/*/
[13:35:46.867] INFO: /*/*/*/*::: ROC 8: uncalibrated Vbg = 160.8calibrated Vbg = 1.22523 :::*/*/*/*/
[13:35:46.867] INFO: /*/*/*/*::: ROC 9: uncalibrated Vbg = 142.4calibrated Vbg = 1.22595 :::*/*/*/*/
[13:35:46.867] INFO: /*/*/*/*::: ROC 10: uncalibrated Vbg = 148calibrated Vbg = 1.21847 :::*/*/*/*/
[13:35:46.867] INFO: /*/*/*/*::: ROC 11: uncalibrated Vbg = 156.8calibrated Vbg = 1.22678 :::*/*/*/*/
[13:35:46.867] INFO: /*/*/*/*::: ROC 12: uncalibrated Vbg = 160.2calibrated Vbg = 1.21402 :::*/*/*/*/
[13:35:46.867] INFO: /*/*/*/*::: ROC 13: uncalibrated Vbg = 158.9calibrated Vbg = 1.20413 :::*/*/*/*/
[13:35:46.867] INFO: /*/*/*/*::: ROC 14: uncalibrated Vbg = 153.3calibrated Vbg = 1.20678 :::*/*/*/*/
[13:35:46.867] INFO: /*/*/*/*::: ROC 15: uncalibrated Vbg = 148calibrated Vbg = 1.20985 :::*/*/*/*/
[13:35:46.872] INFO: PixTestReadback::RES sent once
[13:39:42.198] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/readbackCal_C0.dat
[13:39:42.198] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/readbackCal_C1.dat
[13:39:42.198] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/readbackCal_C2.dat
[13:39:42.198] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/readbackCal_C3.dat
[13:39:42.198] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/readbackCal_C4.dat
[13:39:42.198] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/readbackCal_C5.dat
[13:39:42.199] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/readbackCal_C6.dat
[13:39:42.199] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/readbackCal_C7.dat
[13:39:42.199] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/readbackCal_C8.dat
[13:39:42.199] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/readbackCal_C9.dat
[13:39:42.199] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/readbackCal_C10.dat
[13:39:42.199] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/readbackCal_C11.dat
[13:39:42.199] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/readbackCal_C12.dat
[13:39:42.199] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/readbackCal_C13.dat
[13:39:42.199] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/readbackCal_C14.dat
[13:39:42.199] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/001_Fulltest_m20/readbackCal_C15.dat
[13:39:42.250] INFO: PixTestPattern:: pg_setup set to default.
[13:39:42.252] INFO: PixTestReadback::doTest() done
[13:39:42.266] INFO: enter test to run
[13:39:42.266] INFO: test: q no parameter change
[13:39:42.466] QUIET: Connection to board 175 closed.
[13:39:42.470] INFO: pXar: this is the end, my friend