[21:36:50.374] INFO: *** Welcome to pxar ***
[21:36:50.374] INFO: *** Today: 2015/08/14
[21:36:50.374] INFO: readRocDacs: /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/dacParameters_C0.dat .. /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/dacParameters_C15.dat
[21:36:50.375] INFO: readTbmDacs: /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/tbmParameters_C0a.dat .. /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/tbmParameters_C0b.dat
[21:36:50.375] INFO: readMaskFile: /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/defaultMaskFile.dat
[21:36:50.375] INFO: readTrimFile: /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/trimParameters_C0.dat .. /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/trimParameters_C15.dat
[21:36:50.473] INFO: clk: 4
[21:36:50.473] INFO: ctr: 4
[21:36:50.473] INFO: sda: 19
[21:36:50.473] INFO: tin: 9
[21:36:50.473] INFO: level: 15
[21:36:50.473] INFO: triggerdelay: 0
[21:36:50.473] QUIET: Instanciating API for pxar prod-01+69~g35a931b
[21:36:50.474] INFO: Log level: INFO
[21:36:50.491] INFO: Found DTB DTB_WZ4WY6
[21:36:50.502] QUIET: Connection to board DTB_WZ4WY6 opened.
[21:36:50.506] 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:
------------------------------------------------------
[21:36:50.509] INFO: RPC call hashes of host and DTB match: 447413373
[21:36:52.265] INFO: DUT info:
[21:36:52.265] INFO: The DUT currently contains the following objects:
[21:36:52.265] INFO: 2 TBM Cores tbm08c (2 ON)
[21:36:52.265] INFO: TBM Core alpha (0): 7 registers set
[21:36:52.265] INFO: TBM Core beta (1): 7 registers set
[21:36:52.265] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[21:36:52.265] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[21:36:52.265] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[21:36:52.265] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[21:36:52.265] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[21:36:52.265] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[21:36:52.265] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[21:36:52.265] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[21:36:52.266] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[21:36:52.266] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[21:36:52.266] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[21:36:52.266] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[21:36:52.266] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[21:36:52.266] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[21:36:52.266] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[21:36:52.266] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[21:36:52.266] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[21:36:52.667] INFO: enter 'restricted' command line mode
[21:36:52.667] INFO: enter test to run
[21:36:52.667] INFO: test: pretest no parameter change
[21:36:52.667] INFO: running: pretest
[21:36:52.677] INFO: ######################################################################
[21:36:52.677] INFO: PixTestPretest::doTest()
[21:36:52.677] INFO: ######################################################################
[21:36:52.678] INFO: ----------------------------------------------------------------------
[21:36:52.679] INFO: PixTestPretest::programROC()
[21:36:52.679] INFO: ----------------------------------------------------------------------
[21:37:10.702] INFO: PixTestPretest::programROC() done: ROCs are all programmable
[21:37:10.703] INFO: IA differences per ROC: 15.3 20.1 17.7 19.3 18.5 17.7 18.5 17.7 16.9 16.9 18.5 17.7 17.7 18.5 18.5 20.1
[21:37:10.796] INFO: ----------------------------------------------------------------------
[21:37:10.796] INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[21:37:10.796] INFO: ----------------------------------------------------------------------
[21:37:30.469] INFO: PixTestPretest::setVana() done, Module Ia 385.1 mA = 24.0688 mA/ROC
[21:37:30.471] INFO: ----------------------------------------------------------------------
[21:37:30.471] INFO: PixTestPreTest::setTimings()
[21:37:30.471] INFO: ----------------------------------------------------------------------
[21:37:31.447] INFO: ----------------------------------------------------------------------
[21:37:31.447] INFO: Current timings are good. No timing scan needed.
[21:37:31.447] INFO: ----------------------------------------------------------------------
[21:37:31.447] INFO: Test took 976 ms.
[21:37:31.447] INFO: PixTestPretest::setTimings() done.
[21:37:31.639] INFO: ----------------------------------------------------------------------
[21:37:31.639] INFO: PixTestPretest::findWorkingPixel()
[21:37:31.639] INFO: ----------------------------------------------------------------------
[21:37:39.244] INFO: Test took 7600ms.
[21:37:39.555] INFO: Found working pixel in all ROCs: col/row = 12/22
[21:37:39.607] INFO: ----------------------------------------------------------------------
[21:37:39.607] INFO: PixTestPretest::setVthrCompCalDel()
[21:37:39.607] INFO: ----------------------------------------------------------------------
[21:37:47.236] INFO: Test took 7623ms.
[21:37:47.576] INFO: PixTestPretest::setVthrCompCalDel() done
[21:37:47.576] INFO: CalDel: 133 158 155 134 129 161 142 118 122 145 143 129 139 132 156 132
[21:37:47.576] INFO: VthrComp: 51 51 51 51 51 51 51 51 51 52 51 51 51 51 51 51
[21:37:47.581] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/dacParameters_C0.dat
[21:37:47.581] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/dacParameters_C1.dat
[21:37:47.581] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/dacParameters_C2.dat
[21:37:47.581] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/dacParameters_C3.dat
[21:37:47.581] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/dacParameters_C4.dat
[21:37:47.581] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/dacParameters_C5.dat
[21:37:47.581] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/dacParameters_C6.dat
[21:37:47.582] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/dacParameters_C7.dat
[21:37:47.582] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/dacParameters_C8.dat
[21:37:47.582] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/dacParameters_C9.dat
[21:37:47.582] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/dacParameters_C10.dat
[21:37:47.582] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/dacParameters_C11.dat
[21:37:47.582] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/dacParameters_C12.dat
[21:37:47.582] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/dacParameters_C13.dat
[21:37:47.582] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/dacParameters_C14.dat
[21:37:47.582] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/dacParameters_C15.dat
[21:37:47.583] INFO: write tbm parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/tbmParameters_C0a.dat
[21:37:47.583] INFO: write tbm parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/tbmParameters_C0b.dat
[21:37:47.583] INFO: PixTestPretest::doTest() done, duration: 54 seconds
[21:37:47.668] INFO: enter test to run
[21:37:47.668] INFO: test: fulltest no parameter change
[21:37:47.668] INFO: running: fulltest
[21:37:47.668] INFO: ######################################################################
[21:37:47.668] INFO: PixTestFullTest::doTest()
[21:37:47.668] INFO: ######################################################################
[21:37:47.669] INFO: ######################################################################
[21:37:47.669] INFO: PixTestAlive::doTest()
[21:37:47.669] INFO: ######################################################################
[21:37:47.671] INFO: ----------------------------------------------------------------------
[21:37:47.671] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[21:37:47.671] INFO: ----------------------------------------------------------------------
[21:37:51.224] INFO: Test took 3551ms.
[21:37:51.253] INFO: Fetched DAQ statistics. Counters are being reset now.
[21:37:51.497] INFO: PixTestAlive::aliveTest() done
[21:37:51.497] INFO: number of dead pixels (per ROC): 0 0 0 3 2 0 0 0 0 0 0 0 0 0 0 0
[21:37:51.499] INFO: ----------------------------------------------------------------------
[21:37:51.499] INFO: PixTestAlive::maskTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[21:37:51.499] INFO: ----------------------------------------------------------------------
[21:37:54.330] INFO: Test took 2828ms.
[21:37:54.337] INFO: Fetched DAQ statistics. Counters are being reset now.
[21:37:54.338] INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[21:37:54.605] INFO: PixTestAlive::maskTest() done
[21:37:54.605] INFO: number of mask-defect pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[21:37:54.608] INFO: ----------------------------------------------------------------------
[21:37:54.608] INFO: PixTestAlive::addressDecodingTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[21:37:54.608] INFO: ----------------------------------------------------------------------
[21:37:58.184] INFO: Test took 3573ms.
[21:37:58.216] INFO: Fetched DAQ statistics. Counters are being reset now.
[21:37:58.473] INFO: PixTestAlive::addressDecodingTest() done
[21:37:58.473] INFO: number of address-decoding pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[21:37:58.474] INFO: PixTestAlive::doTest() done, duration: 10 seconds
[21:37:58.485] INFO: ######################################################################
[21:37:58.485] INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[21:37:58.485] INFO: ######################################################################
[21:37:58.490] INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (30/5) hits flags = 2 (plus default)
[21:37:58.512] INFO: dacScan step from 0 .. 29
[21:37:58.512] INFO: dacScan split into 1 runs with ntrig = 5
[21:37:58.512] INFO: run 1 of 1
[21:38:18.398] INFO: Test took 19886ms.
[21:38:18.460] INFO: Fetched DAQ statistics. Counters are being reset now.
[21:38:18.460] INFO: dacScan step from 30 .. 59
[21:38:18.460] INFO: dacScan split into 1 runs with ntrig = 5
[21:38:18.460] INFO: run 1 of 1
[21:38:38.708] INFO: Test took 20248ms.
[21:38:38.815] INFO: Fetched DAQ statistics. Counters are being reset now.
[21:38:38.824] INFO: dacScan step from 60 .. 89
[21:38:38.824] INFO: dacScan split into 1 runs with ntrig = 5
[21:38:38.824] INFO: run 1 of 1
[21:39:04.820] INFO: Test took 25996ms.
[21:39:05.186] INFO: Fetched DAQ statistics. Counters are being reset now.
[21:39:05.268] INFO: dacScan step from 90 .. 119
[21:39:05.268] INFO: dacScan split into 1 runs with ntrig = 5
[21:39:05.268] INFO: run 1 of 1
[21:39:33.114] INFO: Test took 27846ms.
[21:39:33.527] INFO: Fetched DAQ statistics. Counters are being reset now.
[21:39:33.624] INFO: dacScan step from 120 .. 149
[21:39:33.624] INFO: dacScan split into 1 runs with ntrig = 5
[21:39:33.624] INFO: run 1 of 1
[21:39:58.134] INFO: Test took 24509ms.
[21:39:58.490] INFO: Fetched DAQ statistics. Counters are being reset now.
[21:40:36.022] INFO: PixTestBBMap::doTest() done, duration: 157 seconds
[21:40:36.022] INFO: number of dead bumps (per ROC): 0 0 0 0 0 0 5 0 1 0 0 0 0 0 0 2
[21:40:36.023] INFO: separation cut (per ROC): 105 96 102 106 102 87 87 113 117 104 109 113 109 118 91 107
[21:40:36.124] INFO: ######################################################################
[21:40:36.124] INFO: PixTestScurves::fullTest() ntrig = 50, dacs/step = -1, ntrig/step = 1
[21:40:36.124] INFO: ######################################################################
[21:40:36.124] INFO: ----------------------------------------------------------------------
[21:40:36.124] INFO: PixTestScurves::scurves(Vcal), ntrig = 50, dacs/step = -1, ntrig/step = 1
[21:40:36.124] INFO: ----------------------------------------------------------------------
[21:40:36.125] INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 0 .. 149 (-1/1) hits flags = 16 (plus default)
[21:40:36.140] INFO: dacScan split into 50 runs with ntrig = 1
[21:40:36.140] INFO: run 1 of 50
[21:41:25.337] INFO: Test took 49197ms.
[21:41:25.734] INFO: Fetched DAQ statistics. Counters are being reset now.
[21:41:25.905] INFO: run 2 of 50
[21:42:15.175] INFO: Test took 49270ms.
[21:42:15.551] INFO: Fetched DAQ statistics. Counters are being reset now.
[21:42:15.742] INFO: run 3 of 50
[21:43:05.022] INFO: Test took 49280ms.
[21:43:05.404] INFO: Fetched DAQ statistics. Counters are being reset now.
[21:43:05.584] INFO: run 4 of 50
[21:43:54.865] INFO: Test took 49281ms.
[21:43:55.244] INFO: Fetched DAQ statistics. Counters are being reset now.
[21:43:55.424] INFO: run 5 of 50
[21:44:44.700] INFO: Test took 49276ms.
[21:44:45.068] INFO: Fetched DAQ statistics. Counters are being reset now.
[21:44:45.241] INFO: run 6 of 50
[21:45:34.446] INFO: Test took 49205ms.
[21:45:34.831] INFO: Fetched DAQ statistics. Counters are being reset now.
[21:45:35.006] INFO: run 7 of 50
[21:46:24.140] INFO: Test took 49134ms.
[21:46:24.519] INFO: Fetched DAQ statistics. Counters are being reset now.
[21:46:24.701] INFO: run 8 of 50
[21:47:13.946] INFO: Test took 49244ms.
[21:47:14.305] INFO: Fetched DAQ statistics. Counters are being reset now.
[21:47:14.474] INFO: run 9 of 50
[21:48:03.692] INFO: Test took 49218ms.
[21:48:04.068] INFO: Fetched DAQ statistics. Counters are being reset now.
[21:48:04.254] INFO: run 10 of 50
[21:48:53.562] INFO: Test took 49308ms.
[21:48:53.928] INFO: Fetched DAQ statistics. Counters are being reset now.
[21:48:54.110] INFO: run 11 of 50
[21:49:43.343] INFO: Test took 49233ms.
[21:49:43.716] INFO: Fetched DAQ statistics. Counters are being reset now.
[21:49:43.887] INFO: run 12 of 50
[21:50:33.195] INFO: Test took 49308ms.
[21:50:33.564] INFO: Fetched DAQ statistics. Counters are being reset now.
[21:50:33.737] INFO: run 13 of 50
[21:51:22.003] INFO: Test took 49266ms.
[21:51:23.365] INFO: Fetched DAQ statistics. Counters are being reset now.
[21:51:23.536] INFO: run 14 of 50
[21:52:12.780] INFO: Test took 49244ms.
[21:52:13.145] INFO: Fetched DAQ statistics. Counters are being reset now.
[21:52:13.318] INFO: run 15 of 50
[21:53:02.610] INFO: Test took 49292ms.
[21:53:02.982] INFO: Fetched DAQ statistics. Counters are being reset now.
[21:53:03.152] INFO: run 16 of 50
[21:53:52.391] INFO: Test took 49238ms.
[21:53:52.768] INFO: Fetched DAQ statistics. Counters are being reset now.
[21:53:52.949] INFO: run 17 of 50
[21:54:42.287] INFO: Test took 49338ms.
[21:54:42.654] INFO: Fetched DAQ statistics. Counters are being reset now.
[21:54:42.826] INFO: run 18 of 50
[21:55:32.062] INFO: Test took 49235ms.
[21:55:32.427] INFO: Fetched DAQ statistics. Counters are being reset now.
[21:55:32.602] INFO: run 19 of 50
[21:56:21.876] INFO: Test took 49274ms.
[21:56:22.247] INFO: Fetched DAQ statistics. Counters are being reset now.
[21:56:22.428] INFO: run 20 of 50
[21:57:11.872] INFO: Test took 49443ms.
[21:57:12.245] INFO: Fetched DAQ statistics. Counters are being reset now.
[21:57:12.419] INFO: run 21 of 50
[21:58:01.770] INFO: Test took 49351ms.
[21:58:02.141] INFO: Fetched DAQ statistics. Counters are being reset now.
[21:58:02.326] INFO: run 22 of 50
[21:58:51.693] INFO: Test took 49367ms.
[21:58:52.075] INFO: Fetched DAQ statistics. Counters are being reset now.
[21:58:52.258] INFO: run 23 of 50
[21:59:41.576] INFO: Test took 49317ms.
[21:59:41.958] INFO: Fetched DAQ statistics. Counters are being reset now.
[21:59:42.134] INFO: run 24 of 50
[22:00:31.455] INFO: Test took 49321ms.
[22:00:31.820] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:00:31.991] INFO: run 25 of 50
[22:01:21.290] INFO: Test took 49299ms.
[22:01:21.668] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:01:21.840] INFO: run 26 of 50
[22:02:11.190] INFO: Test took 49350ms.
[22:02:11.539] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:02:11.713] INFO: run 27 of 50
[22:03:01.031] INFO: Test took 49318ms.
[22:03:01.396] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:03:01.576] INFO: run 28 of 50
[22:03:50.999] INFO: Test took 49423ms.
[22:03:51.354] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:03:51.524] INFO: run 29 of 50
[22:04:40.859] INFO: Test took 49335ms.
[22:04:41.225] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:04:41.399] INFO: run 30 of 50
[22:05:30.653] INFO: Test took 49254ms.
[22:05:31.006] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:05:31.176] INFO: run 31 of 50
[22:06:20.568] INFO: Test took 49392ms.
[22:06:20.933] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:06:21.116] INFO: run 32 of 50
[22:07:10.422] INFO: Test took 49306ms.
[22:07:10.780] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:07:10.964] INFO: run 33 of 50
[22:08:00.342] INFO: Test took 49378ms.
[22:08:00.698] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:08:00.873] INFO: run 34 of 50
[22:08:50.150] INFO: Test took 49276ms.
[22:08:50.502] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:08:50.672] INFO: run 35 of 50
[22:09:40.059] INFO: Test took 49386ms.
[22:09:40.419] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:09:40.599] INFO: run 36 of 50
[22:10:29.003] INFO: Test took 49404ms.
[22:10:30.362] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:10:30.542] INFO: run 37 of 50
[22:11:19.004] INFO: Test took 49462ms.
[22:11:20.362] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:11:20.539] INFO: run 38 of 50
[22:12:09.886] INFO: Test took 49347ms.
[22:12:10.251] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:12:10.425] INFO: run 39 of 50
[22:12:59.769] INFO: Test took 49344ms.
[22:13:00.132] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:13:00.310] INFO: run 40 of 50
[22:13:49.560] INFO: Test took 49250ms.
[22:13:49.003] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:13:50.181] INFO: run 41 of 50
[22:14:39.565] INFO: Test took 49384ms.
[22:14:39.916] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:14:40.086] INFO: run 42 of 50
[22:15:29.385] INFO: Test took 49299ms.
[22:15:29.748] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:15:29.923] INFO: run 43 of 50
[22:16:19.254] INFO: Test took 49331ms.
[22:16:19.630] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:16:19.812] INFO: run 44 of 50
[22:17:09.188] INFO: Test took 49376ms.
[22:17:09.548] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:17:09.719] INFO: run 45 of 50
[22:17:58.973] INFO: Test took 49253ms.
[22:17:59.327] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:17:59.498] INFO: run 46 of 50
[22:18:48.765] INFO: Test took 49267ms.
[22:18:49.133] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:18:49.302] INFO: run 47 of 50
[22:19:38.575] INFO: Test took 49273ms.
[22:19:38.932] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:19:39.101] INFO: run 48 of 50
[22:20:28.370] INFO: Test took 49269ms.
[22:20:28.735] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:20:28.910] INFO: run 49 of 50
[22:21:18.285] INFO: Test took 49375ms.
[22:21:18.646] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:21:18.817] INFO: run 50 of 50
[22:22:07.905] INFO: Test took 49088ms.
[22:22:08.430] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:22:08.665] INFO: dumping ASCII scurve output file: SCurveData
[22:22:11.249] INFO: dumping ASCII scurve output file: SCurveData
[22:22:13.727] INFO: dumping ASCII scurve output file: SCurveData
[22:22:16.269] INFO: dumping ASCII scurve output file: SCurveData
[22:22:18.787] INFO: dumping ASCII scurve output file: SCurveData
[22:22:21.527] INFO: dumping ASCII scurve output file: SCurveData
[22:22:24.175] INFO: dumping ASCII scurve output file: SCurveData
[22:22:26.916] INFO: dumping ASCII scurve output file: SCurveData
[22:22:29.296] INFO: dumping ASCII scurve output file: SCurveData
[22:22:31.470] INFO: dumping ASCII scurve output file: SCurveData
[22:22:33.771] INFO: dumping ASCII scurve output file: SCurveData
[22:22:36.129] INFO: dumping ASCII scurve output file: SCurveData
[22:22:38.465] INFO: dumping ASCII scurve output file: SCurveData
[22:22:40.844] INFO: dumping ASCII scurve output file: SCurveData
[22:22:43.215] INFO: dumping ASCII scurve output file: SCurveData
[22:22:45.553] INFO: dumping ASCII scurve output file: SCurveData
[22:22:47.753] INFO: PixTestScurves::scurves() done
[22:22:47.753] INFO: Vcal mean: 93.37 81.62 90.37 92.90 84.39 80.49 86.42 92.04 109.46 105.08 101.93 106.37 101.98 101.22 85.06 101.49
[22:22:47.753] INFO: Vcal RMS: 5.30 5.10 5.67 5.81 5.28 4.68 5.06 5.98 5.71 7.05 5.62 5.94 6.25 6.26 5.28 5.77
[22:22:47.753] INFO: PixTestScurves::fullTest() done, duration: 2531 seconds
[22:22:47.857] INFO: ######################################################################
[22:22:47.858] INFO: PixTestTrim::doTest()
[22:22:47.858] INFO: ######################################################################
[22:22:47.859] INFO: ----------------------------------------------------------------------
[22:22:47.859] INFO: PixTestTrim::trimTest() ntrig = 10, vcal = 35
[22:22:47.859] INFO: ----------------------------------------------------------------------
[22:22:48.010] INFO: ---> VthrComp thr map (minimal VthrComp)
[22:22:48.010] INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 5 dacrange: 0 .. 159 (20/-1) hits flags = 16 (plus default)
[22:22:48.025] INFO: dacScan step from 0 .. 19
[22:22:48.025] INFO: dacScan split into 1 runs with ntrig = 5
[22:22:48.025] INFO: run 1 of 1
[22:23:02.272] INFO: Test took 14247ms.
[22:23:02.314] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:23:02.314] INFO: dacScan step from 20 .. 39
[22:23:02.314] INFO: dacScan split into 1 runs with ntrig = 5
[22:23:02.314] INFO: run 1 of 1
[22:23:16.602] INFO: Test took 14288ms.
[22:23:16.643] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:23:16.643] INFO: dacScan step from 40 .. 59
[22:23:16.643] INFO: dacScan split into 1 runs with ntrig = 5
[22:23:16.643] INFO: run 1 of 1
[22:23:30.860] INFO: Test took 14217ms.
[22:23:30.901] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:23:30.901] INFO: dacScan step from 60 .. 79
[22:23:30.901] INFO: dacScan split into 1 runs with ntrig = 5
[22:23:30.901] INFO: run 1 of 1
[22:23:45.071] INFO: Test took 14169ms.
[22:23:45.113] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:23:45.113] INFO: dacScan step from 80 .. 99
[22:23:45.113] INFO: dacScan split into 1 runs with ntrig = 5
[22:23:45.113] INFO: run 1 of 1
[22:23:59.606] INFO: Test took 14493ms.
[22:23:59.681] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:23:59.694] INFO: dacScan step from 100 .. 119
[22:23:59.694] INFO: dacScan split into 1 runs with ntrig = 5
[22:23:59.694] INFO: run 1 of 1
[22:24:16.700] INFO: Test took 17006ms.
[22:24:16.911] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:24:16.959] INFO: dacScan step from 120 .. 139
[22:24:16.959] INFO: dacScan split into 1 runs with ntrig = 5
[22:24:16.959] INFO: run 1 of 1
[22:24:34.745] INFO: Test took 17786ms.
[22:24:35.017] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:24:35.080] INFO: dacScan step from 140 .. 159
[22:24:35.080] INFO: dacScan split into 1 runs with ntrig = 5
[22:24:35.080] INFO: run 1 of 1
[22:24:50.393] INFO: Test took 15313ms.
[22:24:50.595] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:25:26.852] INFO: ROC 0 VthrComp = 97
[22:25:26.852] INFO: ROC 1 VthrComp = 84
[22:25:26.852] INFO: ROC 2 VthrComp = 92
[22:25:26.852] INFO: ROC 3 VthrComp = 97
[22:25:26.852] INFO: ROC 4 VthrComp = 91
[22:25:26.853] INFO: ROC 5 VthrComp = 83
[22:25:26.853] INFO: ROC 6 VthrComp = 88
[22:25:26.853] INFO: ROC 7 VthrComp = 92
[22:25:26.853] INFO: ROC 8 VthrComp = 103
[22:25:26.853] INFO: ROC 9 VthrComp = 97
[22:25:26.854] INFO: ROC 10 VthrComp = 104
[22:25:26.854] INFO: ROC 11 VthrComp = 106
[22:25:26.854] INFO: ROC 12 VthrComp = 100
[22:25:26.854] INFO: ROC 13 VthrComp = 107
[22:25:26.854] INFO: ROC 14 VthrComp = 88
[22:25:26.854] INFO: ROC 15 VthrComp = 103
[22:25:26.854] INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[22:25:26.854] INFO: ---> dac: vcal name: TrimThr1 ntrig: 5 dacrange: 0 .. 159 (20/-1) hits flags = 16 (plus default)
[22:25:26.869] INFO: dacScan step from 0 .. 19
[22:25:26.869] INFO: dacScan split into 1 runs with ntrig = 5
[22:25:26.869] INFO: run 1 of 1
[22:25:41.219] INFO: Test took 14350ms.
[22:25:41.259] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:25:41.259] INFO: dacScan step from 20 .. 39
[22:25:41.259] INFO: dacScan split into 1 runs with ntrig = 5
[22:25:41.259] INFO: run 1 of 1
[22:25:55.518] INFO: Test took 14259ms.
[22:25:55.574] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:25:55.578] INFO: dacScan step from 40 .. 59
[22:25:55.578] INFO: dacScan split into 1 runs with ntrig = 5
[22:25:55.578] INFO: run 1 of 1
[22:26:13.034] INFO: Test took 17456ms.
[22:26:13.269] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:26:13.325] INFO: dacScan step from 60 .. 79
[22:26:13.325] INFO: dacScan split into 1 runs with ntrig = 5
[22:26:13.325] INFO: run 1 of 1
[22:26:32.775] INFO: Test took 19450ms.
[22:26:33.063] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:26:33.133] INFO: dacScan step from 80 .. 99
[22:26:33.133] INFO: dacScan split into 1 runs with ntrig = 5
[22:26:33.133] INFO: run 1 of 1
[22:26:52.766] INFO: Test took 19632ms.
[22:26:53.045] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:26:53.111] INFO: dacScan step from 100 .. 119
[22:26:53.111] INFO: dacScan split into 1 runs with ntrig = 5
[22:26:53.111] INFO: run 1 of 1
[22:27:12.663] INFO: Test took 19551ms.
[22:27:12.965] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:27:13.038] INFO: dacScan step from 120 .. 139
[22:27:13.038] INFO: dacScan split into 1 runs with ntrig = 5
[22:27:13.038] INFO: run 1 of 1
[22:27:32.544] INFO: Test took 19506ms.
[22:27:32.872] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:27:32.953] INFO: dacScan step from 140 .. 159
[22:27:32.953] INFO: dacScan split into 1 runs with ntrig = 5
[22:27:32.953] INFO: run 1 of 1
[22:27:52.524] INFO: Test took 19571ms.
[22:27:52.884] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:28:34.848] INFO: roc 0 with ID = 0 has maximal Vcal 58.3877 for pixel 23/25 mean/min/max = 45.1257/31.7744/58.4771
[22:28:34.849] INFO: roc 1 with ID = 1 has maximal Vcal 61.212 for pixel 1/7 mean/min/max = 46.4067/31.5934/61.22
[22:28:34.850] INFO: roc 2 with ID = 2 has maximal Vcal 60.2072 for pixel 41/1 mean/min/max = 46.0974/31.9373/60.2575
[22:28:34.850] INFO: roc 3 with ID = 3 has maximal Vcal 58.11 for pixel 23/21 mean/min/max = 44.9166/31.6876/58.1455
[22:28:34.851] INFO: roc 4 with ID = 4 has maximal Vcal 58.1436 for pixel 15/70 mean/min/max = 45.1651/32.0282/58.302
[22:28:34.851] INFO: roc 5 with ID = 5 has maximal Vcal 59.0386 for pixel 48/2 mean/min/max = 45.6694/32.1769/59.162
[22:28:34.852] INFO: roc 6 with ID = 6 has maximal Vcal 58.1245 for pixel 6/2 mean/min/max = 45.6237/32.8098/58.4375
[22:28:34.852] INFO: roc 7 with ID = 7 has maximal Vcal 61.4464 for pixel 22/1 mean/min/max = 46.6456/31.7675/61.5238
[22:28:34.852] INFO: roc 8 with ID = 8 has maximal Vcal 65.3626 for pixel 18/79 mean/min/max = 49.1095/32.71/65.5089
[22:28:34.853] INFO: roc 9 with ID = 9 has maximal Vcal 66.3761 for pixel 15/8 mean/min/max = 49.0629/31.7413/66.3845
[22:28:34.853] INFO: roc 10 with ID = 10 has maximal Vcal 60.9333 for pixel 35/1 mean/min/max = 47.314/33.6677/60.9604
[22:28:34.854] INFO: roc 11 with ID = 11 has maximal Vcal 63.2369 for pixel 34/71 mean/min/max = 48.0792/32.8436/63.3148
[22:28:34.854] INFO: roc 12 with ID = 12 has maximal Vcal 61.4835 for pixel 8/16 mean/min/max = 46.7807/31.9549/61.6065
[22:28:34.855] INFO: roc 13 with ID = 13 has maximal Vcal 61.9232 for pixel 0/8 mean/min/max = 47.4268/32.915/61.9387
[22:28:34.855] INFO: roc 14 with ID = 14 has maximal Vcal 60.4178 for pixel 14/30 mean/min/max = 46.7694/33.1128/60.426
[22:28:34.855] INFO: roc 15 with ID = 15 has maximal Vcal 61.1206 for pixel 29/1 mean/min/max = 46.9102/32.5813/61.2392
[22:28:34.856] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[22:29:56.825] INFO: Test took 81969ms.
[22:29:58.957] INFO: ---> dac: vcal name: TrimThr2 ntrig: 10 dacrange: 0 .. 199 (20/5) hits flags = 16 (plus default)
[22:29:58.973] INFO: dacScan step from 0 .. 19
[22:29:58.973] INFO: dacScan split into 2 runs with ntrig = 5
[22:29:58.973] INFO: run 1 of 2
[22:30:13.334] INFO: Test took 14361ms.
[22:30:13.384] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:30:13.389] INFO: run 2 of 2
[22:30:27.774] INFO: Test took 14385ms.
[22:30:27.827] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:30:27.832] INFO: dacScan step from 20 .. 39
[22:30:27.832] INFO: dacScan split into 2 runs with ntrig = 5
[22:30:27.832] INFO: run 1 of 2
[22:30:44.735] INFO: Test took 16903ms.
[22:30:45.019] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:30:45.069] INFO: run 2 of 2
[22:31:01.882] INFO: Test took 16812ms.
[22:31:02.110] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:31:02.162] INFO: dacScan step from 40 .. 59
[22:31:02.162] INFO: dacScan split into 2 runs with ntrig = 5
[22:31:02.162] INFO: run 1 of 2
[22:31:21.607] INFO: Test took 19444ms.
[22:31:21.919] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:31:21.986] INFO: run 2 of 2
[22:31:41.355] INFO: Test took 19369ms.
[22:31:41.754] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:31:41.832] INFO: dacScan step from 60 .. 79
[22:31:41.832] INFO: dacScan split into 2 runs with ntrig = 5
[22:31:41.832] INFO: run 1 of 2
[22:32:01.323] INFO: Test took 19491ms.
[22:32:01.701] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:32:01.772] INFO: run 2 of 2
[22:32:21.342] INFO: Test took 19570ms.
[22:32:21.619] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:32:21.692] INFO: dacScan step from 80 .. 99
[22:32:21.692] INFO: dacScan split into 2 runs with ntrig = 5
[22:32:21.692] INFO: run 1 of 2
[22:32:41.249] INFO: Test took 19557ms.
[22:32:41.527] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:32:41.595] INFO: run 2 of 2
[22:33:01.199] INFO: Test took 19604ms.
[22:33:01.488] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:33:01.560] INFO: dacScan step from 100 .. 119
[22:33:01.560] INFO: dacScan split into 2 runs with ntrig = 5
[22:33:01.560] INFO: run 1 of 2
[22:33:21.155] INFO: Test took 19595ms.
[22:33:21.444] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:33:21.518] INFO: run 2 of 2
[22:33:41.091] INFO: Test took 19573ms.
[22:33:41.365] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:33:41.437] INFO: dacScan step from 120 .. 139
[22:33:41.437] INFO: dacScan split into 2 runs with ntrig = 5
[22:33:41.437] INFO: run 1 of 2
[22:34:00.990] INFO: Test took 19553ms.
[22:34:01.269] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:34:01.340] INFO: run 2 of 2
[22:34:20.987] INFO: Test took 19647ms.
[22:34:21.271] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:34:21.341] INFO: dacScan step from 140 .. 159
[22:34:21.341] INFO: dacScan split into 2 runs with ntrig = 5
[22:34:21.341] INFO: run 1 of 2
[22:34:40.958] INFO: Test took 19617ms.
[22:34:41.263] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:34:41.329] INFO: run 2 of 2
[22:35:01.027] INFO: Test took 19698ms.
[22:35:01.334] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:35:01.407] INFO: dacScan step from 160 .. 179
[22:35:01.407] INFO: dacScan split into 2 runs with ntrig = 5
[22:35:01.407] INFO: run 1 of 2
[22:35:21.329] INFO: Test took 19922ms.
[22:35:21.622] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:35:21.697] INFO: run 2 of 2
[22:35:41.496] INFO: Test took 19799ms.
[22:35:41.816] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:35:41.889] INFO: dacScan step from 180 .. 199
[22:35:41.889] INFO: dacScan split into 2 runs with ntrig = 5
[22:35:41.889] INFO: run 1 of 2
[22:36:02.365] INFO: Test took 20476ms.
[22:36:02.705] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:36:02.786] INFO: run 2 of 2
[22:36:23.460] INFO: Test took 20674ms.
[22:36:23.787] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:37:06.403] INFO: ---> TrimStepCorr4 extremal thresholds: 0.062019 .. 255.000000
[22:37:06.559] INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 4 dacrange: 0 .. 255 (20/-1) hits flags = 16 (plus default)
[22:37:06.573] INFO: dacScan step from 0 .. 19
[22:37:06.573] INFO: dacScan split into 1 runs with ntrig = 4
[22:37:06.573] INFO: run 1 of 1
[22:37:19.451] INFO: Test took 12878ms.
[22:37:19.489] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:37:19.489] INFO: dacScan step from 20 .. 39
[22:37:19.489] INFO: dacScan split into 1 runs with ntrig = 4
[22:37:19.489] INFO: run 1 of 1
[22:37:33.297] INFO: Test took 13808ms.
[22:37:33.428] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:37:33.462] INFO: dacScan step from 40 .. 59
[22:37:33.462] INFO: dacScan split into 1 runs with ntrig = 4
[22:37:33.462] INFO: run 1 of 1
[22:37:50.453] INFO: Test took 16991ms.
[22:37:50.698] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:37:50.770] INFO: dacScan step from 60 .. 79
[22:37:50.770] INFO: dacScan split into 1 runs with ntrig = 4
[22:37:50.770] INFO: run 1 of 1
[22:38:07.997] INFO: Test took 17227ms.
[22:38:08.252] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:38:08.326] INFO: dacScan step from 80 .. 99
[22:38:08.326] INFO: dacScan split into 1 runs with ntrig = 4
[22:38:08.326] INFO: run 1 of 1
[22:38:25.431] INFO: Test took 17105ms.
[22:38:25.700] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:38:25.770] INFO: dacScan step from 100 .. 119
[22:38:25.770] INFO: dacScan split into 1 runs with ntrig = 4
[22:38:25.770] INFO: run 1 of 1
[22:38:42.920] INFO: Test took 17150ms.
[22:38:43.172] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:38:43.247] INFO: dacScan step from 120 .. 139
[22:38:43.247] INFO: dacScan split into 1 runs with ntrig = 4
[22:38:43.247] INFO: run 1 of 1
[22:39:00.423] INFO: Test took 17176ms.
[22:39:00.676] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:39:00.752] INFO: dacScan step from 140 .. 159
[22:39:00.752] INFO: dacScan split into 1 runs with ntrig = 4
[22:39:00.752] INFO: run 1 of 1
[22:39:17.846] INFO: Test took 17094ms.
[22:39:18.104] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:39:18.176] INFO: dacScan step from 160 .. 179
[22:39:18.176] INFO: dacScan split into 1 runs with ntrig = 4
[22:39:18.176] INFO: run 1 of 1
[22:39:35.482] INFO: Test took 17306ms.
[22:39:35.742] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:39:35.813] INFO: dacScan step from 180 .. 199
[22:39:35.813] INFO: dacScan split into 1 runs with ntrig = 4
[22:39:35.813] INFO: run 1 of 1
[22:39:53.818] INFO: Test took 18004ms.
[22:39:54.099] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:39:54.179] INFO: dacScan step from 200 .. 219
[22:39:54.179] INFO: dacScan split into 1 runs with ntrig = 4
[22:39:54.179] INFO: run 1 of 1
[22:40:11.325] INFO: Test took 17146ms.
[22:40:11.609] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:40:11.692] INFO: dacScan step from 220 .. 239
[22:40:11.692] INFO: dacScan split into 1 runs with ntrig = 4
[22:40:11.692] INFO: run 1 of 1
[22:40:28.903] INFO: Test took 17211ms.
[22:40:29.255] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:40:29.342] INFO: dacScan step from 240 .. 255
[22:40:29.342] INFO: dacScan split into 1 runs with ntrig = 4
[22:40:29.342] INFO: run 1 of 1
[22:40:43.877] INFO: Test took 14535ms.
[22:40:44.104] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:41:36.884] INFO: ---> TrimStepCorr2 extremal thresholds: 16.291887 .. 60.510956
[22:41:37.032] INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 4 dacrange: 6 .. 70 (20/-1) hits flags = 16 (plus default)
[22:41:37.046] INFO: dacScan step from 6 .. 25
[22:41:37.046] INFO: dacScan split into 1 runs with ntrig = 4
[22:41:37.046] INFO: run 1 of 1
[22:41:50.017] INFO: Test took 12971ms.
[22:41:50.058] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:41:50.058] INFO: dacScan step from 26 .. 45
[22:41:50.058] INFO: dacScan split into 1 runs with ntrig = 4
[22:41:50.058] INFO: run 1 of 1
[22:42:05.094] INFO: Test took 15036ms.
[22:42:05.302] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:42:05.357] INFO: dacScan step from 46 .. 65
[22:42:05.357] INFO: dacScan split into 1 runs with ntrig = 4
[22:42:05.357] INFO: run 1 of 1
[22:42:22.682] INFO: Test took 17324ms.
[22:42:22.972] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:42:23.052] INFO: dacScan step from 66 .. 70
[22:42:23.052] INFO: dacScan split into 1 runs with ntrig = 4
[22:42:23.052] INFO: run 1 of 1
[22:42:29.773] INFO: Test took 6720ms.
[22:42:29.846] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:42:58.708] INFO: ---> TrimStepCorr1a extremal thresholds: 2.089776 .. 60.510956
[22:42:58.853] INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 4 dacrange: 2 .. 70 (20/-1) hits flags = 16 (plus default)
[22:42:58.868] INFO: dacScan step from 2 .. 21
[22:42:58.868] INFO: dacScan split into 1 runs with ntrig = 4
[22:42:58.868] INFO: run 1 of 1
[22:43:11.778] INFO: Test took 12910ms.
[22:43:11.814] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:43:11.814] INFO: dacScan step from 22 .. 41
[22:43:11.814] INFO: dacScan split into 1 runs with ntrig = 4
[22:43:11.814] INFO: run 1 of 1
[22:43:26.144] INFO: Test took 14330ms.
[22:43:26.308] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:43:26.352] INFO: dacScan step from 42 .. 61
[22:43:26.352] INFO: dacScan split into 1 runs with ntrig = 4
[22:43:26.352] INFO: run 1 of 1
[22:43:43.800] INFO: Test took 17448ms.
[22:43:44.096] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:43:44.178] INFO: dacScan step from 62 .. 70
[22:43:44.178] INFO: dacScan split into 1 runs with ntrig = 4
[22:43:44.178] INFO: run 1 of 1
[22:43:53.840] INFO: Test took 9662ms.
[22:43:53.961] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:44:22.294] INFO: ---> TrimStepCorr1b extremal thresholds: 2.089776 .. 60.510956
[22:44:22.439] INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 4 dacrange: 2 .. 70 (20/-1) hits flags = 16 (plus default)
[22:44:22.455] INFO: dacScan step from 2 .. 21
[22:44:22.455] INFO: dacScan split into 1 runs with ntrig = 4
[22:44:22.455] INFO: run 1 of 1
[22:44:35.402] INFO: Test took 12947ms.
[22:44:35.437] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:44:35.437] INFO: dacScan step from 22 .. 41
[22:44:35.437] INFO: dacScan split into 1 runs with ntrig = 4
[22:44:35.437] INFO: run 1 of 1
[22:44:49.583] INFO: Test took 14146ms.
[22:44:49.734] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:44:49.773] INFO: dacScan step from 42 .. 61
[22:44:49.773] INFO: dacScan split into 1 runs with ntrig = 4
[22:44:49.773] INFO: run 1 of 1
[22:45:06.951] INFO: Test took 17178ms.
[22:45:07.236] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:45:07.318] INFO: dacScan step from 62 .. 70
[22:45:07.318] INFO: dacScan split into 1 runs with ntrig = 4
[22:45:07.318] INFO: run 1 of 1
[22:45:16.976] INFO: Test took 9658ms.
[22:45:17.105] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:45:45.729] INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[22:45:45.729] INFO: ---> dac: vcal name: TrimThrFinal ntrig: 10 dacrange: 15 .. 55 (20/5) hits flags = 16 (plus default)
[22:45:45.743] INFO: dacScan step from 15 .. 34
[22:45:45.743] INFO: dacScan split into 2 runs with ntrig = 5
[22:45:45.743] INFO: run 1 of 2
[22:46:00.139] INFO: Test took 14396ms.
[22:46:00.221] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:46:00.239] INFO: run 2 of 2
[22:46:14.674] INFO: Test took 14434ms.
[22:46:14.745] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:46:14.760] INFO: dacScan step from 35 .. 54
[22:46:14.760] INFO: dacScan split into 2 runs with ntrig = 5
[22:46:14.760] INFO: run 1 of 2
[22:46:33.883] INFO: Test took 19123ms.
[22:46:34.216] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:46:34.295] INFO: run 2 of 2
[22:46:53.630] INFO: Test took 19335ms.
[22:46:53.929] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:46:53.002] INFO: dacScan step from 55 .. 55
[22:46:53.002] INFO: dacScan split into 2 runs with ntrig = 5
[22:46:53.002] INFO: run 1 of 2
[22:46:57.989] INFO: Test took 3987ms.
[22:46:58.008] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:46:58.015] INFO: run 2 of 2
[22:47:02.006] INFO: Test took 3991ms.
[22:47:02.031] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:47:22.595] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/dacParameters35_C0.dat
[22:47:22.595] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/dacParameters35_C1.dat
[22:47:22.595] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/dacParameters35_C2.dat
[22:47:22.595] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/dacParameters35_C3.dat
[22:47:22.596] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/dacParameters35_C4.dat
[22:47:22.596] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/dacParameters35_C5.dat
[22:47:22.596] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/dacParameters35_C6.dat
[22:47:22.596] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/dacParameters35_C7.dat
[22:47:22.596] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/dacParameters35_C8.dat
[22:47:22.597] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/dacParameters35_C9.dat
[22:47:22.597] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/dacParameters35_C10.dat
[22:47:22.597] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/dacParameters35_C11.dat
[22:47:22.597] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/dacParameters35_C12.dat
[22:47:22.598] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/dacParameters35_C13.dat
[22:47:22.598] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/dacParameters35_C14.dat
[22:47:22.598] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/dacParameters35_C15.dat
[22:47:22.599] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/trimParameters35_C0.dat
[22:47:22.611] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/trimParameters35_C1.dat
[22:47:22.621] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/trimParameters35_C2.dat
[22:47:22.630] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/trimParameters35_C3.dat
[22:47:22.639] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/trimParameters35_C4.dat
[22:47:22.650] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/trimParameters35_C5.dat
[22:47:22.659] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/trimParameters35_C6.dat
[22:47:22.668] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/trimParameters35_C7.dat
[22:47:22.678] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/trimParameters35_C8.dat
[22:47:22.687] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/trimParameters35_C9.dat
[22:47:22.697] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/trimParameters35_C10.dat
[22:47:22.706] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/trimParameters35_C11.dat
[22:47:22.717] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/trimParameters35_C12.dat
[22:47:22.726] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/trimParameters35_C13.dat
[22:47:22.736] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/trimParameters35_C14.dat
[22:47:22.746] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/trimParameters35_C15.dat
[22:47:22.756] INFO: PixTestTrim::trimTest() done
[22:47:22.756] INFO: vtrim: 114 116 107 120 116 96 102 106 121 105 118 119 119 123 115 119
[22:47:22.756] INFO: vthrcomp: 97 84 92 97 91 83 88 92 103 97 104 106 100 107 88 103
[22:47:22.756] INFO: vcal mean: 35.09 35.04 35.04 35.00 35.02 35.11 35.04 35.03 35.12 35.13 35.09 35.09 35.07 35.08 35.08 35.08
[22:47:22.756] INFO: vcal RMS: 1.16 1.33 1.26 1.40 1.31 1.07 1.03 1.12 1.24 1.24 1.11 1.11 1.25 1.03 1.15 1.07
[22:47:22.756] INFO: bits mean: 10.36 10.18 9.58 10.30 10.01 10.11 9.81 9.10 9.11 9.51 9.43 9.41 9.82 8.87 9.79 9.49
[22:47:22.756] INFO: bits RMS: 2.31 2.32 2.61 2.38 2.44 2.40 2.48 2.85 2.54 2.42 2.39 2.48 2.43 2.66 2.36 2.49
[22:47:22.767] INFO: ----------------------------------------------------------------------
[22:47:22.767] INFO: PixTestTrim::trimBitTest() ntrig = 10, vtrims = 254 126 63 32
[22:47:22.767] INFO: ----------------------------------------------------------------------
[22:47:22.771] INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 10 dacrange: 0 .. 199 (20/5) hits flags = 16 (plus default)
[22:47:22.790] INFO: dacScan step from 0 .. 19
[22:47:22.790] INFO: dacScan split into 2 runs with ntrig = 5
[22:47:22.790] INFO: run 1 of 2
[22:47:37.045] INFO: Test took 14255ms.
[22:47:37.083] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:47:37.083] INFO: run 2 of 2
[22:47:51.275] INFO: Test took 14192ms.
[22:47:51.316] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:47:51.316] INFO: dacScan step from 20 .. 39
[22:47:51.316] INFO: dacScan split into 2 runs with ntrig = 5
[22:47:51.316] INFO: run 1 of 2
[22:48:05.536] INFO: Test took 14220ms.
[22:48:05.576] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:48:05.576] INFO: run 2 of 2
[22:48:19.842] INFO: Test took 14266ms.
[22:48:19.883] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:48:19.883] INFO: dacScan step from 40 .. 59
[22:48:19.883] INFO: dacScan split into 2 runs with ntrig = 5
[22:48:19.883] INFO: run 1 of 2
[22:48:34.179] INFO: Test took 14296ms.
[22:48:34.220] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:48:34.220] INFO: run 2 of 2
[22:48:48.343] INFO: Test took 14123ms.
[22:48:48.388] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:48:48.388] INFO: dacScan step from 60 .. 79
[22:48:48.388] INFO: dacScan split into 2 runs with ntrig = 5
[22:48:48.388] INFO: run 1 of 2
[22:49:02.546] INFO: Test took 14158ms.
[22:49:02.586] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:49:02.586] INFO: run 2 of 2
[22:49:16.901] INFO: Test took 14315ms.
[22:49:16.938] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:49:16.938] INFO: dacScan step from 80 .. 99
[22:49:16.938] INFO: dacScan split into 2 runs with ntrig = 5
[22:49:16.938] INFO: run 1 of 2
[22:49:31.059] INFO: Test took 14121ms.
[22:49:31.101] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:49:31.103] INFO: run 2 of 2
[22:49:45.200] INFO: Test took 14097ms.
[22:49:45.247] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:49:45.248] INFO: dacScan step from 100 .. 119
[22:49:45.248] INFO: dacScan split into 2 runs with ntrig = 5
[22:49:45.248] INFO: run 1 of 2
[22:50:00.482] INFO: Test took 15234ms.
[22:50:00.618] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:50:00.639] INFO: run 2 of 2
[22:50:15.992] INFO: Test took 15353ms.
[22:50:16.132] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:50:16.153] INFO: dacScan step from 120 .. 139
[22:50:16.153] INFO: dacScan split into 2 runs with ntrig = 5
[22:50:16.153] INFO: run 1 of 2
[22:50:34.194] INFO: Test took 18041ms.
[22:50:34.430] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:50:34.488] INFO: run 2 of 2
[22:50:52.472] INFO: Test took 17984ms.
[22:50:52.734] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:50:52.795] INFO: dacScan step from 140 .. 159
[22:50:52.795] INFO: dacScan split into 2 runs with ntrig = 5
[22:50:52.795] INFO: run 1 of 2
[22:51:12.183] INFO: Test took 19388ms.
[22:51:12.499] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:51:12.582] INFO: run 2 of 2
[22:51:31.947] INFO: Test took 19365ms.
[22:51:32.253] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:51:32.336] INFO: dacScan step from 160 .. 179
[22:51:32.336] INFO: dacScan split into 2 runs with ntrig = 5
[22:51:32.336] INFO: run 1 of 2
[22:51:52.192] INFO: Test took 19856ms.
[22:51:52.526] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:51:52.607] INFO: run 2 of 2
[22:52:12.452] INFO: Test took 19845ms.
[22:52:12.774] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:52:12.851] INFO: dacScan step from 180 .. 199
[22:52:12.851] INFO: dacScan split into 2 runs with ntrig = 5
[22:52:12.851] INFO: run 1 of 2
[22:52:33.601] INFO: Test took 20750ms.
[22:52:33.944] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:52:34.022] INFO: run 2 of 2
[22:52:54.594] INFO: Test took 20572ms.
[22:52:54.948] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:53:37.103] INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 10 dacrange: 0 .. 206 (20/5) hits flags = 16 (plus default)
[22:53:37.120] INFO: dacScan step from 0 .. 19
[22:53:37.120] INFO: dacScan split into 2 runs with ntrig = 5
[22:53:37.120] INFO: run 1 of 2
[22:53:51.428] INFO: Test took 14308ms.
[22:53:51.471] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:53:51.471] INFO: run 2 of 2
[22:54:05.692] INFO: Test took 14221ms.
[22:54:05.735] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:54:05.735] INFO: dacScan step from 20 .. 39
[22:54:05.735] INFO: dacScan split into 2 runs with ntrig = 5
[22:54:05.735] INFO: run 1 of 2
[22:54:19.953] INFO: Test took 14218ms.
[22:54:19.997] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:54:19.997] INFO: run 2 of 2
[22:54:34.180] INFO: Test took 14183ms.
[22:54:34.224] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:54:34.224] INFO: dacScan step from 40 .. 59
[22:54:34.224] INFO: dacScan split into 2 runs with ntrig = 5
[22:54:34.224] INFO: run 1 of 2
[22:54:48.423] INFO: Test took 14199ms.
[22:54:48.465] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:54:48.465] INFO: run 2 of 2
[22:55:02.580] INFO: Test took 14115ms.
[22:55:02.625] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:55:02.625] INFO: dacScan step from 60 .. 79
[22:55:02.625] INFO: dacScan split into 2 runs with ntrig = 5
[22:55:02.625] INFO: run 1 of 2
[22:55:16.623] INFO: Test took 13998ms.
[22:55:16.667] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:55:16.667] INFO: run 2 of 2
[22:55:30.837] INFO: Test took 14170ms.
[22:55:30.882] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:55:30.882] INFO: dacScan step from 80 .. 99
[22:55:30.882] INFO: dacScan split into 2 runs with ntrig = 5
[22:55:30.882] INFO: run 1 of 2
[22:55:45.289] INFO: Test took 14407ms.
[22:55:45.363] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:55:45.371] INFO: run 2 of 2
[22:55:59.791] INFO: Test took 14420ms.
[22:55:59.867] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:55:59.876] INFO: dacScan step from 100 .. 119
[22:55:59.876] INFO: dacScan split into 2 runs with ntrig = 5
[22:55:59.876] INFO: run 1 of 2
[22:56:16.338] INFO: Test took 16462ms.
[22:56:16.536] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:56:16.578] INFO: run 2 of 2
[22:56:33.083] INFO: Test took 16505ms.
[22:56:33.346] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:56:33.400] INFO: dacScan step from 120 .. 139
[22:56:33.400] INFO: dacScan split into 2 runs with ntrig = 5
[22:56:33.400] INFO: run 1 of 2
[22:56:52.432] INFO: Test took 19031ms.
[22:56:52.739] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:56:52.818] INFO: run 2 of 2
[22:57:11.828] INFO: Test took 19009ms.
[22:57:12.088] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:57:12.155] INFO: dacScan step from 140 .. 159
[22:57:12.155] INFO: dacScan split into 2 runs with ntrig = 5
[22:57:12.155] INFO: run 1 of 2
[22:57:31.793] INFO: Test took 19638ms.
[22:57:32.119] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:57:32.199] INFO: run 2 of 2
[22:57:51.732] INFO: Test took 19533ms.
[22:57:52.063] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:57:52.145] INFO: dacScan step from 160 .. 179
[22:57:52.145] INFO: dacScan split into 2 runs with ntrig = 5
[22:57:52.145] INFO: run 1 of 2
[22:58:12.074] INFO: Test took 19929ms.
[22:58:12.403] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:58:12.482] INFO: run 2 of 2
[22:58:32.436] INFO: Test took 19954ms.
[22:58:32.729] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:58:32.802] INFO: dacScan step from 180 .. 199
[22:58:32.802] INFO: dacScan split into 2 runs with ntrig = 5
[22:58:32.802] INFO: run 1 of 2
[22:58:53.411] INFO: Test took 20608ms.
[22:58:53.733] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:58:53.808] INFO: run 2 of 2
[22:59:14.501] INFO: Test took 20692ms.
[22:59:14.807] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:59:14.879] INFO: dacScan step from 200 .. 206
[22:59:14.880] INFO: dacScan split into 2 runs with ntrig = 5
[22:59:14.880] INFO: run 1 of 2
[22:59:23.764] INFO: Test took 8884ms.
[22:59:23.866] INFO: Fetched DAQ statistics. Counters are being reset now.
[22:59:23.894] INFO: run 2 of 2
[22:59:32.758] INFO: Test took 8864ms.
[22:59:32.852] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:00:13.495] INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 10 dacrange: 0 .. 192 (20/5) hits flags = 16 (plus default)
[23:00:13.510] INFO: dacScan step from 0 .. 19
[23:00:13.510] INFO: dacScan split into 2 runs with ntrig = 5
[23:00:13.510] INFO: run 1 of 2
[23:00:27.632] INFO: Test took 14121ms.
[23:00:27.672] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:00:27.672] INFO: run 2 of 2
[23:00:41.827] INFO: Test took 14154ms.
[23:00:41.869] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:00:41.869] INFO: dacScan step from 20 .. 39
[23:00:41.869] INFO: dacScan split into 2 runs with ntrig = 5
[23:00:41.869] INFO: run 1 of 2
[23:00:56.106] INFO: Test took 14237ms.
[23:00:56.151] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:00:56.151] INFO: run 2 of 2
[23:01:10.245] INFO: Test took 14094ms.
[23:01:10.288] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:01:10.288] INFO: dacScan step from 40 .. 59
[23:01:10.288] INFO: dacScan split into 2 runs with ntrig = 5
[23:01:10.288] INFO: run 1 of 2
[23:01:24.423] INFO: Test took 14134ms.
[23:01:24.469] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:01:24.469] INFO: run 2 of 2
[23:01:38.529] INFO: Test took 14060ms.
[23:01:38.579] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:01:38.579] INFO: dacScan step from 60 .. 79
[23:01:38.579] INFO: dacScan split into 2 runs with ntrig = 5
[23:01:38.579] INFO: run 1 of 2
[23:01:52.668] INFO: Test took 14089ms.
[23:01:52.714] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:01:52.714] INFO: run 2 of 2
[23:02:06.910] INFO: Test took 14196ms.
[23:02:06.952] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:02:06.952] INFO: dacScan step from 80 .. 99
[23:02:06.952] INFO: dacScan split into 2 runs with ntrig = 5
[23:02:06.952] INFO: run 1 of 2
[23:02:21.253] INFO: Test took 14301ms.
[23:02:21.325] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:02:21.330] INFO: run 2 of 2
[23:02:35.536] INFO: Test took 14206ms.
[23:02:35.620] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:02:35.626] INFO: dacScan step from 100 .. 119
[23:02:35.626] INFO: dacScan split into 2 runs with ntrig = 5
[23:02:35.626] INFO: run 1 of 2
[23:02:52.100] INFO: Test took 16474ms.
[23:02:52.320] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:02:52.364] INFO: run 2 of 2
[23:03:08.953] INFO: Test took 16589ms.
[23:03:09.184] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:03:09.229] INFO: dacScan step from 120 .. 139
[23:03:09.229] INFO: dacScan split into 2 runs with ntrig = 5
[23:03:09.229] INFO: run 1 of 2
[23:03:28.360] INFO: Test took 19131ms.
[23:03:28.669] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:03:28.745] INFO: run 2 of 2
[23:03:47.953] INFO: Test took 19208ms.
[23:03:48.207] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:03:48.276] INFO: dacScan step from 140 .. 159
[23:03:48.276] INFO: dacScan split into 2 runs with ntrig = 5
[23:03:48.276] INFO: run 1 of 2
[23:04:08.045] INFO: Test took 19769ms.
[23:04:08.337] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:04:08.403] INFO: run 2 of 2
[23:04:27.878] INFO: Test took 19475ms.
[23:04:28.189] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:04:28.266] INFO: dacScan step from 160 .. 179
[23:04:28.266] INFO: dacScan split into 2 runs with ntrig = 5
[23:04:28.266] INFO: run 1 of 2
[23:04:48.127] INFO: Test took 19861ms.
[23:04:48.427] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:04:48.492] INFO: run 2 of 2
[23:05:08.235] INFO: Test took 19743ms.
[23:05:08.624] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:05:08.694] INFO: dacScan step from 180 .. 192
[23:05:08.694] INFO: dacScan split into 2 runs with ntrig = 5
[23:05:08.694] INFO: run 1 of 2
[23:05:23.258] INFO: Test took 14564ms.
[23:05:23.453] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:05:23.498] INFO: run 2 of 2
[23:05:38.215] INFO: Test took 14717ms.
[23:05:38.395] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:06:17.858] INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 10 dacrange: 0 .. 199 (20/5) hits flags = 16 (plus default)
[23:06:17.873] INFO: dacScan step from 0 .. 19
[23:06:17.873] INFO: dacScan split into 2 runs with ntrig = 5
[23:06:17.873] INFO: run 1 of 2
[23:06:32.283] INFO: Test took 14409ms.
[23:06:32.328] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:06:32.328] INFO: run 2 of 2
[23:06:46.593] INFO: Test took 14264ms.
[23:06:46.642] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:06:46.642] INFO: dacScan step from 20 .. 39
[23:06:46.642] INFO: dacScan split into 2 runs with ntrig = 5
[23:06:46.642] INFO: run 1 of 2
[23:07:00.835] INFO: Test took 14193ms.
[23:07:00.876] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:07:00.876] INFO: run 2 of 2
[23:07:15.166] INFO: Test took 14290ms.
[23:07:15.205] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:07:15.205] INFO: dacScan step from 40 .. 59
[23:07:15.205] INFO: dacScan split into 2 runs with ntrig = 5
[23:07:15.205] INFO: run 1 of 2
[23:07:29.552] INFO: Test took 14347ms.
[23:07:29.595] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:07:29.595] INFO: run 2 of 2
[23:07:43.736] INFO: Test took 14141ms.
[23:07:43.780] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:07:43.780] INFO: dacScan step from 60 .. 79
[23:07:43.780] INFO: dacScan split into 2 runs with ntrig = 5
[23:07:43.780] INFO: run 1 of 2
[23:07:58.014] INFO: Test took 14234ms.
[23:07:58.061] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:07:58.061] INFO: run 2 of 2
[23:08:12.266] INFO: Test took 14205ms.
[23:08:12.312] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:08:12.312] INFO: dacScan step from 80 .. 99
[23:08:12.312] INFO: dacScan split into 2 runs with ntrig = 5
[23:08:12.312] INFO: run 1 of 2
[23:08:26.867] INFO: Test took 14554ms.
[23:08:26.960] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:08:26.966] INFO: run 2 of 2
[23:08:41.401] INFO: Test took 14434ms.
[23:08:41.473] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:08:41.478] INFO: dacScan step from 100 .. 119
[23:08:41.478] INFO: dacScan split into 2 runs with ntrig = 5
[23:08:41.478] INFO: run 1 of 2
[23:08:58.199] INFO: Test took 16721ms.
[23:08:58.407] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:08:58.452] INFO: run 2 of 2
[23:09:15.261] INFO: Test took 16809ms.
[23:09:15.463] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:09:15.503] INFO: dacScan step from 120 .. 139
[23:09:15.503] INFO: dacScan split into 2 runs with ntrig = 5
[23:09:15.503] INFO: run 1 of 2
[23:09:34.741] INFO: Test took 19238ms.
[23:09:35.032] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:09:35.106] INFO: run 2 of 2
[23:09:54.346] INFO: Test took 19240ms.
[23:09:54.632] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:09:54.700] INFO: dacScan step from 140 .. 159
[23:09:54.700] INFO: dacScan split into 2 runs with ntrig = 5
[23:09:54.700] INFO: run 1 of 2
[23:10:14.398] INFO: Test took 19698ms.
[23:10:14.693] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:10:14.774] INFO: run 2 of 2
[23:10:34.358] INFO: Test took 19584ms.
[23:10:34.644] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:10:34.717] INFO: dacScan step from 160 .. 179
[23:10:34.717] INFO: dacScan split into 2 runs with ntrig = 5
[23:10:34.717] INFO: run 1 of 2
[23:10:54.621] INFO: Test took 19904ms.
[23:10:54.930] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:10:54.997] INFO: run 2 of 2
[23:11:14.666] INFO: Test took 19669ms.
[23:11:14.988] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:11:15.067] INFO: dacScan step from 180 .. 199
[23:11:15.067] INFO: dacScan split into 2 runs with ntrig = 5
[23:11:15.067] INFO: run 1 of 2
[23:11:35.587] INFO: Test took 20520ms.
[23:11:35.908] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:11:35.985] INFO: run 2 of 2
[23:11:56.657] INFO: Test took 20672ms.
[23:11:56.964] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:12:38.619] INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 10 dacrange: 0 .. 191 (20/5) hits flags = 16 (plus default)
[23:12:38.634] INFO: dacScan step from 0 .. 19
[23:12:38.634] INFO: dacScan split into 2 runs with ntrig = 5
[23:12:38.634] INFO: run 1 of 2
[23:12:52.768] INFO: Test took 14133ms.
[23:12:52.816] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:12:52.816] INFO: run 2 of 2
[23:13:07.033] INFO: Test took 14217ms.
[23:13:07.074] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:13:07.074] INFO: dacScan step from 20 .. 39
[23:13:07.074] INFO: dacScan split into 2 runs with ntrig = 5
[23:13:07.074] INFO: run 1 of 2
[23:13:21.179] INFO: Test took 14105ms.
[23:13:21.226] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:13:21.226] INFO: run 2 of 2
[23:13:35.431] INFO: Test took 14204ms.
[23:13:35.478] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:13:35.478] INFO: dacScan step from 40 .. 59
[23:13:35.478] INFO: dacScan split into 2 runs with ntrig = 5
[23:13:35.478] INFO: run 1 of 2
[23:13:49.597] INFO: Test took 14118ms.
[23:13:49.642] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:13:49.642] INFO: run 2 of 2
[23:14:03.866] INFO: Test took 14223ms.
[23:14:03.908] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:14:03.908] INFO: dacScan step from 60 .. 79
[23:14:03.908] INFO: dacScan split into 2 runs with ntrig = 5
[23:14:03.908] INFO: run 1 of 2
[23:14:18.288] INFO: Test took 14380ms.
[23:14:18.329] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:14:18.329] INFO: run 2 of 2
[23:14:32.514] INFO: Test took 14184ms.
[23:14:32.553] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:14:32.553] INFO: dacScan step from 80 .. 99
[23:14:32.553] INFO: dacScan split into 2 runs with ntrig = 5
[23:14:32.553] INFO: run 1 of 2
[23:14:46.883] INFO: Test took 14330ms.
[23:14:46.962] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:14:46.970] INFO: run 2 of 2
[23:15:01.313] INFO: Test took 14343ms.
[23:15:01.388] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:15:01.393] INFO: dacScan step from 100 .. 119
[23:15:01.393] INFO: dacScan split into 2 runs with ntrig = 5
[23:15:01.393] INFO: run 1 of 2
[23:15:18.025] INFO: Test took 16632ms.
[23:15:18.239] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:15:18.282] INFO: run 2 of 2
[23:15:34.782] INFO: Test took 16500ms.
[23:15:34.985] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:15:35.027] INFO: dacScan step from 120 .. 139
[23:15:35.027] INFO: dacScan split into 2 runs with ntrig = 5
[23:15:35.027] INFO: run 1 of 2
[23:15:54.143] INFO: Test took 19115ms.
[23:15:54.392] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:15:54.456] INFO: run 2 of 2
[23:16:13.481] INFO: Test took 19025ms.
[23:16:13.732] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:16:13.802] INFO: dacScan step from 140 .. 159
[23:16:13.802] INFO: dacScan split into 2 runs with ntrig = 5
[23:16:13.802] INFO: run 1 of 2
[23:16:33.177] INFO: Test took 19375ms.
[23:16:33.447] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:16:33.518] INFO: run 2 of 2
[23:16:53.094] INFO: Test took 19576ms.
[23:16:53.351] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:16:53.422] INFO: dacScan step from 160 .. 179
[23:16:53.422] INFO: dacScan split into 2 runs with ntrig = 5
[23:16:53.422] INFO: run 1 of 2
[23:17:13.112] INFO: Test took 19690ms.
[23:17:13.470] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:17:13.540] INFO: run 2 of 2
[23:17:33.229] INFO: Test took 19689ms.
[23:17:33.528] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:17:33.604] INFO: dacScan step from 180 .. 191
[23:17:33.604] INFO: dacScan split into 2 runs with ntrig = 5
[23:17:33.604] INFO: run 1 of 2
[23:17:47.268] INFO: Test took 13664ms.
[23:17:47.430] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:17:47.473] INFO: run 2 of 2
[23:18:01.187] INFO: Test took 13714ms.
[23:18:01.350] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:18:41.719] INFO: PixTestTrim::trimBitTest() done
[23:18:41.720] INFO: PixTestTrim::doTest() done, duration: 3353 seconds
[23:18:42.649] INFO: ######################################################################
[23:18:42.649] INFO: PixTestPhOptimization::doTest() Ntrig = 10
[23:18:42.649] INFO: ######################################################################
[23:18:46.360] INFO: Test took 3709ms.
[23:18:46.399] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:18:50.290] INFO: Test took 3688ms.
[23:18:50.420] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:18:54.102] INFO: Test took 3665ms.
[23:18:54.244] INFO: Fetched DAQ statistics. Counters are being reset now.
[23:18:54.255] INFO: The DUT currently contains the following objects:
[23:18:54.255] INFO: 2 TBM Cores tbm08c (2 ON)
[23:18:54.255] INFO: TBM Core alpha (0): 7 registers set
[23:18:54.255] INFO: TBM Core beta (1): 7 registers set
[23:18:54.255] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[23:18:54.255] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:54.256] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:54.256] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:54.256] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:54.256] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:54.256] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:54.256] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:54.256] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:54.256] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:54.256] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:54.256] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:54.256] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:54.256] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:54.256] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:54.256] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:54.256] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:55.355] INFO: Test took 1099ms.
[23:18:55.357] INFO: The DUT currently contains the following objects:
[23:18:55.357] INFO: 2 TBM Cores tbm08c (2 ON)
[23:18:55.357] INFO: TBM Core alpha (0): 7 registers set
[23:18:55.357] INFO: TBM Core beta (1): 7 registers set
[23:18:55.357] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[23:18:55.357] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:55.357] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:55.357] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:55.358] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:55.358] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:55.358] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:55.358] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:55.358] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:55.358] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:55.358] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:55.358] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:55.358] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:55.358] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:55.358] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:55.358] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:55.358] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:56.459] INFO: Test took 1101ms.
[23:18:56.461] INFO: The DUT currently contains the following objects:
[23:18:56.461] INFO: 2 TBM Cores tbm08c (2 ON)
[23:18:56.461] INFO: TBM Core alpha (0): 7 registers set
[23:18:56.461] INFO: TBM Core beta (1): 7 registers set
[23:18:56.461] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[23:18:56.461] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:56.461] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:56.461] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:56.461] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:56.462] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:56.462] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:56.462] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:56.462] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:56.462] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:56.462] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:56.462] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:56.462] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:56.462] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:56.462] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:56.462] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:56.462] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:57.561] INFO: Test took 1099ms.
[23:18:57.562] INFO: The DUT currently contains the following objects:
[23:18:57.562] INFO: 2 TBM Cores tbm08c (2 ON)
[23:18:57.562] INFO: TBM Core alpha (0): 7 registers set
[23:18:57.563] INFO: TBM Core beta (1): 7 registers set
[23:18:57.563] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[23:18:57.563] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:57.563] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:57.563] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:57.563] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:57.563] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:57.563] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:57.563] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:57.563] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:57.563] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:57.563] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:57.563] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:57.563] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:57.563] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:57.563] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:57.563] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:57.563] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:58.665] INFO: Test took 1102ms.
[23:18:58.667] INFO: The DUT currently contains the following objects:
[23:18:58.667] INFO: 2 TBM Cores tbm08c (2 ON)
[23:18:58.667] INFO: TBM Core alpha (0): 7 registers set
[23:18:58.667] INFO: TBM Core beta (1): 7 registers set
[23:18:58.667] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[23:18:58.667] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:58.667] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:58.667] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:58.667] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:58.667] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:58.667] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:58.667] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:58.667] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:58.667] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:58.667] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:58.667] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:58.667] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:58.667] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:58.667] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:58.667] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:58.667] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:59.764] INFO: Test took 1097ms.
[23:18:59.767] INFO: The DUT currently contains the following objects:
[23:18:59.767] INFO: 2 TBM Cores tbm08c (2 ON)
[23:18:59.767] INFO: TBM Core alpha (0): 7 registers set
[23:18:59.767] INFO: TBM Core beta (1): 7 registers set
[23:18:59.767] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[23:18:59.767] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:59.767] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:59.767] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:59.767] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:59.767] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:59.767] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:59.767] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:59.767] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:59.767] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:59.767] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:59.767] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:59.767] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:59.767] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:59.767] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:59.767] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:18:59.767] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:00.869] INFO: Test took 1102ms.
[23:19:00.870] INFO: The DUT currently contains the following objects:
[23:19:00.870] INFO: 2 TBM Cores tbm08c (2 ON)
[23:19:00.870] INFO: TBM Core alpha (0): 7 registers set
[23:19:00.870] INFO: TBM Core beta (1): 7 registers set
[23:19:00.870] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[23:19:00.870] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:00.870] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:00.870] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:00.871] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:00.871] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:00.871] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:00.871] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:00.871] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:00.871] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:00.871] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:00.871] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:00.871] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:00.871] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:00.871] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:00.871] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:00.871] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:01.972] INFO: Test took 1101ms.
[23:19:01.974] INFO: The DUT currently contains the following objects:
[23:19:01.974] INFO: 2 TBM Cores tbm08c (2 ON)
[23:19:01.974] INFO: TBM Core alpha (0): 7 registers set
[23:19:01.974] INFO: TBM Core beta (1): 7 registers set
[23:19:01.974] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[23:19:01.974] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:01.974] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:01.975] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:01.975] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:01.975] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:01.975] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:01.975] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:01.975] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:01.975] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:01.975] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:01.975] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:01.975] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:01.975] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:01.975] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:01.975] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:01.975] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:03.071] INFO: Test took 1096ms.
[23:19:03.073] INFO: The DUT currently contains the following objects:
[23:19:03.073] INFO: 2 TBM Cores tbm08c (2 ON)
[23:19:03.073] INFO: TBM Core alpha (0): 7 registers set
[23:19:03.073] INFO: TBM Core beta (1): 7 registers set
[23:19:03.073] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[23:19:03.073] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:03.073] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:03.074] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:03.074] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:03.074] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:03.074] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:03.074] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:03.074] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:03.074] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:03.074] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:03.074] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:03.074] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:03.074] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:03.074] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:03.074] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:03.074] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:04.173] INFO: Test took 1099ms.
[23:19:04.175] INFO: The DUT currently contains the following objects:
[23:19:04.175] INFO: 2 TBM Cores tbm08c (2 ON)
[23:19:04.175] INFO: TBM Core alpha (0): 7 registers set
[23:19:04.175] INFO: TBM Core beta (1): 7 registers set
[23:19:04.175] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[23:19:04.175] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:04.175] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:04.175] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:04.175] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:04.175] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:04.175] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:04.175] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:04.175] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:04.175] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:04.175] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:04.175] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:04.175] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:04.175] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:04.175] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:04.175] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:04.175] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:05.277] INFO: Test took 1102ms.
[23:19:05.280] INFO: The DUT currently contains the following objects:
[23:19:05.280] INFO: 2 TBM Cores tbm08c (2 ON)
[23:19:05.280] INFO: TBM Core alpha (0): 7 registers set
[23:19:05.280] INFO: TBM Core beta (1): 7 registers set
[23:19:05.280] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[23:19:05.280] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:05.280] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:05.280] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:05.280] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:05.280] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:05.280] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:05.280] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:05.280] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:05.280] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:05.280] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:05.280] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:05.280] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:05.280] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:05.280] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:05.280] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:05.280] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:06.381] INFO: Test took 1101ms.
[23:19:06.384] INFO: The DUT currently contains the following objects:
[23:19:06.384] INFO: 2 TBM Cores tbm08c (2 ON)
[23:19:06.384] INFO: TBM Core alpha (0): 7 registers set
[23:19:06.384] INFO: TBM Core beta (1): 7 registers set
[23:19:06.384] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[23:19:06.384] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:06.384] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:06.384] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:06.384] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:06.384] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:06.384] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:06.384] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:06.384] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:06.384] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:06.384] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:06.384] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:06.384] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:06.384] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:06.384] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:06.384] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:06.384] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:07.485] INFO: Test took 1101ms.
[23:19:07.488] INFO: The DUT currently contains the following objects:
[23:19:07.488] INFO: 2 TBM Cores tbm08c (2 ON)
[23:19:07.488] INFO: TBM Core alpha (0): 7 registers set
[23:19:07.488] INFO: TBM Core beta (1): 7 registers set
[23:19:07.488] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[23:19:07.488] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:07.488] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:07.488] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:07.488] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:07.488] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:07.488] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:07.488] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:07.488] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:07.488] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:07.488] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:07.488] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:07.488] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:07.488] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:07.488] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:07.488] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:07.489] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:08.587] INFO: Test took 1098ms.
[23:19:08.589] INFO: The DUT currently contains the following objects:
[23:19:08.589] INFO: 2 TBM Cores tbm08c (2 ON)
[23:19:08.589] INFO: TBM Core alpha (0): 7 registers set
[23:19:08.589] INFO: TBM Core beta (1): 7 registers set
[23:19:08.589] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[23:19:08.589] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:08.589] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:08.589] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:08.589] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:08.589] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:08.589] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:08.589] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:08.589] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:08.589] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:08.589] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:08.589] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:08.590] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:08.590] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:08.590] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:08.590] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:08.590] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:09.689] INFO: Test took 1099ms.
[23:19:09.691] INFO: The DUT currently contains the following objects:
[23:19:09.691] INFO: 2 TBM Cores tbm08c (2 ON)
[23:19:09.691] INFO: TBM Core alpha (0): 7 registers set
[23:19:09.692] INFO: TBM Core beta (1): 7 registers set
[23:19:09.692] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[23:19:09.692] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:09.692] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:09.692] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:09.692] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:09.692] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:09.692] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:09.692] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:09.692] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:09.692] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:09.692] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:09.692] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:09.692] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:09.692] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:09.692] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:09.692] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:09.692] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:10.794] INFO: Test took 1102ms.
[23:19:10.797] INFO: The DUT currently contains the following objects:
[23:19:10.797] INFO: 2 TBM Cores tbm08c (2 ON)
[23:19:10.797] INFO: TBM Core alpha (0): 7 registers set
[23:19:10.797] INFO: TBM Core beta (1): 7 registers set
[23:19:10.797] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[23:19:10.797] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:10.797] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:10.797] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:10.797] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:10.797] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:10.797] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:10.797] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:10.797] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:10.797] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:10.797] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:10.797] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:10.797] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:10.797] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:10.797] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:10.797] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:10.797] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[23:19:11.897] INFO: Test took 1100ms.
[23:19:11.904] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:22:26.170] INFO: Test took 194266ms.
[23:22:29.335] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:25:42.711] INFO: Test took 193377ms.
[23:25:45.829] INFO: safety margin for low PH: adding 0, margin is now 20
[23:25:45.839] INFO: safety margin for low PH: adding 0, margin is now 20
[23:25:45.849] INFO: safety margin for low PH: adding 0, margin is now 20
[23:25:45.858] INFO: safety margin for low PH: adding 0, margin is now 20
[23:25:45.868] INFO: safety margin for low PH: adding 0, margin is now 20
[23:25:45.878] INFO: safety margin for low PH: adding 0, margin is now 20
[23:25:45.887] INFO: safety margin for low PH: adding 0, margin is now 20
[23:25:45.897] INFO: safety margin for low PH: adding 0, margin is now 20
[23:25:45.907] INFO: safety margin for low PH: adding 0, margin is now 20
[23:25:45.917] INFO: safety margin for low PH: adding 0, margin is now 20
[23:25:45.927] INFO: safety margin for low PH: adding 0, margin is now 20
[23:25:45.937] INFO: safety margin for low PH: adding 1, margin is now 21
[23:25:45.947] INFO: safety margin for low PH: adding 2, margin is now 22
[23:25:45.957] INFO: safety margin for low PH: adding 3, margin is now 23
[23:25:45.967] INFO: safety margin for low PH: adding 4, margin is now 24
[23:25:45.977] INFO: safety margin for low PH: adding 5, margin is now 25
[23:25:45.987] INFO: safety margin for low PH: adding 6, margin is now 26
[23:25:45.997] INFO: safety margin for low PH: adding 0, margin is now 20
[23:25:46.007] INFO: safety margin for low PH: adding 0, margin is now 20
[23:25:46.017] INFO: safety margin for low PH: adding 0, margin is now 20
[23:25:46.026] INFO: safety margin for low PH: adding 0, margin is now 20
[23:25:46.036] INFO: safety margin for low PH: adding 0, margin is now 20
[23:25:46.112] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/dacParameters35_C0.dat
[23:25:46.113] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/dacParameters35_C1.dat
[23:25:46.113] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/dacParameters35_C2.dat
[23:25:46.114] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/dacParameters35_C3.dat
[23:25:46.114] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/dacParameters35_C4.dat
[23:25:46.114] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/dacParameters35_C5.dat
[23:25:46.115] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/dacParameters35_C6.dat
[23:25:46.115] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/dacParameters35_C7.dat
[23:25:46.116] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/dacParameters35_C8.dat
[23:25:46.116] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/dacParameters35_C9.dat
[23:25:46.116] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/dacParameters35_C10.dat
[23:25:46.117] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/dacParameters35_C11.dat
[23:25:46.117] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/dacParameters35_C12.dat
[23:25:46.117] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/dacParameters35_C13.dat
[23:25:46.118] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/dacParameters35_C14.dat
[23:25:46.118] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/dacParameters35_C15.dat
[23:25:49.846] INFO: Test took 3722ms.
[23:25:53.760] INFO: Test took 3561ms.
[23:25:57.831] INFO: Test took 3724ms.
[23:25:58.206] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:25:59.117] INFO: Test took 912ms.
[23:25:59.121] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:26:00.222] INFO: Test took 1101ms.
[23:26:00.227] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:26:01.330] INFO: Test took 1103ms.
[23:26:01.336] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:26:02.437] INFO: Test took 1101ms.
[23:26:02.444] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:26:03.540] INFO: Test took 1096ms.
[23:26:03.543] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:26:04.646] INFO: Test took 1103ms.
[23:26:04.653] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:26:05.753] INFO: Test took 1100ms.
[23:26:05.758] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:26:06.860] INFO: Test took 1102ms.
[23:26:06.865] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:26:07.963] INFO: Test took 1098ms.
[23:26:07.970] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:26:09.070] INFO: Test took 1100ms.
[23:26:09.077] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:26:10.177] INFO: Test took 1100ms.
[23:26:10.184] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:26:11.285] INFO: Test took 1102ms.
[23:26:11.292] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:26:12.392] INFO: Test took 1100ms.
[23:26:12.398] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:26:13.500] INFO: Test took 1103ms.
[23:26:13.507] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:26:14.608] INFO: Test took 1102ms.
[23:26:14.614] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:26:15.715] INFO: Test took 1101ms.
[23:26:15.722] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:26:16.822] INFO: Test took 1101ms.
[23:26:16.829] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:26:17.930] INFO: Test took 1101ms.
[23:26:17.936] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:26:19.035] INFO: Test took 1099ms.
[23:26:19.040] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:26:20.140] INFO: Test took 1101ms.
[23:26:20.147] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:26:21.249] INFO: Test took 1102ms.
[23:26:21.253] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:26:22.355] INFO: Test took 1102ms.
[23:26:22.360] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:26:23.461] INFO: Test took 1101ms.
[23:26:23.469] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:26:24.569] INFO: Test took 1101ms.
[23:26:24.575] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:26:25.674] INFO: Test took 1099ms.
[23:26:25.680] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:26:26.782] INFO: Test took 1103ms.
[23:26:26.789] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:26:27.887] INFO: Test took 1099ms.
[23:26:27.895] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:26:28.996] INFO: Test took 1102ms.
[23:26:28.002] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:26:30.100] INFO: Test took 1098ms.
[23:26:30.105] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:26:31.208] INFO: Test took 1103ms.
[23:26:31.214] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:26:32.315] INFO: Test took 1102ms.
[23:26:32.322] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:26:33.422] INFO: Test took 1101ms.
[23:26:34.037] INFO: PixTestPhOptimization::doTest() done, duration: 471 seconds
[23:26:34.037] INFO: PH scale (per ROC): 78 79 80 82 85 75 75 80 79 66 80 76 69 85 80 75
[23:26:34.037] INFO: PH offset (per ROC): 160 151 145 158 149 144 154 172 170 183 178 159 162 149 147 165
[23:26:34.225] INFO: ######################################################################
[23:26:34.225] INFO: PixTestGainPedestal::fullTest() ntrig = 10
[23:26:34.225] INFO: ######################################################################
[23:26:34.243] INFO: scanning low vcal = 10
[23:26:38.320] INFO: Test took 4077ms.
[23:26:38.328] INFO: scanning low vcal = 20
[23:26:42.401] INFO: Test took 4073ms.
[23:26:42.409] INFO: scanning low vcal = 30
[23:26:46.464] INFO: Test took 4054ms.
[23:26:46.484] INFO: scanning low vcal = 40
[23:26:50.988] INFO: Test took 4503ms.
[23:26:51.096] INFO: scanning low vcal = 50
[23:26:55.656] INFO: Test took 4560ms.
[23:26:55.779] INFO: scanning low vcal = 60
[23:27:00.432] INFO: Test took 4653ms.
[23:27:00.545] INFO: scanning low vcal = 70
[23:27:05.115] INFO: Test took 4570ms.
[23:27:05.234] INFO: scanning low vcal = 80
[23:27:09.770] INFO: Test took 4536ms.
[23:27:09.895] INFO: scanning low vcal = 90
[23:27:14.513] INFO: Test took 4618ms.
[23:27:14.632] INFO: scanning low vcal = 100
[23:27:19.274] INFO: Test took 4642ms.
[23:27:19.403] INFO: scanning low vcal = 110
[23:27:24.012] INFO: Test took 4609ms.
[23:27:24.132] INFO: scanning low vcal = 120
[23:27:28.759] INFO: Test took 4627ms.
[23:27:28.874] INFO: scanning low vcal = 130
[23:27:33.424] INFO: Test took 4550ms.
[23:27:33.595] INFO: scanning low vcal = 140
[23:27:38.234] INFO: Test took 4639ms.
[23:27:38.344] INFO: scanning low vcal = 150
[23:27:42.923] INFO: Test took 4579ms.
[23:27:43.034] INFO: scanning low vcal = 160
[23:27:47.661] INFO: Test took 4627ms.
[23:27:47.775] INFO: scanning low vcal = 170
[23:27:52.381] INFO: Test took 4606ms.
[23:27:52.497] INFO: scanning low vcal = 180
[23:27:57.070] INFO: Test took 4573ms.
[23:27:57.185] INFO: scanning low vcal = 190
[23:28:01.891] INFO: Test took 4706ms.
[23:28:02.006] INFO: scanning low vcal = 200
[23:28:06.585] INFO: Test took 4579ms.
[23:28:06.706] INFO: scanning low vcal = 210
[23:28:11.271] INFO: Test took 4565ms.
[23:28:11.381] INFO: scanning low vcal = 220
[23:28:15.964] INFO: Test took 4583ms.
[23:28:16.092] INFO: scanning low vcal = 230
[23:28:20.731] INFO: Test took 4639ms.
[23:28:20.845] INFO: scanning low vcal = 240
[23:28:25.475] INFO: Test took 4630ms.
[23:28:25.591] INFO: scanning low vcal = 250
[23:28:30.122] INFO: Test took 4531ms.
[23:28:30.245] INFO: scanning high vcal = 30 (= 210 in low range)
[23:28:34.859] INFO: Test took 4614ms.
[23:28:34.972] INFO: scanning high vcal = 50 (= 350 in low range)
[23:28:39.577] INFO: Test took 4605ms.
[23:28:39.689] INFO: scanning high vcal = 70 (= 490 in low range)
[23:28:44.278] INFO: Test took 4589ms.
[23:28:44.391] INFO: scanning high vcal = 90 (= 630 in low range)
[23:28:48.961] INFO: Test took 4570ms.
[23:28:49.074] INFO: scanning high vcal = 200 (= 1400 in low range)
[23:28:53.650] INFO: Test took 4576ms.
[23:28:54.389] INFO: PixTestGainPedestal::measure() done
[23:29:47.428] INFO: PixTestGainPedestal::fit() done
[23:29:47.428] INFO: non-linearity mean: 0.957 0.951 0.959 0.962 0.957 0.957 0.955 0.951 0.960 0.959 0.964 0.959 0.963 0.949 0.965 0.958
[23:29:47.428] INFO: non-linearity RMS: 0.006 0.007 0.006 0.006 0.006 0.006 0.006 0.007 0.006 0.008 0.004 0.005 0.007 0.007 0.005 0.006
[23:29:47.428] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/phCalibrationFitErr35_C0.dat
[23:29:47.453] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/phCalibrationFitErr35_C1.dat
[23:29:47.478] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/phCalibrationFitErr35_C2.dat
[23:29:47.503] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/phCalibrationFitErr35_C3.dat
[23:29:47.528] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/phCalibrationFitErr35_C4.dat
[23:29:47.554] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/phCalibrationFitErr35_C5.dat
[23:29:47.579] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/phCalibrationFitErr35_C6.dat
[23:29:47.605] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/phCalibrationFitErr35_C7.dat
[23:29:47.630] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/phCalibrationFitErr35_C8.dat
[23:29:47.656] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/phCalibrationFitErr35_C9.dat
[23:29:47.682] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/phCalibrationFitErr35_C10.dat
[23:29:47.708] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/phCalibrationFitErr35_C11.dat
[23:29:47.734] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/phCalibrationFitErr35_C12.dat
[23:29:47.759] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/phCalibrationFitErr35_C13.dat
[23:29:47.785] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/phCalibrationFitErr35_C14.dat
[23:29:47.811] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/phCalibrationFitErr35_C15.dat
[23:29:47.836] INFO: PixTestGainPedestal::doTest() done, duration: 193 seconds
[23:29:47.845] INFO: readReadbackCal: /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/readbackCal_C0.dat .. /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/readbackCal_C15.dat
[23:29:47.847] INFO: PixTestReadback::doTest() start.
[23:29:47.848] INFO: PixTestReadback::RES sent once
[23:30:04.446] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/readbackCal_C0.dat
[23:30:04.447] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/readbackCal_C1.dat
[23:30:04.447] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/readbackCal_C2.dat
[23:30:04.447] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/readbackCal_C3.dat
[23:30:04.447] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/readbackCal_C4.dat
[23:30:04.447] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/readbackCal_C5.dat
[23:30:04.447] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/readbackCal_C6.dat
[23:30:04.447] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/readbackCal_C7.dat
[23:30:04.447] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/readbackCal_C8.dat
[23:30:04.447] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/readbackCal_C9.dat
[23:30:04.447] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/readbackCal_C10.dat
[23:30:04.447] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/readbackCal_C11.dat
[23:30:04.447] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/readbackCal_C12.dat
[23:30:04.448] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/readbackCal_C13.dat
[23:30:04.448] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/readbackCal_C14.dat
[23:30:04.448] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/readbackCal_C15.dat
[23:30:04.494] INFO: PixTestPattern:: pg_setup set to default.
[23:30:04.495] INFO: PixTestReadback::RES sent once
[23:30:21.008] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/readbackCal_C0.dat
[23:30:21.009] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/readbackCal_C1.dat
[23:30:21.009] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/readbackCal_C2.dat
[23:30:21.009] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/readbackCal_C3.dat
[23:30:21.009] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/readbackCal_C4.dat
[23:30:21.009] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/readbackCal_C5.dat
[23:30:21.009] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/readbackCal_C6.dat
[23:30:21.009] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/readbackCal_C7.dat
[23:30:21.009] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/readbackCal_C8.dat
[23:30:21.009] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/readbackCal_C9.dat
[23:30:21.009] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/readbackCal_C10.dat
[23:30:21.009] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/readbackCal_C11.dat
[23:30:21.010] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/readbackCal_C12.dat
[23:30:21.010] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/readbackCal_C13.dat
[23:30:21.010] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/readbackCal_C14.dat
[23:30:21.010] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/readbackCal_C15.dat
[23:30:21.061] INFO: PixTestPattern:: pg_setup set to default.
[23:30:21.062] INFO: PixTestReadback::RES sent once
[23:30:33.843] INFO: PixTestPattern:: pg_setup set to default.
[23:30:33.843] INFO: Vbg will be calibrated using Vd calibration
[23:30:33.844] INFO: /*/*/*/*::: ROC 0: uncalibrated Vbg = 152.2calibrated Vbg = 1.20322 :::*/*/*/*/
[23:30:33.844] INFO: /*/*/*/*::: ROC 1: uncalibrated Vbg = 151.2calibrated Vbg = 1.20583 :::*/*/*/*/
[23:30:33.844] INFO: /*/*/*/*::: ROC 2: uncalibrated Vbg = 153.5calibrated Vbg = 1.20829 :::*/*/*/*/
[23:30:33.844] INFO: /*/*/*/*::: ROC 3: uncalibrated Vbg = 148calibrated Vbg = 1.21582 :::*/*/*/*/
[23:30:33.844] INFO: /*/*/*/*::: ROC 4: uncalibrated Vbg = 147.4calibrated Vbg = 1.21186 :::*/*/*/*/
[23:30:33.844] INFO: /*/*/*/*::: ROC 5: uncalibrated Vbg = 149.2calibrated Vbg = 1.21479 :::*/*/*/*/
[23:30:33.844] INFO: /*/*/*/*::: ROC 6: uncalibrated Vbg = 154.2calibrated Vbg = 1.2106 :::*/*/*/*/
[23:30:33.844] INFO: /*/*/*/*::: ROC 7: uncalibrated Vbg = 160calibrated Vbg = 1.21251 :::*/*/*/*/
[23:30:33.844] INFO: /*/*/*/*::: ROC 8: uncalibrated Vbg = 164.4calibrated Vbg = 1.21612 :::*/*/*/*/
[23:30:33.844] INFO: /*/*/*/*::: ROC 9: uncalibrated Vbg = 159.2calibrated Vbg = 1.21603 :::*/*/*/*/
[23:30:33.844] INFO: /*/*/*/*::: ROC 10: uncalibrated Vbg = 161.9calibrated Vbg = 1.21619 :::*/*/*/*/
[23:30:33.844] INFO: /*/*/*/*::: ROC 11: uncalibrated Vbg = 160.7calibrated Vbg = 1.21095 :::*/*/*/*/
[23:30:33.844] INFO: /*/*/*/*::: ROC 12: uncalibrated Vbg = 155calibrated Vbg = 1.21243 :::*/*/*/*/
[23:30:33.844] INFO: /*/*/*/*::: ROC 13: uncalibrated Vbg = 153.7calibrated Vbg = 1.1952 :::*/*/*/*/
[23:30:33.844] INFO: /*/*/*/*::: ROC 14: uncalibrated Vbg = 148.2calibrated Vbg = 1.20607 :::*/*/*/*/
[23:30:33.844] INFO: /*/*/*/*::: ROC 15: uncalibrated Vbg = 151.8calibrated Vbg = 1.20003 :::*/*/*/*/
[23:30:33.849] INFO: PixTestReadback::RES sent once
[23:34:29.244] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/readbackCal_C0.dat
[23:34:29.244] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/readbackCal_C1.dat
[23:34:29.244] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/readbackCal_C2.dat
[23:34:29.244] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/readbackCal_C3.dat
[23:34:29.244] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/readbackCal_C4.dat
[23:34:29.244] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/readbackCal_C5.dat
[23:34:29.244] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/readbackCal_C6.dat
[23:34:29.244] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/readbackCal_C7.dat
[23:34:29.244] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/readbackCal_C8.dat
[23:34:29.244] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/readbackCal_C9.dat
[23:34:29.244] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/readbackCal_C10.dat
[23:34:29.245] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/readbackCal_C11.dat
[23:34:29.245] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/readbackCal_C12.dat
[23:34:29.245] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/readbackCal_C13.dat
[23:34:29.245] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/readbackCal_C14.dat
[23:34:29.245] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4553_FullQualification_2015-08-14_15h47m_1439563624/001_Fulltest_m20/readbackCal_C15.dat
[23:34:29.299] INFO: PixTestPattern:: pg_setup set to default.
[23:34:29.302] INFO: PixTestReadback::doTest() done
[23:34:29.320] INFO: enter test to run
[23:34:29.320] INFO: test: q no parameter change
[23:34:29.498] QUIET: Connection to board 175 closed.
[23:34:29.501] INFO: pXar: this is the end, my friend