[18:22:45.502] INFO: *** Welcome to pxar ***
[18:22:45.502] INFO: *** Today: 2015/08/10
[18:22:45.502] INFO: readRocDacs: /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/dacParameters_C0.dat .. /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/dacParameters_C15.dat
[18:22:45.502] INFO: readTbmDacs: /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/tbmParameters_C0a.dat .. /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/tbmParameters_C0b.dat
[18:22:45.503] INFO: readMaskFile: /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/defaultMaskFile.dat
[18:22:45.503] INFO: readTrimFile: /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/trimParameters_C0.dat .. /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/trimParameters_C15.dat
[18:22:45.600] INFO: clk: 4
[18:22:45.600] INFO: ctr: 4
[18:22:45.600] INFO: sda: 19
[18:22:45.600] INFO: tin: 9
[18:22:45.600] INFO: level: 15
[18:22:45.600] INFO: triggerdelay: 0
[18:22:45.600] QUIET: Instanciating API for pxar prod-01+36~geb5ac3f
[18:22:45.600] INFO: Log level: INFO
[18:22:45.611] INFO: Found DTB DTB_X0DB1G
[18:22:45.627] QUIET: Connection to board DTB_X0DB1G opened.
[18:22:45.630] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 178
HW version: DTB1.2
FW version: 4.2
SW version: 4.2
USB id: DTB_X0DB1G
MAC address: 40D8551180B2
Hostname: pixelDTB178
Comment:
------------------------------------------------------
[18:22:45.632] INFO: RPC call hashes of host and DTB match: 447413373
[18:22:47.383] INFO: DUT info:
[18:22:47.383] INFO: The DUT currently contains the following objects:
[18:22:47.383] INFO: 2 TBM Cores tbm08c (2 ON)
[18:22:47.383] INFO: TBM Core alpha (0): 7 registers set
[18:22:47.383] INFO: TBM Core beta (1): 7 registers set
[18:22:47.383] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[18:22:47.383] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[18:22:47.383] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[18:22:47.383] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[18:22:47.383] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[18:22:47.383] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[18:22:47.383] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[18:22:47.383] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[18:22:47.383] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[18:22:47.383] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[18:22:47.383] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[18:22:47.384] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[18:22:47.384] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[18:22:47.384] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[18:22:47.384] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[18:22:47.384] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[18:22:47.384] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[18:22:47.785] INFO: enter 'restricted' command line mode
[18:22:47.785] INFO: enter test to run
[18:22:47.785] INFO: test: pretest no parameter change
[18:22:47.785] INFO: running: pretest
[18:22:47.790] INFO: ######################################################################
[18:22:47.790] INFO: PixTestPretest::doTest()
[18:22:47.790] INFO: ######################################################################
[18:22:47.792] INFO: ----------------------------------------------------------------------
[18:22:47.792] INFO: PixTestPretest::programROC()
[18:22:47.792] INFO: ----------------------------------------------------------------------
[18:23:05.811] INFO: PixTestPretest::programROC() done: ROCs are all programmable
[18:23:05.811] INFO: IA differences per ROC: 16.1 19.3 17.7 16.9 18.5 16.1 16.9 16.1 17.7 18.5 17.7 17.7 16.9 16.9 17.7 16.1
[18:23:05.886] INFO: ----------------------------------------------------------------------
[18:23:05.886] INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[18:23:05.886] INFO: ----------------------------------------------------------------------
[18:23:10.592] INFO: PixTestPretest::setVana() done, Module Ia 393.1 mA = 24.5688 mA/ROC
[18:23:10.596] INFO: ----------------------------------------------------------------------
[18:23:10.596] INFO: PixTestPretest::findWorkingPixel()
[18:23:10.596] INFO: ----------------------------------------------------------------------
[18:23:18.413] INFO: Test took 7809ms.
[18:23:18.739] INFO: Found working pixel in all ROCs: col/row = 12/22
[18:23:18.786] INFO: ----------------------------------------------------------------------
[18:23:18.786] INFO: PixTestPretest::setVthrCompCalDel()
[18:23:18.786] INFO: ----------------------------------------------------------------------
[18:23:26.621] INFO: Test took 7829ms.
[18:23:26.950] INFO: PixTestPretest::setVthrCompCalDel() done
[18:23:26.950] INFO: CalDel: 147 129 141 119 135 157 119 141 136 132 133 128 132 145 160 123
[18:23:26.950] INFO: VthrComp: 51 51 51 51 51 51 52 51 51 51 51 51 51 51 51 51
[18:23:26.954] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/dacParameters_C0.dat
[18:23:26.954] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/dacParameters_C1.dat
[18:23:26.955] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/dacParameters_C2.dat
[18:23:26.955] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/dacParameters_C3.dat
[18:23:26.955] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/dacParameters_C4.dat
[18:23:26.955] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/dacParameters_C5.dat
[18:23:26.955] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/dacParameters_C6.dat
[18:23:26.955] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/dacParameters_C7.dat
[18:23:26.956] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/dacParameters_C8.dat
[18:23:26.956] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/dacParameters_C9.dat
[18:23:26.956] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/dacParameters_C10.dat
[18:23:26.956] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/dacParameters_C11.dat
[18:23:26.956] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/dacParameters_C12.dat
[18:23:26.956] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/dacParameters_C13.dat
[18:23:26.956] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/dacParameters_C14.dat
[18:23:26.957] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/dacParameters_C15.dat
[18:23:26.957] INFO: PixTestPretest::doTest() done, duration: 39 seconds
[18:23:27.045] INFO: enter test to run
[18:23:27.045] INFO: test: fulltest no parameter change
[18:23:27.045] INFO: running: fulltest
[18:23:27.045] INFO: ######################################################################
[18:23:27.045] INFO: PixTestFullTest::doTest()
[18:23:27.045] INFO: ######################################################################
[18:23:27.046] INFO: ######################################################################
[18:23:27.046] INFO: PixTestAlive::doTest()
[18:23:27.046] INFO: ######################################################################
[18:23:27.048] INFO: ----------------------------------------------------------------------
[18:23:27.048] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[18:23:27.048] INFO: ----------------------------------------------------------------------
[18:23:31.169] INFO: Test took 4120ms.
[18:23:31.203] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:23:31.439] INFO: PixTestAlive::aliveTest() done
[18:23:31.439] INFO: number of dead pixels (per ROC): 1 0 0 0 0 0 0 0 1 0 0 0 0 0 0 0
[18:23:31.441] INFO: ----------------------------------------------------------------------
[18:23:31.441] INFO: PixTestAlive::maskTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[18:23:31.441] INFO: ----------------------------------------------------------------------
[18:23:34.388] INFO: Test took 2945ms.
[18:23:34.393] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:23:34.393] INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[18:23:34.627] INFO: PixTestAlive::maskTest() done
[18:23:34.627] INFO: number of mask-defect pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[18:23:34.629] INFO: ----------------------------------------------------------------------
[18:23:34.629] INFO: PixTestAlive::addressDecodingTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[18:23:34.629] INFO: ----------------------------------------------------------------------
[18:23:38.748] INFO: Test took 4117ms.
[18:23:38.784] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:23:39.027] INFO: PixTestAlive::addressDecodingTest() done
[18:23:39.027] INFO: number of address-decoding pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[18:23:39.027] INFO: PixTestAlive::doTest() done, duration: 11 seconds
[18:23:39.038] INFO: ######################################################################
[18:23:39.038] INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[18:23:39.038] INFO: ######################################################################
[18:23:39.042] INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (30/5) hits flags = 2 (plus default)
[18:23:39.062] INFO: dacScan step from 0 .. 29
[18:23:39.062] INFO: dacScan split into 1 runs with ntrig = 5
[18:23:39.062] INFO: run 1 of 1
[18:23:58.099] INFO: Test took 19036ms.
[18:23:58.159] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:23:58.160] INFO: dacScan step from 30 .. 59
[18:23:58.160] INFO: dacScan split into 1 runs with ntrig = 5
[18:23:58.160] INFO: run 1 of 1
[18:24:17.686] INFO: Test took 19526ms.
[18:24:17.795] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:24:17.809] INFO: dacScan step from 60 .. 89
[18:24:17.809] INFO: dacScan split into 1 runs with ntrig = 5
[18:24:17.809] INFO: run 1 of 1
[18:24:43.120] INFO: Test took 25311ms.
[18:24:43.499] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:24:43.587] INFO: dacScan step from 90 .. 119
[18:24:43.587] INFO: dacScan split into 1 runs with ntrig = 5
[18:24:43.587] INFO: run 1 of 1
[18:25:10.819] INFO: Test took 27233ms.
[18:25:11.233] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:25:11.334] INFO: dacScan step from 120 .. 149
[18:25:11.334] INFO: dacScan split into 1 runs with ntrig = 5
[18:25:11.334] INFO: run 1 of 1
[18:25:37.378] INFO: Test took 26044ms.
[18:25:37.705] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:26:12.564] INFO: PixTestBBMap::doTest() done, duration: 153 seconds
[18:26:12.564] INFO: number of dead bumps (per ROC): 0 0 0 0 0 0 0 0 1 0 1 0 0 0 0 0
[18:26:12.564] INFO: separation cut (per ROC): 113 108 102 115 106 88 109 115 99 124 105 113 95 102 96 113
[18:26:12.670] INFO: ######################################################################
[18:26:12.670] INFO: PixTestScurves::fullTest() ntrig = 50, dacs/step = -1, ntrig/step = 1
[18:26:12.670] INFO: ######################################################################
[18:26:12.670] INFO: ----------------------------------------------------------------------
[18:26:12.670] INFO: PixTestScurves::scurves(Vcal), ntrig = 50, dacs/step = -1, ntrig/step = 1
[18:26:12.670] INFO: ----------------------------------------------------------------------
[18:26:12.670] INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 0 .. 149 (-1/1) hits flags = 16 (plus default)
[18:26:12.686] INFO: dacScan split into 50 runs with ntrig = 1
[18:26:12.686] INFO: run 1 of 50
[18:27:01.730] INFO: Test took 49044ms.
[18:27:02.095] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:27:02.287] INFO: run 2 of 50
[18:27:51.243] INFO: Test took 48956ms.
[18:27:51.607] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:27:51.793] INFO: run 3 of 50
[18:28:40.746] INFO: Test took 48953ms.
[18:28:41.109] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:28:41.304] INFO: run 4 of 50
[18:29:30.194] INFO: Test took 48890ms.
[18:29:30.554] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:29:30.739] INFO: run 5 of 50
[18:30:19.685] INFO: Test took 48946ms.
[18:30:20.071] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:30:20.262] INFO: run 6 of 50
[18:31:09.296] INFO: Test took 49034ms.
[18:31:09.656] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:31:09.841] INFO: run 7 of 50
[18:31:58.660] INFO: Test took 48819ms.
[18:31:59.018] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:31:59.202] INFO: run 8 of 50
[18:32:47.962] INFO: Test took 48759ms.
[18:32:48.312] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:32:48.500] INFO: run 9 of 50
[18:33:37.267] INFO: Test took 48767ms.
[18:33:37.650] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:33:37.854] INFO: run 10 of 50
[18:34:26.682] INFO: Test took 48828ms.
[18:34:27.030] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:34:27.217] INFO: run 11 of 50
[18:35:16.102] INFO: Test took 48885ms.
[18:35:16.458] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:35:16.638] INFO: run 12 of 50
[18:36:05.530] INFO: Test took 48892ms.
[18:36:05.883] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:36:06.073] INFO: run 13 of 50
[18:36:55.097] INFO: Test took 49024ms.
[18:36:55.442] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:36:55.625] INFO: run 14 of 50
[18:37:44.585] INFO: Test took 48960ms.
[18:37:44.938] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:37:45.121] INFO: run 15 of 50
[18:38:34.016] INFO: Test took 48895ms.
[18:38:34.363] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:38:34.551] INFO: run 16 of 50
[18:39:23.404] INFO: Test took 48853ms.
[18:39:23.754] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:39:23.933] INFO: run 17 of 50
[18:40:12.857] INFO: Test took 48924ms.
[18:40:13.210] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:40:13.390] INFO: run 18 of 50
[18:41:02.337] INFO: Test took 48946ms.
[18:41:02.682] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:41:02.865] INFO: run 19 of 50
[18:41:51.866] INFO: Test took 49001ms.
[18:41:52.219] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:41:52.401] INFO: run 20 of 50
[18:42:41.404] INFO: Test took 49004ms.
[18:42:41.756] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:42:41.941] INFO: run 21 of 50
[18:43:30.865] INFO: Test took 48924ms.
[18:43:31.215] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:43:31.403] INFO: run 22 of 50
[18:44:20.392] INFO: Test took 48989ms.
[18:44:20.741] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:44:20.920] INFO: run 23 of 50
[18:45:09.870] INFO: Test took 48949ms.
[18:45:10.221] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:45:10.402] INFO: run 24 of 50
[18:45:59.258] INFO: Test took 48856ms.
[18:45:59.608] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:45:59.792] INFO: run 25 of 50
[18:46:48.597] INFO: Test took 48804ms.
[18:46:48.952] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:46:49.132] INFO: run 26 of 50
[18:47:37.904] INFO: Test took 48772ms.
[18:47:38.264] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:47:38.447] INFO: run 27 of 50
[18:48:27.172] INFO: Test took 48725ms.
[18:48:27.528] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:48:27.723] INFO: run 28 of 50
[18:49:16.568] INFO: Test took 48845ms.
[18:49:16.921] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:49:17.101] INFO: run 29 of 50
[18:50:06.049] INFO: Test took 48948ms.
[18:50:06.405] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:50:06.591] INFO: run 30 of 50
[18:50:55.538] INFO: Test took 48946ms.
[18:50:55.891] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:50:56.071] INFO: run 31 of 50
[18:51:44.909] INFO: Test took 48837ms.
[18:51:45.261] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:51:45.444] INFO: run 32 of 50
[18:52:34.375] INFO: Test took 48931ms.
[18:52:34.730] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:52:34.913] INFO: run 33 of 50
[18:53:23.850] INFO: Test took 48936ms.
[18:53:24.201] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:53:24.383] INFO: run 34 of 50
[18:54:13.369] INFO: Test took 48985ms.
[18:54:13.725] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:54:13.913] INFO: run 35 of 50
[18:55:02.901] INFO: Test took 48988ms.
[18:55:03.243] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:55:03.431] INFO: run 36 of 50
[18:55:52.470] INFO: Test took 49039ms.
[18:55:52.830] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:55:53.020] INFO: run 37 of 50
[18:56:41.002] INFO: Test took 48981ms.
[18:56:42.356] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:56:42.538] INFO: run 38 of 50
[18:57:31.480] INFO: Test took 48942ms.
[18:57:31.838] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:57:32.016] INFO: run 39 of 50
[18:58:20.924] INFO: Test took 48908ms.
[18:58:21.284] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:58:21.465] INFO: run 40 of 50
[18:59:10.407] INFO: Test took 48942ms.
[18:59:10.763] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:59:10.945] INFO: run 41 of 50
[18:59:59.857] INFO: Test took 48911ms.
[19:00:00.212] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:00:00.404] INFO: run 42 of 50
[19:00:49.463] INFO: Test took 49059ms.
[19:00:49.823] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:00:50.010] INFO: run 43 of 50
[19:01:38.955] INFO: Test took 48945ms.
[19:01:39.309] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:01:39.490] INFO: run 44 of 50
[19:02:28.397] INFO: Test took 48907ms.
[19:02:28.748] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:02:28.930] INFO: run 45 of 50
[19:03:17.674] INFO: Test took 48744ms.
[19:03:18.046] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:03:18.230] INFO: run 46 of 50
[19:04:07.010] INFO: Test took 48780ms.
[19:04:07.365] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:04:07.547] INFO: run 47 of 50
[19:04:56.371] INFO: Test took 48824ms.
[19:04:56.718] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:04:56.901] INFO: run 48 of 50
[19:05:45.757] INFO: Test took 48856ms.
[19:05:46.114] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:05:46.300] INFO: run 49 of 50
[19:06:35.126] INFO: Test took 48826ms.
[19:06:35.478] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:06:35.658] INFO: run 50 of 50
[19:07:24.609] INFO: Test took 48950ms.
[19:07:24.967] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:07:25.158] INFO: dumping ASCII scurve output file: SCurveData
[19:07:27.182] INFO: dumping ASCII scurve output file: SCurveData
[19:07:29.218] INFO: dumping ASCII scurve output file: SCurveData
[19:07:31.278] INFO: dumping ASCII scurve output file: SCurveData
[19:07:33.359] INFO: dumping ASCII scurve output file: SCurveData
[19:07:35.310] INFO: dumping ASCII scurve output file: SCurveData
[19:07:37.493] INFO: dumping ASCII scurve output file: SCurveData
[19:07:39.638] INFO: dumping ASCII scurve output file: SCurveData
[19:07:41.661] INFO: dumping ASCII scurve output file: SCurveData
[19:07:43.870] INFO: dumping ASCII scurve output file: SCurveData
[19:07:46.056] INFO: dumping ASCII scurve output file: SCurveData
[19:07:48.308] INFO: dumping ASCII scurve output file: SCurveData
[19:07:50.486] INFO: dumping ASCII scurve output file: SCurveData
[19:07:52.785] INFO: dumping ASCII scurve output file: SCurveData
[19:07:55.039] INFO: dumping ASCII scurve output file: SCurveData
[19:07:57.296] INFO: dumping ASCII scurve output file: SCurveData
[19:07:59.544] INFO: PixTestScurves::scurves() done
[19:07:59.544] INFO: Vcal mean: 87.38 96.72 87.66 96.93 92.83 82.97 101.41 91.30 85.07 105.15 91.56 110.63 84.84 88.98 91.70 103.30
[19:07:59.544] INFO: Vcal RMS: 6.64 5.98 5.41 6.70 6.14 4.67 6.23 6.02 5.33 5.97 5.66 5.78 4.99 5.33 5.29 5.62
[19:07:59.545] INFO: PixTestScurves::fullTest() done, duration: 2506 seconds
[19:07:59.644] INFO: ######################################################################
[19:07:59.644] INFO: PixTestTrim::doTest()
[19:07:59.644] INFO: ######################################################################
[19:07:59.646] INFO: ----------------------------------------------------------------------
[19:07:59.646] INFO: PixTestTrim::trimTest() ntrig = 10, vcal = 35
[19:07:59.646] INFO: ----------------------------------------------------------------------
[19:07:59.789] INFO: ---> VthrComp thr map (minimal VthrComp)
[19:07:59.789] INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 5 dacrange: 0 .. 159 (20/-1) hits flags = 16 (plus default)
[19:07:59.805] INFO: dacScan step from 0 .. 19
[19:07:59.805] INFO: dacScan split into 1 runs with ntrig = 5
[19:07:59.805] INFO: run 1 of 1
[19:08:13.211] INFO: Test took 13406ms.
[19:08:13.257] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:08:13.257] INFO: dacScan step from 20 .. 39
[19:08:13.257] INFO: dacScan split into 1 runs with ntrig = 5
[19:08:13.257] INFO: run 1 of 1
[19:08:26.701] INFO: Test took 13444ms.
[19:08:26.746] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:08:26.746] INFO: dacScan step from 40 .. 59
[19:08:26.746] INFO: dacScan split into 1 runs with ntrig = 5
[19:08:26.746] INFO: run 1 of 1
[19:08:40.129] INFO: Test took 13383ms.
[19:08:40.174] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:08:40.174] INFO: dacScan step from 60 .. 79
[19:08:40.174] INFO: dacScan split into 1 runs with ntrig = 5
[19:08:40.174] INFO: run 1 of 1
[19:08:53.571] INFO: Test took 13397ms.
[19:08:53.612] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:08:53.612] INFO: dacScan step from 80 .. 99
[19:08:53.612] INFO: dacScan split into 1 runs with ntrig = 5
[19:08:53.612] INFO: run 1 of 1
[19:09:07.279] INFO: Test took 13667ms.
[19:09:07.376] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:09:07.382] INFO: dacScan step from 100 .. 119
[19:09:07.382] INFO: dacScan split into 1 runs with ntrig = 5
[19:09:07.382] INFO: run 1 of 1
[19:09:23.667] INFO: Test took 16285ms.
[19:09:23.884] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:09:23.929] INFO: dacScan step from 120 .. 139
[19:09:23.929] INFO: dacScan split into 1 runs with ntrig = 5
[19:09:23.929] INFO: run 1 of 1
[19:09:42.959] INFO: Test took 19030ms.
[19:09:43.195] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:09:43.252] INFO: dacScan step from 140 .. 159
[19:09:43.252] INFO: dacScan split into 1 runs with ntrig = 5
[19:09:43.252] INFO: run 1 of 1
[19:09:58.412] INFO: Test took 15159ms.
[19:09:58.546] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:10:32.216] INFO: ROC 0 VthrComp = 90
[19:10:32.216] INFO: ROC 1 VthrComp = 98
[19:10:32.216] INFO: ROC 2 VthrComp = 92
[19:10:32.217] INFO: ROC 3 VthrComp = 97
[19:10:32.217] INFO: ROC 4 VthrComp = 99
[19:10:32.217] INFO: ROC 5 VthrComp = 87
[19:10:32.217] INFO: ROC 6 VthrComp = 101
[19:10:32.217] INFO: ROC 7 VthrComp = 89
[19:10:32.217] INFO: ROC 8 VthrComp = 90
[19:10:32.217] INFO: ROC 9 VthrComp = 105
[19:10:32.217] INFO: ROC 10 VthrComp = 97
[19:10:32.218] INFO: ROC 11 VthrComp = 106
[19:10:32.218] INFO: ROC 12 VthrComp = 89
[19:10:32.218] INFO: ROC 13 VthrComp = 95
[19:10:32.218] INFO: ROC 14 VthrComp = 95
[19:10:32.218] INFO: ROC 15 VthrComp = 100
[19:10:32.218] INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[19:10:32.218] INFO: ---> dac: vcal name: TrimThr1 ntrig: 5 dacrange: 0 .. 159 (20/-1) hits flags = 16 (plus default)
[19:10:32.233] INFO: dacScan step from 0 .. 19
[19:10:32.233] INFO: dacScan split into 1 runs with ntrig = 5
[19:10:32.233] INFO: run 1 of 1
[19:10:45.597] INFO: Test took 13363ms.
[19:10:45.643] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:10:45.644] INFO: dacScan step from 20 .. 39
[19:10:45.644] INFO: dacScan split into 1 runs with ntrig = 5
[19:10:45.644] INFO: run 1 of 1
[19:10:59.314] INFO: Test took 13670ms.
[19:10:59.378] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:10:59.382] INFO: dacScan step from 40 .. 59
[19:10:59.382] INFO: dacScan split into 1 runs with ntrig = 5
[19:10:59.382] INFO: run 1 of 1
[19:11:16.191] INFO: Test took 16808ms.
[19:11:16.460] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:11:16.523] INFO: dacScan step from 60 .. 79
[19:11:16.523] INFO: dacScan split into 1 runs with ntrig = 5
[19:11:16.523] INFO: run 1 of 1
[19:11:35.436] INFO: Test took 18912ms.
[19:11:35.734] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:11:35.812] INFO: dacScan step from 80 .. 99
[19:11:35.812] INFO: dacScan split into 1 runs with ntrig = 5
[19:11:35.812] INFO: run 1 of 1
[19:11:54.767] INFO: Test took 18955ms.
[19:11:55.028] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:11:55.100] INFO: dacScan step from 100 .. 119
[19:11:55.100] INFO: dacScan split into 1 runs with ntrig = 5
[19:11:55.100] INFO: run 1 of 1
[19:12:14.065] INFO: Test took 18965ms.
[19:12:14.361] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:12:14.436] INFO: dacScan step from 120 .. 139
[19:12:14.436] INFO: dacScan split into 1 runs with ntrig = 5
[19:12:14.436] INFO: run 1 of 1
[19:12:34.860] INFO: Test took 20424ms.
[19:12:35.153] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:12:35.227] INFO: dacScan step from 140 .. 159
[19:12:35.227] INFO: dacScan split into 1 runs with ntrig = 5
[19:12:35.227] INFO: run 1 of 1
[19:12:54.300] INFO: Test took 19073ms.
[19:12:54.557] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:13:33.842] INFO: roc 0 with ID = 0 has maximal Vcal 63.7016 for pixel 18/6 mean/min/max = 47.5082/31.2026/63.8138
[19:13:33.843] INFO: roc 1 with ID = 1 has maximal Vcal 61.4596 for pixel 0/72 mean/min/max = 46.5274/31.5671/61.4877
[19:13:33.843] INFO: roc 2 with ID = 2 has maximal Vcal 59.0179 for pixel 19/5 mean/min/max = 45.6476/32.1667/59.1284
[19:13:33.843] INFO: roc 3 with ID = 3 has maximal Vcal 64.5832 for pixel 0/7 mean/min/max = 47.9702/31.2191/64.7214
[19:13:33.844] INFO: roc 4 with ID = 4 has maximal Vcal 59.6899 for pixel 2/79 mean/min/max = 45.3677/31.0078/59.7276
[19:13:33.844] INFO: roc 5 with ID = 5 has maximal Vcal 56.9364 for pixel 2/57 mean/min/max = 44.8394/32.3236/57.3552
[19:13:33.845] INFO: roc 6 with ID = 6 has maximal Vcal 62.3007 for pixel 16/5 mean/min/max = 46.9293/31.332/62.5267
[19:13:33.845] INFO: roc 7 with ID = 7 has maximal Vcal 63.3845 for pixel 12/5 mean/min/max = 47.807/32.2096/63.4044
[19:13:33.846] INFO: roc 8 with ID = 8 has maximal Vcal 58.8421 for pixel 6/15 mean/min/max = 45.6545/32.1726/59.1364
[19:13:33.846] INFO: roc 9 with ID = 9 has maximal Vcal 65.7263 for pixel 22/73 mean/min/max = 49.6586/33.5863/65.731
[19:13:33.847] INFO: roc 10 with ID = 10 has maximal Vcal 58.7063 for pixel 0/27 mean/min/max = 45.062/31.3585/58.7654
[19:13:33.847] INFO: roc 11 with ID = 11 has maximal Vcal 65.4775 for pixel 7/77 mean/min/max = 49.6902/33.6066/65.7738
[19:13:33.848] INFO: roc 12 with ID = 12 has maximal Vcal 59.2627 for pixel 5/79 mean/min/max = 46.0155/32.6065/59.4245
[19:13:33.848] INFO: roc 13 with ID = 13 has maximal Vcal 57.6779 for pixel 41/10 mean/min/max = 44.612/31.4637/57.7603
[19:13:33.849] INFO: roc 14 with ID = 14 has maximal Vcal 58.8427 for pixel 1/8 mean/min/max = 45.3796/31.7421/59.0171
[19:13:33.849] INFO: roc 15 with ID = 15 has maximal Vcal 60.6172 for pixel 24/13 mean/min/max = 46.4456/31.9778/60.9135
[19:13:33.850] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:14:56.635] INFO: Test took 82785ms.
[19:14:58.754] INFO: ---> dac: vcal name: TrimThr2 ntrig: 10 dacrange: 0 .. 199 (20/5) hits flags = 16 (plus default)
[19:14:58.771] INFO: dacScan step from 0 .. 19
[19:14:58.771] INFO: dacScan split into 2 runs with ntrig = 5
[19:14:58.771] INFO: run 1 of 2
[19:15:12.312] INFO: Test took 13541ms.
[19:15:12.363] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:15:12.365] INFO: run 2 of 2
[19:15:25.926] INFO: Test took 13560ms.
[19:15:25.991] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:15:25.993] INFO: dacScan step from 20 .. 39
[19:15:25.993] INFO: dacScan split into 2 runs with ntrig = 5
[19:15:25.993] INFO: run 1 of 2
[19:15:42.163] INFO: Test took 16169ms.
[19:15:42.373] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:15:42.423] INFO: run 2 of 2
[19:15:58.539] INFO: Test took 16116ms.
[19:15:58.761] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:15:58.815] INFO: dacScan step from 40 .. 59
[19:15:58.815] INFO: dacScan split into 2 runs with ntrig = 5
[19:15:58.815] INFO: run 1 of 2
[19:16:17.565] INFO: Test took 18750ms.
[19:16:17.909] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:16:17.989] INFO: run 2 of 2
[19:16:36.656] INFO: Test took 18667ms.
[19:16:36.981] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:16:37.061] INFO: dacScan step from 60 .. 79
[19:16:37.061] INFO: dacScan split into 2 runs with ntrig = 5
[19:16:37.061] INFO: run 1 of 2
[19:16:55.787] INFO: Test took 18726ms.
[19:16:56.090] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:16:56.164] INFO: run 2 of 2
[19:17:14.946] INFO: Test took 18782ms.
[19:17:15.239] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:17:15.312] INFO: dacScan step from 80 .. 99
[19:17:15.312] INFO: dacScan split into 2 runs with ntrig = 5
[19:17:15.312] INFO: run 1 of 2
[19:17:34.100] INFO: Test took 18788ms.
[19:17:34.389] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:17:34.462] INFO: run 2 of 2
[19:17:53.087] INFO: Test took 18624ms.
[19:17:53.395] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:17:53.469] INFO: dacScan step from 100 .. 119
[19:17:53.469] INFO: dacScan split into 2 runs with ntrig = 5
[19:17:53.469] INFO: run 1 of 2
[19:18:12.316] INFO: Test took 18847ms.
[19:18:12.616] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:18:12.692] INFO: run 2 of 2
[19:18:31.525] INFO: Test took 18833ms.
[19:18:31.802] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:18:31.873] INFO: dacScan step from 120 .. 139
[19:18:31.873] INFO: dacScan split into 2 runs with ntrig = 5
[19:18:31.873] INFO: run 1 of 2
[19:18:52.156] INFO: Test took 20283ms.
[19:18:52.459] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:18:52.527] INFO: run 2 of 2
[19:19:12.812] INFO: Test took 20285ms.
[19:19:13.110] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:19:13.179] INFO: dacScan step from 140 .. 159
[19:19:13.179] INFO: dacScan split into 2 runs with ntrig = 5
[19:19:13.179] INFO: run 1 of 2
[19:19:32.131] INFO: Test took 18952ms.
[19:19:32.420] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:19:32.494] INFO: run 2 of 2
[19:19:51.493] INFO: Test took 18999ms.
[19:19:51.799] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:19:51.875] INFO: dacScan step from 160 .. 179
[19:19:51.875] INFO: dacScan split into 2 runs with ntrig = 5
[19:19:51.875] INFO: run 1 of 2
[19:20:10.804] INFO: Test took 18929ms.
[19:20:11.090] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:20:11.167] INFO: run 2 of 2
[19:20:30.012] INFO: Test took 18845ms.
[19:20:30.285] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:20:30.353] INFO: dacScan step from 180 .. 199
[19:20:30.353] INFO: dacScan split into 2 runs with ntrig = 5
[19:20:30.353] INFO: run 1 of 2
[19:20:49.942] INFO: Test took 19588ms.
[19:20:50.246] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:20:50.320] INFO: run 2 of 2
[19:21:09.911] INFO: Test took 19591ms.
[19:21:10.218] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:21:49.410] INFO: ---> TrimStepCorr4 extremal thresholds: 0.061424 .. 255.000000
[19:21:49.560] INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 4 dacrange: 0 .. 255 (20/-1) hits flags = 16 (plus default)
[19:21:49.575] INFO: dacScan step from 0 .. 19
[19:21:49.575] INFO: dacScan split into 1 runs with ntrig = 4
[19:21:49.575] INFO: run 1 of 1
[19:22:01.761] INFO: Test took 12186ms.
[19:22:01.797] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:22:01.797] INFO: dacScan step from 20 .. 39
[19:22:01.797] INFO: dacScan split into 1 runs with ntrig = 4
[19:22:01.797] INFO: run 1 of 1
[19:22:14.961] INFO: Test took 13164ms.
[19:22:15.097] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:22:15.128] INFO: dacScan step from 40 .. 59
[19:22:15.128] INFO: dacScan split into 1 runs with ntrig = 4
[19:22:15.128] INFO: run 1 of 1
[19:22:31.358] INFO: Test took 16230ms.
[19:22:31.649] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:22:31.732] INFO: dacScan step from 60 .. 79
[19:22:31.732] INFO: dacScan split into 1 runs with ntrig = 4
[19:22:31.732] INFO: run 1 of 1
[19:22:48.110] INFO: Test took 16378ms.
[19:22:48.390] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:22:48.474] INFO: dacScan step from 80 .. 99
[19:22:48.474] INFO: dacScan split into 1 runs with ntrig = 4
[19:22:48.474] INFO: run 1 of 1
[19:23:04.989] INFO: Test took 16515ms.
[19:23:05.254] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:23:05.334] INFO: dacScan step from 100 .. 119
[19:23:05.334] INFO: dacScan split into 1 runs with ntrig = 4
[19:23:05.334] INFO: run 1 of 1
[19:23:22.107] INFO: Test took 16773ms.
[19:23:22.352] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:23:22.427] INFO: dacScan step from 120 .. 139
[19:23:22.427] INFO: dacScan split into 1 runs with ntrig = 4
[19:23:22.427] INFO: run 1 of 1
[19:23:40.595] INFO: Test took 18168ms.
[19:23:40.841] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:23:40.915] INFO: dacScan step from 140 .. 159
[19:23:40.915] INFO: dacScan split into 1 runs with ntrig = 4
[19:23:40.915] INFO: run 1 of 1
[19:23:57.729] INFO: Test took 16814ms.
[19:23:57.967] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:23:58.036] INFO: dacScan step from 160 .. 179
[19:23:58.036] INFO: dacScan split into 1 runs with ntrig = 4
[19:23:58.036] INFO: run 1 of 1
[19:24:14.656] INFO: Test took 16620ms.
[19:24:14.877] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:24:14.944] INFO: dacScan step from 180 .. 199
[19:24:14.944] INFO: dacScan split into 1 runs with ntrig = 4
[19:24:14.944] INFO: run 1 of 1
[19:24:32.372] INFO: Test took 17427ms.
[19:24:32.633] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:24:32.706] INFO: dacScan step from 200 .. 219
[19:24:32.706] INFO: dacScan split into 1 runs with ntrig = 4
[19:24:32.706] INFO: run 1 of 1
[19:24:49.293] INFO: Test took 16587ms.
[19:24:49.571] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:24:49.653] INFO: dacScan step from 220 .. 239
[19:24:49.653] INFO: dacScan split into 1 runs with ntrig = 4
[19:24:49.653] INFO: run 1 of 1
[19:25:06.205] INFO: Test took 16552ms.
[19:25:06.496] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:25:06.578] INFO: dacScan step from 240 .. 255
[19:25:06.578] INFO: dacScan split into 1 runs with ntrig = 4
[19:25:06.578] INFO: run 1 of 1
[19:25:20.493] INFO: Test took 13915ms.
[19:25:20.724] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:26:11.986] INFO: ---> TrimStepCorr2 extremal thresholds: 12.317248 .. 44.848430
[19:26:12.131] INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 4 dacrange: 2 .. 54 (20/-1) hits flags = 16 (plus default)
[19:26:12.145] INFO: dacScan step from 2 .. 21
[19:26:12.145] INFO: dacScan split into 1 runs with ntrig = 4
[19:26:12.145] INFO: run 1 of 1
[19:26:24.392] INFO: Test took 12247ms.
[19:26:24.431] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:26:24.431] INFO: dacScan step from 22 .. 41
[19:26:24.431] INFO: dacScan split into 1 runs with ntrig = 4
[19:26:24.431] INFO: run 1 of 1
[19:26:38.029] INFO: Test took 13598ms.
[19:26:38.178] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:26:38.217] INFO: dacScan step from 42 .. 54
[19:26:38.217] INFO: dacScan split into 1 runs with ntrig = 4
[19:26:38.217] INFO: run 1 of 1
[19:26:49.788] INFO: Test took 11571ms.
[19:26:49.979] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:27:15.825] INFO: ---> TrimStepCorr1a extremal thresholds: 0.500000 .. 41.714343
[19:27:15.979] INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 4 dacrange: 0 .. 51 (20/-1) hits flags = 16 (plus default)
[19:27:15.993] INFO: dacScan step from 0 .. 19
[19:27:15.993] INFO: dacScan split into 1 runs with ntrig = 4
[19:27:15.993] INFO: run 1 of 1
[19:27:28.190] INFO: Test took 12197ms.
[19:27:28.236] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:27:28.237] INFO: dacScan step from 20 .. 39
[19:27:28.237] INFO: dacScan split into 1 runs with ntrig = 4
[19:27:28.237] INFO: run 1 of 1
[19:27:41.423] INFO: Test took 13186ms.
[19:27:41.535] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:27:41.565] INFO: dacScan step from 40 .. 51
[19:27:41.565] INFO: dacScan split into 1 runs with ntrig = 4
[19:27:41.565] INFO: run 1 of 1
[19:27:52.488] INFO: Test took 10923ms.
[19:27:52.652] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:28:16.129] INFO: ---> TrimStepCorr1b extremal thresholds: 0.224388 .. 40.348707
[19:28:16.261] INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 4 dacrange: 0 .. 50 (20/-1) hits flags = 16 (plus default)
[19:28:16.276] INFO: dacScan step from 0 .. 19
[19:28:16.276] INFO: dacScan split into 1 runs with ntrig = 4
[19:28:16.276] INFO: run 1 of 1
[19:28:28.466] INFO: Test took 12190ms.
[19:28:28.504] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:28:28.504] INFO: dacScan step from 20 .. 39
[19:28:28.504] INFO: dacScan split into 1 runs with ntrig = 4
[19:28:28.504] INFO: run 1 of 1
[19:28:41.535] INFO: Test took 13031ms.
[19:28:41.657] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:28:41.689] INFO: dacScan step from 40 .. 50
[19:28:41.689] INFO: dacScan split into 1 runs with ntrig = 4
[19:28:41.689] INFO: run 1 of 1
[19:28:51.883] INFO: Test took 10194ms.
[19:28:52.047] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:29:16.616] INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[19:29:16.616] INFO: ---> dac: vcal name: TrimThrFinal ntrig: 10 dacrange: 15 .. 55 (20/5) hits flags = 16 (plus default)
[19:29:16.631] INFO: dacScan step from 15 .. 34
[19:29:16.631] INFO: dacScan split into 2 runs with ntrig = 5
[19:29:16.631] INFO: run 1 of 2
[19:29:30.370] INFO: Test took 13738ms.
[19:29:30.451] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:29:30.464] INFO: run 2 of 2
[19:29:44.279] INFO: Test took 13815ms.
[19:29:44.356] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:29:44.371] INFO: dacScan step from 35 .. 54
[19:29:44.371] INFO: dacScan split into 2 runs with ntrig = 5
[19:29:44.371] INFO: run 1 of 2
[19:30:02.780] INFO: Test took 18409ms.
[19:30:03.094] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:30:03.173] INFO: run 2 of 2
[19:30:21.408] INFO: Test took 18235ms.
[19:30:21.683] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:30:21.757] INFO: dacScan step from 55 .. 55
[19:30:21.757] INFO: dacScan split into 2 runs with ntrig = 5
[19:30:21.757] INFO: run 1 of 2
[19:30:25.379] INFO: Test took 3621ms.
[19:30:25.398] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:30:25.408] INFO: run 2 of 2
[19:30:29.011] INFO: Test took 3603ms.
[19:30:29.033] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:30:52.481] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/dacParameters35_C0.dat
[19:30:52.481] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/dacParameters35_C1.dat
[19:30:52.481] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/dacParameters35_C2.dat
[19:30:52.482] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/dacParameters35_C3.dat
[19:30:52.482] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/dacParameters35_C4.dat
[19:30:52.482] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/dacParameters35_C5.dat
[19:30:52.482] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/dacParameters35_C6.dat
[19:30:52.483] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/dacParameters35_C7.dat
[19:30:52.483] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/dacParameters35_C8.dat
[19:30:52.483] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/dacParameters35_C9.dat
[19:30:52.483] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/dacParameters35_C10.dat
[19:30:52.484] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/dacParameters35_C11.dat
[19:30:52.484] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/dacParameters35_C12.dat
[19:30:52.484] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/dacParameters35_C13.dat
[19:30:52.484] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/dacParameters35_C14.dat
[19:30:52.484] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/dacParameters35_C15.dat
[19:30:52.485] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/trimParameters35_C0.dat
[19:30:52.500] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/trimParameters35_C1.dat
[19:30:52.513] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/trimParameters35_C2.dat
[19:30:52.527] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/trimParameters35_C3.dat
[19:30:52.541] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/trimParameters35_C4.dat
[19:30:52.554] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/trimParameters35_C5.dat
[19:30:52.568] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/trimParameters35_C6.dat
[19:30:52.582] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/trimParameters35_C7.dat
[19:30:52.595] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/trimParameters35_C8.dat
[19:30:52.609] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/trimParameters35_C9.dat
[19:30:52.622] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/trimParameters35_C10.dat
[19:30:52.636] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/trimParameters35_C11.dat
[19:30:52.650] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/trimParameters35_C12.dat
[19:30:52.667] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/trimParameters35_C13.dat
[19:30:52.685] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/trimParameters35_C14.dat
[19:30:52.703] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/trimParameters35_C15.dat
[19:30:52.721] INFO: PixTestTrim::trimTest() done
[19:30:52.721] INFO: vtrim: 122 112 117 128 118 100 113 118 111 146 117 132 111 105 111 116
[19:30:52.721] INFO: vthrcomp: 90 98 92 97 99 87 101 89 90 105 97 106 89 95 95 100
[19:30:52.721] INFO: vcal mean: 35.04 35.04 35.04 35.01 35.04 35.06 34.99 35.05 35.08 35.08 35.02 35.09 35.03 35.00 35.06 35.08
[19:30:52.721] INFO: vcal RMS: 1.22 1.10 1.04 1.25 1.10 1.07 1.40 1.22 1.10 1.06 1.12 1.16 1.07 1.09 1.11 1.25
[19:30:52.721] INFO: bits mean: 9.61 9.42 10.02 9.35 9.91 10.15 9.75 9.72 10.10 8.99 10.31 8.94 9.51 9.98 9.90 10.04
[19:30:52.721] INFO: bits RMS: 2.59 2.75 2.42 2.70 2.67 2.40 2.52 2.49 2.34 2.41 2.46 2.43 2.60 2.60 2.55 2.39
[19:30:52.733] INFO: ----------------------------------------------------------------------
[19:30:52.733] INFO: PixTestTrim::trimBitTest() ntrig = 10, vtrims = 254 126 63 32
[19:30:52.733] INFO: ----------------------------------------------------------------------
[19:30:52.736] INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 10 dacrange: 0 .. 199 (20/5) hits flags = 16 (plus default)
[19:30:52.752] INFO: dacScan step from 0 .. 19
[19:30:52.752] INFO: dacScan split into 2 runs with ntrig = 5
[19:30:52.752] INFO: run 1 of 2
[19:31:06.355] INFO: Test took 13602ms.
[19:31:06.402] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:31:06.403] INFO: run 2 of 2
[19:31:19.884] INFO: Test took 13481ms.
[19:31:19.930] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:31:19.930] INFO: dacScan step from 20 .. 39
[19:31:19.930] INFO: dacScan split into 2 runs with ntrig = 5
[19:31:19.930] INFO: run 1 of 2
[19:31:33.368] INFO: Test took 13438ms.
[19:31:33.404] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:31:33.404] INFO: run 2 of 2
[19:31:46.794] INFO: Test took 13390ms.
[19:31:46.839] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:31:46.839] INFO: dacScan step from 40 .. 59
[19:31:46.839] INFO: dacScan split into 2 runs with ntrig = 5
[19:31:46.839] INFO: run 1 of 2
[19:32:00.216] INFO: Test took 13377ms.
[19:32:00.266] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:32:00.267] INFO: run 2 of 2
[19:32:13.866] INFO: Test took 13599ms.
[19:32:13.910] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:32:13.910] INFO: dacScan step from 60 .. 79
[19:32:13.910] INFO: dacScan split into 2 runs with ntrig = 5
[19:32:13.910] INFO: run 1 of 2
[19:32:27.364] INFO: Test took 13453ms.
[19:32:27.406] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:32:27.406] INFO: run 2 of 2
[19:32:40.934] INFO: Test took 13528ms.
[19:32:40.977] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:32:40.977] INFO: dacScan step from 80 .. 99
[19:32:40.977] INFO: dacScan split into 2 runs with ntrig = 5
[19:32:40.977] INFO: run 1 of 2
[19:32:54.450] INFO: Test took 13473ms.
[19:32:54.497] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:32:54.497] INFO: run 2 of 2
[19:33:08.132] INFO: Test took 13634ms.
[19:33:08.181] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:33:08.182] INFO: dacScan step from 100 .. 119
[19:33:08.182] INFO: dacScan split into 2 runs with ntrig = 5
[19:33:08.182] INFO: run 1 of 2
[19:33:22.996] INFO: Test took 14814ms.
[19:33:23.126] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:33:23.149] INFO: run 2 of 2
[19:33:38.029] INFO: Test took 14880ms.
[19:33:38.178] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:33:38.201] INFO: dacScan step from 120 .. 139
[19:33:38.202] INFO: dacScan split into 2 runs with ntrig = 5
[19:33:38.202] INFO: run 1 of 2
[19:33:57.436] INFO: Test took 19234ms.
[19:33:57.711] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:33:57.775] INFO: run 2 of 2
[19:34:16.955] INFO: Test took 19179ms.
[19:34:17.195] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:34:17.268] INFO: dacScan step from 140 .. 159
[19:34:17.269] INFO: dacScan split into 2 runs with ntrig = 5
[19:34:17.269] INFO: run 1 of 2
[19:34:36.296] INFO: Test took 19027ms.
[19:34:36.616] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:34:36.696] INFO: run 2 of 2
[19:34:55.787] INFO: Test took 19090ms.
[19:34:56.071] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:34:56.150] INFO: dacScan step from 160 .. 179
[19:34:56.150] INFO: dacScan split into 2 runs with ntrig = 5
[19:34:56.150] INFO: run 1 of 2
[19:35:15.176] INFO: Test took 19026ms.
[19:35:15.480] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:35:15.559] INFO: run 2 of 2
[19:35:34.791] INFO: Test took 19232ms.
[19:35:35.073] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:35:35.144] INFO: dacScan step from 180 .. 199
[19:35:35.144] INFO: dacScan split into 2 runs with ntrig = 5
[19:35:35.144] INFO: run 1 of 2
[19:35:54.786] INFO: Test took 19642ms.
[19:35:55.100] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:35:55.176] INFO: run 2 of 2
[19:36:15.007] INFO: Test took 19830ms.
[19:36:15.302] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:36:56.450] INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 10 dacrange: 0 .. 181 (20/5) hits flags = 16 (plus default)
[19:36:56.464] INFO: dacScan step from 0 .. 19
[19:36:56.464] INFO: dacScan split into 2 runs with ntrig = 5
[19:36:56.464] INFO: run 1 of 2
[19:37:09.949] INFO: Test took 13485ms.
[19:37:09.993] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:37:09.993] INFO: run 2 of 2
[19:37:23.434] INFO: Test took 13441ms.
[19:37:23.475] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:37:23.475] INFO: dacScan step from 20 .. 39
[19:37:23.475] INFO: dacScan split into 2 runs with ntrig = 5
[19:37:23.475] INFO: run 1 of 2
[19:37:36.965] INFO: Test took 13489ms.
[19:37:37.004] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:37:37.004] INFO: run 2 of 2
[19:37:50.496] INFO: Test took 13492ms.
[19:37:50.534] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:37:50.534] INFO: dacScan step from 40 .. 59
[19:37:50.534] INFO: dacScan split into 2 runs with ntrig = 5
[19:37:50.534] INFO: run 1 of 2
[19:38:04.077] INFO: Test took 13542ms.
[19:38:04.117] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:38:04.117] INFO: run 2 of 2
[19:38:17.632] INFO: Test took 13515ms.
[19:38:17.676] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:38:17.677] INFO: dacScan step from 60 .. 79
[19:38:17.677] INFO: dacScan split into 2 runs with ntrig = 5
[19:38:17.677] INFO: run 1 of 2
[19:38:31.099] INFO: Test took 13422ms.
[19:38:31.139] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:38:31.139] INFO: run 2 of 2
[19:38:44.685] INFO: Test took 13545ms.
[19:38:44.727] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:38:44.727] INFO: dacScan step from 80 .. 99
[19:38:44.727] INFO: dacScan split into 2 runs with ntrig = 5
[19:38:44.727] INFO: run 1 of 2
[19:38:58.393] INFO: Test took 13666ms.
[19:38:58.458] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:38:58.463] INFO: run 2 of 2
[19:39:12.077] INFO: Test took 13614ms.
[19:39:12.139] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:39:12.149] INFO: dacScan step from 100 .. 119
[19:39:12.149] INFO: dacScan split into 2 runs with ntrig = 5
[19:39:12.149] INFO: run 1 of 2
[19:39:28.473] INFO: Test took 16324ms.
[19:39:28.704] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:39:28.752] INFO: run 2 of 2
[19:39:45.022] INFO: Test took 16270ms.
[19:39:45.253] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:39:45.302] INFO: dacScan step from 120 .. 139
[19:39:45.302] INFO: dacScan split into 2 runs with ntrig = 5
[19:39:45.302] INFO: run 1 of 2
[19:40:05.480] INFO: Test took 20178ms.
[19:40:05.787] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:40:05.863] INFO: run 2 of 2
[19:40:25.926] INFO: Test took 20063ms.
[19:40:26.236] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:40:26.314] INFO: dacScan step from 140 .. 159
[19:40:26.314] INFO: dacScan split into 2 runs with ntrig = 5
[19:40:26.314] INFO: run 1 of 2
[19:40:45.051] INFO: Test took 18737ms.
[19:40:45.381] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:40:45.464] INFO: run 2 of 2
[19:41:04.368] INFO: Test took 18904ms.
[19:41:04.686] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:41:04.771] INFO: dacScan step from 160 .. 179
[19:41:04.771] INFO: dacScan split into 2 runs with ntrig = 5
[19:41:04.771] INFO: run 1 of 2
[19:41:23.778] INFO: Test took 19007ms.
[19:41:24.086] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:41:24.162] INFO: run 2 of 2
[19:41:43.229] INFO: Test took 19067ms.
[19:41:43.521] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:41:43.588] INFO: dacScan step from 180 .. 181
[19:41:43.588] INFO: dacScan split into 2 runs with ntrig = 5
[19:41:43.588] INFO: run 1 of 2
[19:41:47.983] INFO: Test took 4395ms.
[19:41:48.020] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:41:48.031] INFO: run 2 of 2
[19:41:52.485] INFO: Test took 4454ms.
[19:41:52.518] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:42:33.250] INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 10 dacrange: 0 .. 170 (20/5) hits flags = 16 (plus default)
[19:42:33.265] INFO: dacScan step from 0 .. 19
[19:42:33.265] INFO: dacScan split into 2 runs with ntrig = 5
[19:42:33.265] INFO: run 1 of 2
[19:42:46.715] INFO: Test took 13449ms.
[19:42:46.761] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:42:46.761] INFO: run 2 of 2
[19:43:00.396] INFO: Test took 13635ms.
[19:43:00.441] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:43:00.441] INFO: dacScan step from 20 .. 39
[19:43:00.441] INFO: dacScan split into 2 runs with ntrig = 5
[19:43:00.441] INFO: run 1 of 2
[19:43:13.837] INFO: Test took 13396ms.
[19:43:13.882] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:43:13.882] INFO: run 2 of 2
[19:43:27.253] INFO: Test took 13371ms.
[19:43:27.294] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:43:27.294] INFO: dacScan step from 40 .. 59
[19:43:27.294] INFO: dacScan split into 2 runs with ntrig = 5
[19:43:27.294] INFO: run 1 of 2
[19:43:40.750] INFO: Test took 13456ms.
[19:43:40.788] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:43:40.788] INFO: run 2 of 2
[19:43:54.373] INFO: Test took 13585ms.
[19:43:54.417] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:43:54.417] INFO: dacScan step from 60 .. 79
[19:43:54.417] INFO: dacScan split into 2 runs with ntrig = 5
[19:43:54.417] INFO: run 1 of 2
[19:44:07.873] INFO: Test took 13456ms.
[19:44:07.911] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:44:07.911] INFO: run 2 of 2
[19:44:21.330] INFO: Test took 13418ms.
[19:44:21.370] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:44:21.370] INFO: dacScan step from 80 .. 99
[19:44:21.370] INFO: dacScan split into 2 runs with ntrig = 5
[19:44:21.370] INFO: run 1 of 2
[19:44:35.028] INFO: Test took 13657ms.
[19:44:35.090] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:44:35.096] INFO: run 2 of 2
[19:44:48.714] INFO: Test took 13617ms.
[19:44:48.777] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:44:48.787] INFO: dacScan step from 100 .. 119
[19:44:48.787] INFO: dacScan split into 2 runs with ntrig = 5
[19:44:48.787] INFO: run 1 of 2
[19:45:04.887] INFO: Test took 16100ms.
[19:45:05.109] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:45:05.157] INFO: run 2 of 2
[19:45:21.261] INFO: Test took 16104ms.
[19:45:21.486] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:45:21.535] INFO: dacScan step from 120 .. 139
[19:45:21.535] INFO: dacScan split into 2 runs with ntrig = 5
[19:45:21.535] INFO: run 1 of 2
[19:45:41.401] INFO: Test took 19865ms.
[19:45:41.705] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:45:41.775] INFO: run 2 of 2
[19:46:01.660] INFO: Test took 19885ms.
[19:46:01.945] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:46:02.012] INFO: dacScan step from 140 .. 159
[19:46:02.012] INFO: dacScan split into 2 runs with ntrig = 5
[19:46:02.012] INFO: run 1 of 2
[19:46:20.906] INFO: Test took 18894ms.
[19:46:21.185] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:46:21.259] INFO: run 2 of 2
[19:46:40.234] INFO: Test took 18975ms.
[19:46:40.555] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:46:40.632] INFO: dacScan step from 160 .. 170
[19:46:40.632] INFO: dacScan split into 2 runs with ntrig = 5
[19:46:40.632] INFO: run 1 of 2
[19:46:52.498] INFO: Test took 11865ms.
[19:46:52.672] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:46:52.726] INFO: run 2 of 2
[19:47:04.427] INFO: Test took 11701ms.
[19:47:04.604] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:47:41.790] INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 10 dacrange: 0 .. 166 (20/5) hits flags = 16 (plus default)
[19:47:41.807] INFO: dacScan step from 0 .. 19
[19:47:41.807] INFO: dacScan split into 2 runs with ntrig = 5
[19:47:41.807] INFO: run 1 of 2
[19:47:55.248] INFO: Test took 13441ms.
[19:47:55.293] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:47:55.293] INFO: run 2 of 2
[19:48:08.883] INFO: Test took 13590ms.
[19:48:08.922] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:48:08.922] INFO: dacScan step from 20 .. 39
[19:48:08.922] INFO: dacScan split into 2 runs with ntrig = 5
[19:48:08.922] INFO: run 1 of 2
[19:48:22.426] INFO: Test took 13504ms.
[19:48:22.465] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:48:22.465] INFO: run 2 of 2
[19:48:36.038] INFO: Test took 13572ms.
[19:48:36.076] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:48:36.076] INFO: dacScan step from 40 .. 59
[19:48:36.076] INFO: dacScan split into 2 runs with ntrig = 5
[19:48:36.076] INFO: run 1 of 2
[19:48:49.571] INFO: Test took 13495ms.
[19:48:49.612] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:48:49.612] INFO: run 2 of 2
[19:49:03.071] INFO: Test took 13459ms.
[19:49:03.108] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:49:03.108] INFO: dacScan step from 60 .. 79
[19:49:03.108] INFO: dacScan split into 2 runs with ntrig = 5
[19:49:03.108] INFO: run 1 of 2
[19:49:16.647] INFO: Test took 13539ms.
[19:49:16.684] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:49:16.684] INFO: run 2 of 2
[19:49:30.213] INFO: Test took 13529ms.
[19:49:30.253] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:49:30.253] INFO: dacScan step from 80 .. 99
[19:49:30.253] INFO: dacScan split into 2 runs with ntrig = 5
[19:49:30.253] INFO: run 1 of 2
[19:49:43.935] INFO: Test took 13681ms.
[19:49:43.997] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:49:43.001] INFO: run 2 of 2
[19:49:57.671] INFO: Test took 13670ms.
[19:49:57.752] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:49:57.758] INFO: dacScan step from 100 .. 119
[19:49:57.758] INFO: dacScan split into 2 runs with ntrig = 5
[19:49:57.758] INFO: run 1 of 2
[19:50:14.040] INFO: Test took 16282ms.
[19:50:14.234] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:50:14.281] INFO: run 2 of 2
[19:50:30.552] INFO: Test took 16271ms.
[19:50:30.747] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:50:30.789] INFO: dacScan step from 120 .. 139
[19:50:30.789] INFO: dacScan split into 2 runs with ntrig = 5
[19:50:30.789] INFO: run 1 of 2
[19:50:50.715] INFO: Test took 19926ms.
[19:50:51.008] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:50:51.087] INFO: run 2 of 2
[19:51:11.040] INFO: Test took 19953ms.
[19:51:11.356] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:51:11.448] INFO: dacScan step from 140 .. 159
[19:51:11.448] INFO: dacScan split into 2 runs with ntrig = 5
[19:51:11.448] INFO: run 1 of 2
[19:51:30.564] INFO: Test took 19116ms.
[19:51:30.880] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:51:30.961] INFO: run 2 of 2
[19:51:50.065] INFO: Test took 19104ms.
[19:51:50.357] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:51:50.428] INFO: dacScan step from 160 .. 166
[19:51:50.428] INFO: dacScan split into 2 runs with ntrig = 5
[19:51:50.429] INFO: run 1 of 2
[19:51:58.999] INFO: Test took 8570ms.
[19:51:59.101] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:51:59.127] INFO: run 2 of 2
[19:52:07.543] INFO: Test took 8416ms.
[19:52:07.654] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:52:44.069] INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 10 dacrange: 0 .. 167 (20/5) hits flags = 16 (plus default)
[19:52:44.084] INFO: dacScan step from 0 .. 19
[19:52:44.084] INFO: dacScan split into 2 runs with ntrig = 5
[19:52:44.084] INFO: run 1 of 2
[19:52:57.594] INFO: Test took 13510ms.
[19:52:57.637] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:52:57.637] INFO: run 2 of 2
[19:53:11.170] INFO: Test took 13532ms.
[19:53:11.214] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:53:11.214] INFO: dacScan step from 20 .. 39
[19:53:11.214] INFO: dacScan split into 2 runs with ntrig = 5
[19:53:11.214] INFO: run 1 of 2
[19:53:24.823] INFO: Test took 13609ms.
[19:53:24.866] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:53:24.866] INFO: run 2 of 2
[19:53:38.344] INFO: Test took 13478ms.
[19:53:38.384] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:53:38.384] INFO: dacScan step from 40 .. 59
[19:53:38.384] INFO: dacScan split into 2 runs with ntrig = 5
[19:53:38.384] INFO: run 1 of 2
[19:53:51.938] INFO: Test took 13554ms.
[19:53:51.977] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:53:51.977] INFO: run 2 of 2
[19:54:05.404] INFO: Test took 13427ms.
[19:54:05.441] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:54:05.441] INFO: dacScan step from 60 .. 79
[19:54:05.441] INFO: dacScan split into 2 runs with ntrig = 5
[19:54:05.441] INFO: run 1 of 2
[19:54:18.916] INFO: Test took 13475ms.
[19:54:18.954] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:54:18.954] INFO: run 2 of 2
[19:54:32.466] INFO: Test took 13512ms.
[19:54:32.506] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:54:32.506] INFO: dacScan step from 80 .. 99
[19:54:32.506] INFO: dacScan split into 2 runs with ntrig = 5
[19:54:32.506] INFO: run 1 of 2
[19:54:46.227] INFO: Test took 13721ms.
[19:54:46.291] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:54:46.296] INFO: run 2 of 2
[19:54:59.992] INFO: Test took 13696ms.
[19:55:00.062] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:55:00.070] INFO: dacScan step from 100 .. 119
[19:55:00.070] INFO: dacScan split into 2 runs with ntrig = 5
[19:55:00.070] INFO: run 1 of 2
[19:55:16.363] INFO: Test took 16293ms.
[19:55:16.580] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:55:16.626] INFO: run 2 of 2
[19:55:32.909] INFO: Test took 16282ms.
[19:55:33.116] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:55:33.163] INFO: dacScan step from 120 .. 139
[19:55:33.163] INFO: dacScan split into 2 runs with ntrig = 5
[19:55:33.163] INFO: run 1 of 2
[19:55:53.069] INFO: Test took 19906ms.
[19:55:53.358] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:55:53.426] INFO: run 2 of 2
[19:56:13.332] INFO: Test took 19906ms.
[19:56:13.649] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:56:13.726] INFO: dacScan step from 140 .. 159
[19:56:13.726] INFO: dacScan split into 2 runs with ntrig = 5
[19:56:13.726] INFO: run 1 of 2
[19:56:32.542] INFO: Test took 18816ms.
[19:56:32.881] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:56:32.979] INFO: run 2 of 2
[19:56:51.941] INFO: Test took 18962ms.
[19:56:52.218] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:56:52.292] INFO: dacScan step from 160 .. 167
[19:56:52.292] INFO: dacScan split into 2 runs with ntrig = 5
[19:56:52.292] INFO: run 1 of 2
[19:57:01.603] INFO: Test took 9310ms.
[19:57:01.728] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:57:01.761] INFO: run 2 of 2
[19:57:11.033] INFO: Test took 9272ms.
[19:57:11.146] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:57:46.630] INFO: PixTestTrim::trimBitTest() done
[19:57:46.632] INFO: PixTestTrim::doTest() done, duration: 2986 seconds
[19:57:47.620] INFO: ######################################################################
[19:57:47.620] INFO: PixTestPhOptimization::doTest() Ntrig = 10
[19:57:47.620] INFO: ######################################################################
[19:57:51.860] INFO: Test took 4239ms.
[19:57:51.899] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:57:56.278] INFO: Test took 4178ms.
[19:57:56.422] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:58:00.673] INFO: Test took 4235ms.
[19:58:00.818] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:58:00.830] INFO: The DUT currently contains the following objects:
[19:58:00.830] INFO: 2 TBM Cores tbm08c (2 ON)
[19:58:00.830] INFO: TBM Core alpha (0): 7 registers set
[19:58:00.830] INFO: TBM Core beta (1): 7 registers set
[19:58:00.830] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[19:58:00.830] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:00.830] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:00.830] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:00.830] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:00.830] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:00.830] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:00.830] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:00.830] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:00.830] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:00.830] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:00.830] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:00.830] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:00.830] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:00.830] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:00.830] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:00.830] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:01.927] INFO: Test took 1097ms.
[19:58:01.929] INFO: The DUT currently contains the following objects:
[19:58:01.929] INFO: 2 TBM Cores tbm08c (2 ON)
[19:58:01.929] INFO: TBM Core alpha (0): 7 registers set
[19:58:01.929] INFO: TBM Core beta (1): 7 registers set
[19:58:01.929] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[19:58:01.929] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:01.929] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:01.929] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:01.929] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:01.929] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:01.929] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:01.929] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:01.929] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:01.929] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:01.929] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:01.929] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:01.929] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:01.929] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:01.929] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:01.929] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:01.929] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:03.025] INFO: Test took 1096ms.
[19:58:03.027] INFO: The DUT currently contains the following objects:
[19:58:03.027] INFO: 2 TBM Cores tbm08c (2 ON)
[19:58:03.027] INFO: TBM Core alpha (0): 7 registers set
[19:58:03.027] INFO: TBM Core beta (1): 7 registers set
[19:58:03.027] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[19:58:03.027] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:03.027] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:03.027] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:03.027] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:03.027] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:03.027] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:03.027] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:03.027] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:03.027] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:03.027] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:03.027] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:03.027] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:03.027] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:03.027] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:03.027] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:03.027] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:04.123] INFO: Test took 1096ms.
[19:58:04.125] INFO: The DUT currently contains the following objects:
[19:58:04.125] INFO: 2 TBM Cores tbm08c (2 ON)
[19:58:04.125] INFO: TBM Core alpha (0): 7 registers set
[19:58:04.125] INFO: TBM Core beta (1): 7 registers set
[19:58:04.125] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[19:58:04.125] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:04.126] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:04.126] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:04.126] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:04.126] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:04.126] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:04.126] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:04.126] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:04.126] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:04.126] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:04.126] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:04.126] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:04.126] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:04.126] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:04.126] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:04.126] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:05.220] INFO: Test took 1094ms.
[19:58:05.223] INFO: The DUT currently contains the following objects:
[19:58:05.223] INFO: 2 TBM Cores tbm08c (2 ON)
[19:58:05.223] INFO: TBM Core alpha (0): 7 registers set
[19:58:05.223] INFO: TBM Core beta (1): 7 registers set
[19:58:05.223] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[19:58:05.223] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:05.223] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:05.223] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:05.223] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:05.223] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:05.223] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:05.223] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:05.223] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:05.223] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:05.223] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:05.223] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:05.223] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:05.223] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:05.223] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:05.223] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:05.223] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:06.319] INFO: Test took 1096ms.
[19:58:06.322] INFO: The DUT currently contains the following objects:
[19:58:06.322] INFO: 2 TBM Cores tbm08c (2 ON)
[19:58:06.322] INFO: TBM Core alpha (0): 7 registers set
[19:58:06.322] INFO: TBM Core beta (1): 7 registers set
[19:58:06.322] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[19:58:06.322] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:06.322] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:06.322] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:06.322] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:06.322] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:06.322] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:06.322] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:06.322] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:06.322] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:06.322] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:06.322] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:06.322] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:06.322] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:06.322] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:06.322] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:06.322] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:07.417] INFO: Test took 1095ms.
[19:58:07.418] INFO: The DUT currently contains the following objects:
[19:58:07.418] INFO: 2 TBM Cores tbm08c (2 ON)
[19:58:07.418] INFO: TBM Core alpha (0): 7 registers set
[19:58:07.418] INFO: TBM Core beta (1): 7 registers set
[19:58:07.418] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[19:58:07.418] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:07.418] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:07.418] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:07.418] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:07.418] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:07.419] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:07.419] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:07.419] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:07.419] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:07.419] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:07.419] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:07.419] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:07.419] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:07.419] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:07.419] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:07.419] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:08.516] INFO: Test took 1097ms.
[19:58:08.519] INFO: The DUT currently contains the following objects:
[19:58:08.519] INFO: 2 TBM Cores tbm08c (2 ON)
[19:58:08.519] INFO: TBM Core alpha (0): 7 registers set
[19:58:08.519] INFO: TBM Core beta (1): 7 registers set
[19:58:08.519] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[19:58:08.519] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:08.519] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:08.519] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:08.519] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:08.519] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:08.519] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:08.519] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:08.519] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:08.519] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:08.519] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:08.519] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:08.519] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:08.519] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:08.519] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:08.519] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:08.519] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:09.616] INFO: Test took 1097ms.
[19:58:09.618] INFO: The DUT currently contains the following objects:
[19:58:09.619] INFO: 2 TBM Cores tbm08c (2 ON)
[19:58:09.619] INFO: TBM Core alpha (0): 7 registers set
[19:58:09.619] INFO: TBM Core beta (1): 7 registers set
[19:58:09.619] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[19:58:09.619] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:09.619] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:09.619] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:09.619] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:09.619] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:09.619] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:09.619] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:09.619] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:09.619] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:09.619] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:09.619] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:09.619] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:09.619] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:09.619] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:09.619] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:09.619] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:10.714] INFO: Test took 1095ms.
[19:58:10.716] INFO: The DUT currently contains the following objects:
[19:58:10.716] INFO: 2 TBM Cores tbm08c (2 ON)
[19:58:10.716] INFO: TBM Core alpha (0): 7 registers set
[19:58:10.716] INFO: TBM Core beta (1): 7 registers set
[19:58:10.716] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[19:58:10.716] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:10.716] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:10.716] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:10.716] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:10.716] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:10.716] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:10.716] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:10.716] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:10.716] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:10.716] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:10.716] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:10.717] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:10.717] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:10.717] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:10.717] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:10.717] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:11.810] INFO: Test took 1093ms.
[19:58:11.811] INFO: The DUT currently contains the following objects:
[19:58:11.811] INFO: 2 TBM Cores tbm08c (2 ON)
[19:58:11.811] INFO: TBM Core alpha (0): 7 registers set
[19:58:11.811] INFO: TBM Core beta (1): 7 registers set
[19:58:11.811] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[19:58:11.811] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:11.811] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:11.811] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:11.811] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:11.811] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:11.811] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:11.811] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:11.811] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:11.811] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:11.811] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:11.811] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:11.812] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:11.812] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:11.812] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:11.812] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:11.812] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:12.905] INFO: Test took 1093ms.
[19:58:12.907] INFO: The DUT currently contains the following objects:
[19:58:12.907] INFO: 2 TBM Cores tbm08c (2 ON)
[19:58:12.907] INFO: TBM Core alpha (0): 7 registers set
[19:58:12.907] INFO: TBM Core beta (1): 7 registers set
[19:58:12.907] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[19:58:12.907] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:12.907] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:12.907] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:12.907] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:12.907] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:12.907] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:12.907] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:12.907] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:12.907] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:12.907] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:12.907] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:12.907] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:12.907] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:12.907] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:12.907] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:12.907] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:13.003] INFO: Test took 1096ms.
[19:58:14.005] INFO: The DUT currently contains the following objects:
[19:58:14.005] INFO: 2 TBM Cores tbm08c (2 ON)
[19:58:14.005] INFO: TBM Core alpha (0): 7 registers set
[19:58:14.005] INFO: TBM Core beta (1): 7 registers set
[19:58:14.005] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[19:58:14.005] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:14.005] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:14.005] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:14.005] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:14.005] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:14.006] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:14.006] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:14.006] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:14.006] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:14.006] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:14.006] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:14.006] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:14.006] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:14.006] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:14.006] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:14.006] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:15.102] INFO: Test took 1096ms.
[19:58:15.104] INFO: The DUT currently contains the following objects:
[19:58:15.104] INFO: 2 TBM Cores tbm08c (2 ON)
[19:58:15.104] INFO: TBM Core alpha (0): 7 registers set
[19:58:15.104] INFO: TBM Core beta (1): 7 registers set
[19:58:15.104] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[19:58:15.104] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:15.104] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:15.104] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:15.104] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:15.104] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:15.104] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:15.104] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:15.104] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:15.104] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:15.104] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:15.104] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:15.104] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:15.104] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:15.104] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:15.104] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:15.104] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:16.197] INFO: Test took 1093ms.
[19:58:16.199] INFO: The DUT currently contains the following objects:
[19:58:16.199] INFO: 2 TBM Cores tbm08c (2 ON)
[19:58:16.199] INFO: TBM Core alpha (0): 7 registers set
[19:58:16.199] INFO: TBM Core beta (1): 7 registers set
[19:58:16.199] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[19:58:16.199] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:16.199] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:16.199] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:16.199] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:16.199] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:16.199] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:16.199] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:16.199] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:16.199] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:16.199] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:16.199] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:16.199] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:16.199] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:16.199] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:16.199] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:16.199] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:17.292] INFO: Test took 1093ms.
[19:58:17.293] INFO: The DUT currently contains the following objects:
[19:58:17.293] INFO: 2 TBM Cores tbm08c (2 ON)
[19:58:17.293] INFO: TBM Core alpha (0): 7 registers set
[19:58:17.293] INFO: TBM Core beta (1): 7 registers set
[19:58:17.293] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[19:58:17.293] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:17.293] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:17.293] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:17.293] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:17.293] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:17.293] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:17.293] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:17.293] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:17.293] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:17.293] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:17.293] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:17.293] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:17.293] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:17.293] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:17.293] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:17.293] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[19:58:18.388] INFO: Test took 1095ms.
[19:58:18.394] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[20:01:29.417] INFO: Test took 191023ms.
[20:01:32.691] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[20:04:42.268] INFO: Test took 189577ms.
[20:04:45.808] INFO: safety margin for low PH: adding 0, margin is now 20
[20:04:45.818] INFO: safety margin for low PH: adding 0, margin is now 20
[20:04:45.830] INFO: safety margin for low PH: adding 0, margin is now 20
[20:04:45.840] INFO: safety margin for low PH: adding 0, margin is now 20
[20:04:45.852] INFO: safety margin for low PH: adding 0, margin is now 20
[20:04:45.863] INFO: safety margin for low PH: adding 0, margin is now 20
[20:04:45.874] INFO: safety margin for low PH: adding 1, margin is now 21
[20:04:45.885] INFO: safety margin for low PH: adding 2, margin is now 22
[20:04:45.895] INFO: safety margin for low PH: adding 0, margin is now 20
[20:04:45.907] INFO: safety margin for low PH: adding 0, margin is now 20
[20:04:45.919] INFO: safety margin for low PH: adding 0, margin is now 20
[20:04:45.929] INFO: safety margin for low PH: adding 0, margin is now 20
[20:04:45.941] INFO: safety margin for low PH: adding 1, margin is now 21
[20:04:45.952] INFO: safety margin for low PH: adding 2, margin is now 22
[20:04:45.964] INFO: safety margin for low PH: adding 0, margin is now 20
[20:04:45.975] INFO: safety margin for low PH: adding 0, margin is now 20
[20:04:45.987] INFO: safety margin for low PH: adding 0, margin is now 20
[20:04:45.999] INFO: safety margin for low PH: adding 0, margin is now 20
[20:04:46.010] INFO: safety margin for low PH: adding 0, margin is now 20
[20:04:46.021] INFO: safety margin for low PH: adding 0, margin is now 20
[20:04:46.073] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/dacParameters35_C0.dat
[20:04:46.073] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/dacParameters35_C1.dat
[20:04:46.073] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/dacParameters35_C2.dat
[20:04:46.073] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/dacParameters35_C3.dat
[20:04:46.074] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/dacParameters35_C4.dat
[20:04:46.074] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/dacParameters35_C5.dat
[20:04:46.074] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/dacParameters35_C6.dat
[20:04:46.074] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/dacParameters35_C7.dat
[20:04:46.075] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/dacParameters35_C8.dat
[20:04:46.075] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/dacParameters35_C9.dat
[20:04:46.075] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/dacParameters35_C10.dat
[20:04:46.075] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/dacParameters35_C11.dat
[20:04:46.076] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/dacParameters35_C12.dat
[20:04:46.076] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/dacParameters35_C13.dat
[20:04:46.076] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/dacParameters35_C14.dat
[20:04:46.076] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/dacParameters35_C15.dat
[20:04:50.310] INFO: Test took 4230ms.
[20:04:54.829] INFO: Test took 4162ms.
[20:04:59.405] INFO: Test took 4221ms.
[20:04:59.768] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[20:05:00.674] INFO: Test took 907ms.
[20:05:00.679] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[20:05:01.775] INFO: Test took 1097ms.
[20:05:01.780] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[20:05:02.876] INFO: Test took 1096ms.
[20:05:02.881] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[20:05:03.978] INFO: Test took 1097ms.
[20:05:03.983] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[20:05:05.080] INFO: Test took 1097ms.
[20:05:05.084] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[20:05:06.180] INFO: Test took 1096ms.
[20:05:06.183] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[20:05:07.278] INFO: Test took 1095ms.
[20:05:07.283] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[20:05:08.378] INFO: Test took 1096ms.
[20:05:08.382] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[20:05:09.478] INFO: Test took 1096ms.
[20:05:09.482] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[20:05:10.578] INFO: Test took 1096ms.
[20:05:10.582] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[20:05:11.679] INFO: Test took 1097ms.
[20:05:11.685] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[20:05:12.780] INFO: Test took 1095ms.
[20:05:12.786] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[20:05:13.881] INFO: Test took 1096ms.
[20:05:13.886] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[20:05:14.981] INFO: Test took 1095ms.
[20:05:14.986] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[20:05:16.087] INFO: Test took 1102ms.
[20:05:16.091] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[20:05:17.185] INFO: Test took 1094ms.
[20:05:17.189] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[20:05:18.286] INFO: Test took 1097ms.
[20:05:18.291] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[20:05:19.387] INFO: Test took 1096ms.
[20:05:19.393] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[20:05:20.489] INFO: Test took 1097ms.
[20:05:20.495] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[20:05:21.590] INFO: Test took 1096ms.
[20:05:21.596] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[20:05:22.691] INFO: Test took 1096ms.
[20:05:22.696] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[20:05:23.789] INFO: Test took 1093ms.
[20:05:23.794] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[20:05:24.890] INFO: Test took 1096ms.
[20:05:24.894] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[20:05:25.990] INFO: Test took 1096ms.
[20:05:25.995] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[20:05:27.089] INFO: Test took 1094ms.
[20:05:27.095] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[20:05:28.188] INFO: Test took 1094ms.
[20:05:28.192] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[20:05:29.285] INFO: Test took 1093ms.
[20:05:29.289] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[20:05:30.384] INFO: Test took 1095ms.
[20:05:30.389] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[20:05:31.486] INFO: Test took 1098ms.
[20:05:31.491] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[20:05:32.584] INFO: Test took 1094ms.
[20:05:32.590] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[20:05:33.685] INFO: Test took 1096ms.
[20:05:33.691] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[20:05:34.788] INFO: Test took 1098ms.
[20:05:35.350] INFO: PixTestPhOptimization::doTest() done, duration: 467 seconds
[20:05:35.350] INFO: PH scale (per ROC): 73 80 85 80 78 80 79 71 82 81 82 80 82 84 75 81
[20:05:35.350] INFO: PH offset (per ROC): 155 155 157 160 153 144 159 155 157 176 157 155 170 154 165 176
[20:05:35.571] INFO: ######################################################################
[20:05:35.571] INFO: PixTestGainPedestal::fullTest() ntrig = 10
[20:05:35.571] INFO: ######################################################################
[20:05:35.588] INFO: scanning low vcal = 10
[20:05:39.259] INFO: Test took 3671ms.
[20:05:39.269] INFO: scanning low vcal = 20
[20:05:42.955] INFO: Test took 3686ms.
[20:05:42.962] INFO: scanning low vcal = 30
[20:05:46.664] INFO: Test took 3702ms.
[20:05:46.684] INFO: scanning low vcal = 40
[20:05:50.817] INFO: Test took 4133ms.
[20:05:50.935] INFO: scanning low vcal = 50
[20:05:55.169] INFO: Test took 4234ms.
[20:05:55.299] INFO: scanning low vcal = 60
[20:05:59.546] INFO: Test took 4247ms.
[20:05:59.679] INFO: scanning low vcal = 70
[20:06:03.904] INFO: Test took 4225ms.
[20:06:04.037] INFO: scanning low vcal = 80
[20:06:08.285] INFO: Test took 4248ms.
[20:06:08.410] INFO: scanning low vcal = 90
[20:06:12.656] INFO: Test took 4246ms.
[20:06:12.772] INFO: scanning low vcal = 100
[20:06:17.007] INFO: Test took 4235ms.
[20:06:17.138] INFO: scanning low vcal = 110
[20:06:21.386] INFO: Test took 4248ms.
[20:06:21.505] INFO: scanning low vcal = 120
[20:06:25.702] INFO: Test took 4197ms.
[20:06:25.838] INFO: scanning low vcal = 130
[20:06:30.149] INFO: Test took 4311ms.
[20:06:30.323] INFO: scanning low vcal = 140
[20:06:34.658] INFO: Test took 4335ms.
[20:06:34.786] INFO: scanning low vcal = 150
[20:06:38.987] INFO: Test took 4201ms.
[20:06:39.126] INFO: scanning low vcal = 160
[20:06:43.352] INFO: Test took 4226ms.
[20:06:43.481] INFO: scanning low vcal = 170
[20:06:47.747] INFO: Test took 4266ms.
[20:06:47.876] INFO: scanning low vcal = 180
[20:06:52.071] INFO: Test took 4194ms.
[20:06:52.206] INFO: scanning low vcal = 190
[20:06:56.411] INFO: Test took 4205ms.
[20:06:56.538] INFO: scanning low vcal = 200
[20:07:00.783] INFO: Test took 4245ms.
[20:07:00.903] INFO: scanning low vcal = 210
[20:07:05.115] INFO: Test took 4212ms.
[20:07:05.251] INFO: scanning low vcal = 220
[20:07:09.505] INFO: Test took 4254ms.
[20:07:09.622] INFO: scanning low vcal = 230
[20:07:13.826] INFO: Test took 4204ms.
[20:07:13.963] INFO: scanning low vcal = 240
[20:07:18.210] INFO: Test took 4247ms.
[20:07:18.346] INFO: scanning low vcal = 250
[20:07:22.546] INFO: Test took 4200ms.
[20:07:22.684] INFO: scanning high vcal = 30 (= 210 in low range)
[20:07:26.926] INFO: Test took 4242ms.
[20:07:27.061] INFO: scanning high vcal = 50 (= 350 in low range)
[20:07:31.294] INFO: Test took 4233ms.
[20:07:31.430] INFO: scanning high vcal = 70 (= 490 in low range)
[20:07:35.636] INFO: Test took 4206ms.
[20:07:35.780] INFO: scanning high vcal = 90 (= 630 in low range)
[20:07:39.975] INFO: Test took 4195ms.
[20:07:40.111] INFO: scanning high vcal = 200 (= 1400 in low range)
[20:07:44.333] INFO: Test took 4222ms.
[20:07:45.212] INFO: PixTestGainPedestal::measure() done
[20:08:40.986] INFO: PixTestGainPedestal::fit() done
[20:08:40.986] INFO: non-linearity mean: 0.955 0.960 0.955 0.953 0.954 0.962 0.949 0.953 0.948 0.958 0.957 0.966 0.958 0.956 0.956 0.960
[20:08:40.986] INFO: non-linearity RMS: 0.007 0.005 0.006 0.005 0.006 0.005 0.008 0.006 0.006 0.005 0.005 0.005 0.005 0.006 0.005 0.006
[20:08:40.986] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/phCalibrationFitErr35_C0.dat
[20:08:41.017] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/phCalibrationFitErr35_C1.dat
[20:08:41.048] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/phCalibrationFitErr35_C2.dat
[20:08:41.079] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/phCalibrationFitErr35_C3.dat
[20:08:41.110] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/phCalibrationFitErr35_C4.dat
[20:08:41.141] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/phCalibrationFitErr35_C5.dat
[20:08:41.172] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/phCalibrationFitErr35_C6.dat
[20:08:41.202] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/phCalibrationFitErr35_C7.dat
[20:08:41.233] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/phCalibrationFitErr35_C8.dat
[20:08:41.264] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/phCalibrationFitErr35_C9.dat
[20:08:41.293] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/phCalibrationFitErr35_C10.dat
[20:08:41.320] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/phCalibrationFitErr35_C11.dat
[20:08:41.348] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/phCalibrationFitErr35_C12.dat
[20:08:41.376] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/phCalibrationFitErr35_C13.dat
[20:08:41.404] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/phCalibrationFitErr35_C14.dat
[20:08:41.431] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/phCalibrationFitErr35_C15.dat
[20:08:41.459] INFO: PixTestGainPedestal::doTest() done, duration: 185 seconds
[20:08:41.468] INFO: readReadbackCal: /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/readbackCal_C0.dat .. /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/readbackCal_C15.dat
[20:08:41.470] INFO: PixTestReadback::doTest() start.
[20:08:41.471] INFO: PixTestReadback::RES sent once
[20:08:58.019] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/readbackCal_C0.dat
[20:08:58.019] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/readbackCal_C1.dat
[20:08:58.019] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/readbackCal_C2.dat
[20:08:58.019] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/readbackCal_C3.dat
[20:08:58.019] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/readbackCal_C4.dat
[20:08:58.019] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/readbackCal_C5.dat
[20:08:58.020] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/readbackCal_C6.dat
[20:08:58.020] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/readbackCal_C7.dat
[20:08:58.020] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/readbackCal_C8.dat
[20:08:58.020] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/readbackCal_C9.dat
[20:08:58.020] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/readbackCal_C10.dat
[20:08:58.020] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/readbackCal_C11.dat
[20:08:58.020] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/readbackCal_C12.dat
[20:08:58.020] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/readbackCal_C13.dat
[20:08:58.020] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/readbackCal_C14.dat
[20:08:58.021] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/readbackCal_C15.dat
[20:08:58.055] INFO: PixTestPattern:: pg_setup set to default.
[20:08:58.056] INFO: PixTestReadback::RES sent once
[20:09:14.519] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/readbackCal_C0.dat
[20:09:14.519] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/readbackCal_C1.dat
[20:09:14.519] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/readbackCal_C2.dat
[20:09:14.519] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/readbackCal_C3.dat
[20:09:14.519] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/readbackCal_C4.dat
[20:09:14.520] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/readbackCal_C5.dat
[20:09:14.520] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/readbackCal_C6.dat
[20:09:14.520] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/readbackCal_C7.dat
[20:09:14.520] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/readbackCal_C8.dat
[20:09:14.520] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/readbackCal_C9.dat
[20:09:14.520] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/readbackCal_C10.dat
[20:09:14.520] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/readbackCal_C11.dat
[20:09:14.520] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/readbackCal_C12.dat
[20:09:14.520] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/readbackCal_C13.dat
[20:09:14.521] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/readbackCal_C14.dat
[20:09:14.521] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/readbackCal_C15.dat
[20:09:14.562] INFO: PixTestPattern:: pg_setup set to default.
[20:09:14.562] INFO: PixTestReadback::RES sent once
[20:09:27.305] INFO: PixTestPattern:: pg_setup set to default.
[20:09:27.305] INFO: Vbg will be calibrated using Vd calibration
[20:09:27.305] INFO: /*/*/*/*::: ROC 0: uncalibrated Vbg = 150.3calibrated Vbg = 1.23294 :::*/*/*/*/
[20:09:27.305] INFO: /*/*/*/*::: ROC 1: uncalibrated Vbg = 147.2calibrated Vbg = 1.2279 :::*/*/*/*/
[20:09:27.305] INFO: /*/*/*/*::: ROC 2: uncalibrated Vbg = 152.7calibrated Vbg = 1.23017 :::*/*/*/*/
[20:09:27.305] INFO: /*/*/*/*::: ROC 3: uncalibrated Vbg = 151.8calibrated Vbg = 1.23518 :::*/*/*/*/
[20:09:27.305] INFO: /*/*/*/*::: ROC 4: uncalibrated Vbg = 153.9calibrated Vbg = 1.24456 :::*/*/*/*/
[20:09:27.305] INFO: /*/*/*/*::: ROC 5: uncalibrated Vbg = 154.9calibrated Vbg = 1.23912 :::*/*/*/*/
[20:09:27.305] INFO: /*/*/*/*::: ROC 6: uncalibrated Vbg = 166.2calibrated Vbg = 1.23676 :::*/*/*/*/
[20:09:27.305] INFO: /*/*/*/*::: ROC 7: uncalibrated Vbg = 150.7calibrated Vbg = 1.24058 :::*/*/*/*/
[20:09:27.305] INFO: /*/*/*/*::: ROC 8: uncalibrated Vbg = 150.4calibrated Vbg = 1.24412 :::*/*/*/*/
[20:09:27.305] INFO: /*/*/*/*::: ROC 9: uncalibrated Vbg = 151.6calibrated Vbg = 1.23908 :::*/*/*/*/
[20:09:27.305] INFO: /*/*/*/*::: ROC 10: uncalibrated Vbg = 152.4calibrated Vbg = 1.2355 :::*/*/*/*/
[20:09:27.305] INFO: /*/*/*/*::: ROC 11: uncalibrated Vbg = 151calibrated Vbg = 1.24274 :::*/*/*/*/
[20:09:27.305] INFO: /*/*/*/*::: ROC 12: uncalibrated Vbg = 159calibrated Vbg = 1.24295 :::*/*/*/*/
[20:09:27.306] INFO: /*/*/*/*::: ROC 13: uncalibrated Vbg = 141.5calibrated Vbg = 1.2488 :::*/*/*/*/
[20:09:27.306] INFO: /*/*/*/*::: ROC 14: uncalibrated Vbg = 156.3calibrated Vbg = 1.23595 :::*/*/*/*/
[20:09:27.306] INFO: /*/*/*/*::: ROC 15: uncalibrated Vbg = 156.1calibrated Vbg = 1.22879 :::*/*/*/*/
[20:09:27.309] INFO: PixTestReadback::RES sent once
[20:13:22.478] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/readbackCal_C0.dat
[20:13:22.478] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/readbackCal_C1.dat
[20:13:22.478] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/readbackCal_C2.dat
[20:13:22.478] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/readbackCal_C3.dat
[20:13:22.478] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/readbackCal_C4.dat
[20:13:22.478] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/readbackCal_C5.dat
[20:13:22.478] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/readbackCal_C6.dat
[20:13:22.478] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/readbackCal_C7.dat
[20:13:22.478] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/readbackCal_C8.dat
[20:13:22.478] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/readbackCal_C9.dat
[20:13:22.478] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/readbackCal_C10.dat
[20:13:22.479] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/readbackCal_C11.dat
[20:13:22.479] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/readbackCal_C12.dat
[20:13:22.479] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/readbackCal_C13.dat
[20:13:22.479] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/readbackCal_C14.dat
[20:13:22.479] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4556_FullQualification_2015-08-10_12h35m_1439206531/002_Fulltest_m20/readbackCal_C15.dat
[20:13:22.521] INFO: PixTestPattern:: pg_setup set to default.
[20:13:22.524] INFO: PixTestReadback::doTest() done
[20:13:22.542] INFO: enter test to run
[20:13:22.542] INFO: test: q no parameter change
[20:13:22.693] QUIET: Connection to board 178 closed.
[20:13:22.696] INFO: pXar: this is the end, my friend