[17:13:57.265] INFO: *** Welcome to pxar ***
[17:13:57.265] INFO: *** Today: 2015/08/04
[17:13:57.265] INFO: readRocDacs: /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters_C0.dat .. /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters_C15.dat
[17:13:57.266] INFO: readTbmDacs: /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/tbmParameters_C0a.dat .. /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/tbmParameters_C0b.dat
[17:13:57.266] INFO: readMaskFile: /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/defaultMaskFile.dat
[17:13:57.266] INFO: readTrimFile: /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/trimParameters_C0.dat .. /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/trimParameters_C15.dat
[17:13:57.373] INFO: clk: 4
[17:13:57.373] INFO: ctr: 4
[17:13:57.373] INFO: sda: 19
[17:13:57.373] INFO: tin: 9
[17:13:57.373] INFO: level: 15
[17:13:57.373] INFO: triggerdelay: 0
[17:13:57.373] QUIET: Instanciating API for pxar prod-01+36~geb5ac3f
[17:13:57.373] INFO: Log level: INFO
[17:13:57.385] INFO: Found DTB DTB_WZ4THG
[17:13:57.394] QUIET: Connection to board DTB_WZ4THG opened.
[17:13:57.398] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 173
HW version: DTB1.2
FW version: 4.2
SW version: 4.2
USB id: DTB_WZ4THG
MAC address: 40D8551180AD
Hostname: pixelDTB173
Comment:
------------------------------------------------------
[17:13:57.403] INFO: RPC call hashes of host and DTB match: 447413373
[17:13:59.151] INFO: DUT info:
[17:13:59.151] INFO: The DUT currently contains the following objects:
[17:13:59.151] INFO: 2 TBM Cores tbm08c (2 ON)
[17:13:59.151] INFO: TBM Core alpha (0): 7 registers set
[17:13:59.151] INFO: TBM Core beta (1): 7 registers set
[17:13:59.151] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[17:13:59.151] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[17:13:59.151] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[17:13:59.151] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[17:13:59.151] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[17:13:59.151] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[17:13:59.151] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[17:13:59.151] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[17:13:59.151] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[17:13:59.151] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[17:13:59.151] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[17:13:59.151] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[17:13:59.151] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[17:13:59.151] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[17:13:59.152] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[17:13:59.152] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[17:13:59.152] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[17:13:59.553] INFO: enter 'restricted' command line mode
[17:13:59.553] INFO: enter test to run
[17:13:59.553] INFO: test: pretest no parameter change
[17:13:59.553] INFO: running: pretest
[17:13:59.559] INFO: ######################################################################
[17:13:59.559] INFO: PixTestPretest::doTest()
[17:13:59.559] INFO: ######################################################################
[17:13:59.560] INFO: ----------------------------------------------------------------------
[17:13:59.560] INFO: PixTestPretest::programROC()
[17:13:59.560] INFO: ----------------------------------------------------------------------
[17:14:17.583] INFO: PixTestPretest::programROC() done: ROCs are all programmable
[17:14:17.583] INFO: IA differences per ROC: 19.3 20.1 19.3 20.9 19.3 17.7 16.9 19.3 19.3 17.7 18.5 19.3 17.7 18.5 20.1 18.5
[17:14:17.673] INFO: ----------------------------------------------------------------------
[17:14:17.673] INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[17:14:17.673] INFO: ----------------------------------------------------------------------
[17:14:37.342] INFO: PixTestPretest::setVana() done, Module Ia 389.1 mA = 24.3188 mA/ROC
[17:14:37.346] INFO: ----------------------------------------------------------------------
[17:14:37.346] INFO: PixTestPretest::findWorkingPixel()
[17:14:37.346] INFO: ----------------------------------------------------------------------
[17:14:45.073] INFO: Test took 7720ms.
[17:14:45.413] INFO: Found working pixel in all ROCs: col/row = 12/22
[17:14:45.467] INFO: ----------------------------------------------------------------------
[17:14:45.467] INFO: PixTestPretest::setVthrCompCalDel()
[17:14:45.467] INFO: ----------------------------------------------------------------------
[17:14:53.200] INFO: Test took 7726ms.
[17:14:53.578] INFO: PixTestPretest::setVthrCompCalDel() done
[17:14:53.578] INFO: CalDel: 111 111 112 98 118 119 143 134 117 134 154 135 111 120 132 144
[17:14:53.578] INFO: VthrComp: 51 53 51 51 51 51 51 51 51 52 51 51 51 51 51 51
[17:14:53.584] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters_C0.dat
[17:14:53.584] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters_C1.dat
[17:14:53.584] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters_C2.dat
[17:14:53.585] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters_C3.dat
[17:14:53.585] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters_C4.dat
[17:14:53.585] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters_C5.dat
[17:14:53.585] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters_C6.dat
[17:14:53.586] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters_C7.dat
[17:14:53.586] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters_C8.dat
[17:14:53.586] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters_C9.dat
[17:14:53.586] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters_C10.dat
[17:14:53.587] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters_C11.dat
[17:14:53.587] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters_C12.dat
[17:14:53.587] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters_C13.dat
[17:14:53.587] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters_C14.dat
[17:14:53.588] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters_C15.dat
[17:14:53.588] INFO: PixTestPretest::doTest() done, duration: 54 seconds
[17:14:53.710] INFO: enter test to run
[17:14:53.710] INFO: test: fulltest no parameter change
[17:14:53.710] INFO: running: fulltest
[17:14:53.710] INFO: ######################################################################
[17:14:53.710] INFO: PixTestFullTest::doTest()
[17:14:53.710] INFO: ######################################################################
[17:14:53.712] INFO: ######################################################################
[17:14:53.712] INFO: PixTestAlive::doTest()
[17:14:53.712] INFO: ######################################################################
[17:14:53.714] INFO: ----------------------------------------------------------------------
[17:14:53.714] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[17:14:53.714] INFO: ----------------------------------------------------------------------
[17:14:57.922] INFO: Test took 4206ms.
[17:14:57.958] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:14:58.209] INFO: PixTestAlive::aliveTest() done
[17:14:58.209] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[17:14:58.211] INFO: ----------------------------------------------------------------------
[17:14:58.211] INFO: PixTestAlive::maskTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[17:14:58.211] INFO: ----------------------------------------------------------------------
[17:15:01.301] INFO: Test took 3088ms.
[17:15:01.308] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:15:01.308] INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[17:15:01.567] INFO: PixTestAlive::maskTest() done
[17:15:01.567] INFO: number of mask-defect pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[17:15:01.570] INFO: ----------------------------------------------------------------------
[17:15:01.570] INFO: PixTestAlive::addressDecodingTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[17:15:01.570] INFO: ----------------------------------------------------------------------
[17:15:05.812] INFO: Test took 4239ms.
[17:15:05.850] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:15:06.122] INFO: PixTestAlive::addressDecodingTest() done
[17:15:06.122] INFO: number of address-decoding pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[17:15:06.122] INFO: PixTestAlive::doTest() done, duration: 12 seconds
[17:15:06.135] INFO: ######################################################################
[17:15:06.135] INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[17:15:06.135] INFO: ######################################################################
[17:15:06.139] INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (30/5) hits flags = 2 (plus default)
[17:15:06.158] INFO: dacScan step from 0 .. 29
[17:15:06.158] INFO: dacScan split into 1 runs with ntrig = 5
[17:15:06.158] INFO: run 1 of 1
[17:15:25.230] INFO: Test took 19072ms.
[17:15:25.295] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:15:25.295] INFO: dacScan step from 30 .. 59
[17:15:25.295] INFO: dacScan split into 1 runs with ntrig = 5
[17:15:25.295] INFO: run 1 of 1
[17:15:44.750] INFO: Test took 19455ms.
[17:15:44.874] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:15:44.884] INFO: dacScan step from 60 .. 89
[17:15:44.884] INFO: dacScan split into 1 runs with ntrig = 5
[17:15:44.884] INFO: run 1 of 1
[17:16:09.525] INFO: Test took 24641ms.
[17:16:10.028] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:16:10.123] INFO: dacScan step from 90 .. 119
[17:16:10.123] INFO: dacScan split into 1 runs with ntrig = 5
[17:16:10.123] INFO: run 1 of 1
[17:16:37.016] INFO: Test took 26893ms.
[17:16:37.699] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:16:37.827] INFO: dacScan step from 120 .. 149
[17:16:37.827] INFO: dacScan split into 1 runs with ntrig = 5
[17:16:37.827] INFO: run 1 of 1
[17:17:03.769] INFO: Test took 25942ms.
[17:17:04.208] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:17:47.934] INFO: PixTestBBMap::doTest() done, duration: 161 seconds
[17:17:47.934] INFO: number of dead bumps (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[17:17:47.934] INFO: separation cut (per ROC): 128 127 98 119 97 101 122 115 136 121 88 114 106 114 113 118
[17:17:48.046] INFO: ######################################################################
[17:17:48.046] INFO: PixTestScurves::fullTest() ntrig = 50, dacs/step = -1, ntrig/step = 1
[17:17:48.046] INFO: ######################################################################
[17:17:48.047] INFO: ----------------------------------------------------------------------
[17:17:48.047] INFO: PixTestScurves::scurves(Vcal), ntrig = 50, dacs/step = -1, ntrig/step = 1
[17:17:48.047] INFO: ----------------------------------------------------------------------
[17:17:48.047] INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 0 .. 149 (-1/1) hits flags = 16 (plus default)
[17:17:48.063] INFO: dacScan split into 50 runs with ntrig = 1
[17:17:48.063] INFO: run 1 of 50
[17:18:36.681] INFO: Test took 48618ms.
[17:18:37.117] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:18:37.447] INFO: run 2 of 50
[17:19:26.185] INFO: Test took 48738ms.
[17:19:26.630] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:19:26.977] INFO: run 3 of 50
[17:20:15.627] INFO: Test took 48650ms.
[17:20:16.061] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:20:16.453] INFO: run 4 of 50
[17:21:05.174] INFO: Test took 48721ms.
[17:21:05.710] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:21:06.094] INFO: run 5 of 50
[17:21:54.772] INFO: Test took 48678ms.
[17:21:55.239] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:21:55.545] INFO: run 6 of 50
[17:22:44.162] INFO: Test took 48617ms.
[17:22:44.624] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:22:44.900] INFO: run 7 of 50
[17:23:33.487] INFO: Test took 48586ms.
[17:23:33.916] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:23:34.159] INFO: run 8 of 50
[17:24:22.763] INFO: Test took 48604ms.
[17:24:23.226] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:24:23.480] INFO: run 9 of 50
[17:25:12.163] INFO: Test took 48683ms.
[17:25:12.628] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:25:12.928] INFO: run 10 of 50
[17:26:01.645] INFO: Test took 48717ms.
[17:26:02.213] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:26:02.476] INFO: run 11 of 50
[17:26:51.167] INFO: Test took 48691ms.
[17:26:51.629] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:26:51.912] INFO: run 12 of 50
[17:27:40.571] INFO: Test took 48658ms.
[17:27:41.036] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:27:41.363] INFO: run 13 of 50
[17:28:29.958] INFO: Test took 48594ms.
[17:28:30.403] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:28:30.714] INFO: run 14 of 50
[17:29:19.357] INFO: Test took 48643ms.
[17:29:19.811] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:29:20.135] INFO: run 15 of 50
[17:30:08.833] INFO: Test took 48698ms.
[17:30:09.246] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:30:09.563] INFO: run 16 of 50
[17:30:58.300] INFO: Test took 48737ms.
[17:30:58.750] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:30:59.013] INFO: run 17 of 50
[17:31:47.689] INFO: Test took 48675ms.
[17:31:48.181] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:31:48.533] INFO: run 18 of 50
[17:32:37.336] INFO: Test took 48803ms.
[17:32:37.764] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:32:38.010] INFO: run 19 of 50
[17:33:26.657] INFO: Test took 48647ms.
[17:33:27.089] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:33:27.465] INFO: run 20 of 50
[17:34:16.222] INFO: Test took 48757ms.
[17:34:16.678] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:34:16.969] INFO: run 21 of 50
[17:35:05.669] INFO: Test took 48700ms.
[17:35:06.142] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:35:06.437] INFO: run 22 of 50
[17:35:55.104] INFO: Test took 48667ms.
[17:35:55.541] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:35:55.846] INFO: run 23 of 50
[17:36:44.588] INFO: Test took 48742ms.
[17:36:45.040] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:36:45.343] INFO: run 24 of 50
[17:37:34.056] INFO: Test took 48712ms.
[17:37:34.507] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:37:34.787] INFO: run 25 of 50
[17:38:23.478] INFO: Test took 48691ms.
[17:38:23.938] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:38:24.218] INFO: run 26 of 50
[17:39:12.891] INFO: Test took 48673ms.
[17:39:13.370] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:39:13.647] INFO: run 27 of 50
[17:40:02.401] INFO: Test took 48754ms.
[17:40:02.817] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:40:03.110] INFO: run 28 of 50
[17:40:51.795] INFO: Test took 48684ms.
[17:40:52.208] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:40:52.475] INFO: run 29 of 50
[17:41:41.161] INFO: Test took 48686ms.
[17:41:41.629] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:41:41.920] INFO: run 30 of 50
[17:42:30.628] INFO: Test took 48708ms.
[17:42:31.077] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:42:31.352] INFO: run 31 of 50
[17:43:20.054] INFO: Test took 48702ms.
[17:43:20.536] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:43:20.818] INFO: run 32 of 50
[17:44:09.582] INFO: Test took 48764ms.
[17:44:10.062] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:44:10.337] INFO: run 33 of 50
[17:44:59.125] INFO: Test took 48788ms.
[17:44:59.574] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:44:59.847] INFO: run 34 of 50
[17:45:48.573] INFO: Test took 48726ms.
[17:45:49.026] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:45:49.305] INFO: run 35 of 50
[17:46:38.030] INFO: Test took 48725ms.
[17:46:38.487] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:46:38.771] INFO: run 36 of 50
[17:47:27.483] INFO: Test took 48712ms.
[17:47:27.902] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:47:28.191] INFO: run 37 of 50
[17:48:16.952] INFO: Test took 48761ms.
[17:48:17.372] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:48:17.673] INFO: run 38 of 50
[17:49:06.403] INFO: Test took 48730ms.
[17:49:06.837] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:49:07.120] INFO: run 39 of 50
[17:49:55.859] INFO: Test took 48739ms.
[17:49:56.315] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:49:56.590] INFO: run 40 of 50
[17:50:45.341] INFO: Test took 48751ms.
[17:50:45.794] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:50:46.080] INFO: run 41 of 50
[17:51:34.925] INFO: Test took 48845ms.
[17:51:35.366] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:51:35.595] INFO: run 42 of 50
[17:52:24.354] INFO: Test took 48758ms.
[17:52:24.792] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:52:25.075] INFO: run 43 of 50
[17:53:13.919] INFO: Test took 48844ms.
[17:53:14.352] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:53:14.627] INFO: run 44 of 50
[17:54:03.373] INFO: Test took 48745ms.
[17:54:03.821] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:54:04.080] INFO: run 45 of 50
[17:54:52.782] INFO: Test took 48701ms.
[17:54:53.247] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:54:53.505] INFO: run 46 of 50
[17:55:42.277] INFO: Test took 48772ms.
[17:55:42.723] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:55:43.011] INFO: run 47 of 50
[17:56:31.843] INFO: Test took 48832ms.
[17:56:32.271] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:56:32.568] INFO: run 48 of 50
[17:57:21.307] INFO: Test took 48739ms.
[17:57:21.740] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:57:22.031] INFO: run 49 of 50
[17:58:10.860] INFO: Test took 48829ms.
[17:58:11.324] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:58:11.599] INFO: run 50 of 50
[17:59:00.438] INFO: Test took 48838ms.
[17:59:00.891] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:59:01.140] INFO: dumping ASCII scurve output file: SCurveData
[17:59:03.774] INFO: dumping ASCII scurve output file: SCurveData
[17:59:06.142] INFO: dumping ASCII scurve output file: SCurveData
[17:59:08.764] INFO: dumping ASCII scurve output file: SCurveData
[17:59:11.258] INFO: dumping ASCII scurve output file: SCurveData
[17:59:13.970] INFO: dumping ASCII scurve output file: SCurveData
[17:59:16.576] INFO: dumping ASCII scurve output file: SCurveData
[17:59:19.323] INFO: dumping ASCII scurve output file: SCurveData
[17:59:22.139] INFO: dumping ASCII scurve output file: SCurveData
[17:59:24.978] INFO: dumping ASCII scurve output file: SCurveData
[17:59:27.739] INFO: dumping ASCII scurve output file: SCurveData
[17:59:30.392] INFO: dumping ASCII scurve output file: SCurveData
[17:59:33.093] INFO: dumping ASCII scurve output file: SCurveData
[17:59:35.793] INFO: dumping ASCII scurve output file: SCurveData
[17:59:38.681] INFO: dumping ASCII scurve output file: SCurveData
[17:59:41.386] INFO: dumping ASCII scurve output file: SCurveData
[17:59:44.229] INFO: PixTestScurves::scurves() done
[17:59:44.229] INFO: Vcal mean: 103.55 116.24 86.32 100.06 90.45 86.89 88.12 83.78 103.52 109.98 82.45 98.46 93.51 104.25 94.34 86.32
[17:59:44.229] INFO: Vcal RMS: 5.99 6.07 5.48 5.47 6.20 5.31 5.45 5.52 5.61 6.19 5.47 5.87 5.46 6.15 6.03 5.19
[17:59:44.229] INFO: PixTestScurves::fullTest() done, duration: 2516 seconds
[17:59:44.355] INFO: ######################################################################
[17:59:44.355] INFO: PixTestTrim::doTest()
[17:59:44.355] INFO: ######################################################################
[17:59:44.357] INFO: ----------------------------------------------------------------------
[17:59:44.357] INFO: PixTestTrim::trimTest() ntrig = 10, vcal = 35
[17:59:44.357] INFO: ----------------------------------------------------------------------
[17:59:44.526] INFO: ---> VthrComp thr map (minimal VthrComp)
[17:59:44.526] INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 5 dacrange: 0 .. 159 (20/-1) hits flags = 16 (plus default)
[17:59:44.542] INFO: dacScan step from 0 .. 19
[17:59:44.542] INFO: dacScan split into 1 runs with ntrig = 5
[17:59:44.543] INFO: run 1 of 1
[17:59:58.186] INFO: Test took 13643ms.
[17:59:58.230] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:59:58.230] INFO: dacScan step from 20 .. 39
[17:59:58.230] INFO: dacScan split into 1 runs with ntrig = 5
[17:59:58.230] INFO: run 1 of 1
[18:00:11.874] INFO: Test took 13644ms.
[18:00:11.927] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:00:11.927] INFO: dacScan step from 40 .. 59
[18:00:11.927] INFO: dacScan split into 1 runs with ntrig = 5
[18:00:11.927] INFO: run 1 of 1
[18:00:25.540] INFO: Test took 13613ms.
[18:00:25.591] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:00:25.591] INFO: dacScan step from 60 .. 79
[18:00:25.591] INFO: dacScan split into 1 runs with ntrig = 5
[18:00:25.591] INFO: run 1 of 1
[18:00:39.280] INFO: Test took 13689ms.
[18:00:39.328] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:00:39.328] INFO: dacScan step from 80 .. 99
[18:00:39.328] INFO: dacScan split into 1 runs with ntrig = 5
[18:00:39.328] INFO: run 1 of 1
[18:00:53.240] INFO: Test took 13912ms.
[18:00:53.330] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:00:53.337] INFO: dacScan step from 100 .. 119
[18:00:53.337] INFO: dacScan split into 1 runs with ntrig = 5
[18:00:53.337] INFO: run 1 of 1
[18:01:09.580] INFO: Test took 16243ms.
[18:01:09.801] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:01:09.848] INFO: dacScan step from 120 .. 139
[18:01:09.848] INFO: dacScan split into 1 runs with ntrig = 5
[18:01:09.848] INFO: run 1 of 1
[18:01:28.488] INFO: Test took 18640ms.
[18:01:28.803] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:01:28.876] INFO: dacScan step from 140 .. 159
[18:01:28.876] INFO: dacScan split into 1 runs with ntrig = 5
[18:01:28.876] INFO: run 1 of 1
[18:01:44.325] INFO: Test took 15449ms.
[18:01:44.497] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:02:24.150] INFO: ROC 0 VthrComp = 106
[18:02:24.150] INFO: ROC 1 VthrComp = 109
[18:02:24.150] INFO: ROC 2 VthrComp = 91
[18:02:24.150] INFO: ROC 3 VthrComp = 105
[18:02:24.151] INFO: ROC 4 VthrComp = 88
[18:02:24.151] INFO: ROC 5 VthrComp = 93
[18:02:24.151] INFO: ROC 6 VthrComp = 89
[18:02:24.151] INFO: ROC 7 VthrComp = 87
[18:02:24.151] INFO: ROC 8 VthrComp = 105
[18:02:24.151] INFO: ROC 9 VthrComp = 105
[18:02:24.152] INFO: ROC 10 VthrComp = 80
[18:02:24.152] INFO: ROC 11 VthrComp = 101
[18:02:24.152] INFO: ROC 12 VthrComp = 97
[18:02:24.152] INFO: ROC 13 VthrComp = 105
[18:02:24.152] INFO: ROC 14 VthrComp = 97
[18:02:24.152] INFO: ROC 15 VthrComp = 91
[18:02:24.152] INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[18:02:24.152] INFO: ---> dac: vcal name: TrimThr1 ntrig: 5 dacrange: 0 .. 159 (20/-1) hits flags = 16 (plus default)
[18:02:24.168] INFO: dacScan step from 0 .. 19
[18:02:24.168] INFO: dacScan split into 1 runs with ntrig = 5
[18:02:24.168] INFO: run 1 of 1
[18:02:37.814] INFO: Test took 13646ms.
[18:02:37.861] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:02:37.861] INFO: dacScan step from 20 .. 39
[18:02:37.861] INFO: dacScan split into 1 runs with ntrig = 5
[18:02:37.861] INFO: run 1 of 1
[18:02:51.560] INFO: Test took 13699ms.
[18:02:51.617] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:02:51.624] INFO: dacScan step from 40 .. 59
[18:02:51.624] INFO: dacScan split into 1 runs with ntrig = 5
[18:02:51.624] INFO: run 1 of 1
[18:03:08.430] INFO: Test took 16806ms.
[18:03:08.701] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:03:08.762] INFO: dacScan step from 60 .. 79
[18:03:08.762] INFO: dacScan split into 1 runs with ntrig = 5
[18:03:08.762] INFO: run 1 of 1
[18:03:27.635] INFO: Test took 18873ms.
[18:03:27.953] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:03:28.030] INFO: dacScan step from 80 .. 99
[18:03:28.030] INFO: dacScan split into 1 runs with ntrig = 5
[18:03:28.030] INFO: run 1 of 1
[18:03:46.912] INFO: Test took 18881ms.
[18:03:47.258] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:03:47.339] INFO: dacScan step from 100 .. 119
[18:03:47.339] INFO: dacScan split into 1 runs with ntrig = 5
[18:03:47.339] INFO: run 1 of 1
[18:04:06.317] INFO: Test took 18977ms.
[18:04:06.658] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:04:06.744] INFO: dacScan step from 120 .. 139
[18:04:06.744] INFO: dacScan split into 1 runs with ntrig = 5
[18:04:06.744] INFO: run 1 of 1
[18:04:27.260] INFO: Test took 20516ms.
[18:04:27.590] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:04:27.676] INFO: dacScan step from 140 .. 159
[18:04:27.676] INFO: dacScan split into 1 runs with ntrig = 5
[18:04:27.676] INFO: run 1 of 1
[18:04:46.816] INFO: Test took 19140ms.
[18:04:47.163] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:05:31.925] INFO: roc 0 with ID = 0 has maximal Vcal 62.5522 for pixel 8/79 mean/min/max = 48.2335/33.8453/62.6218
[18:05:31.926] INFO: roc 1 with ID = 1 has maximal Vcal 72.4185 for pixel 9/79 mean/min/max = 54.6499/36.8763/72.4235
[18:05:31.926] INFO: roc 2 with ID = 2 has maximal Vcal 59.0067 for pixel 18/70 mean/min/max = 45.6372/32.0222/59.2522
[18:05:31.927] INFO: roc 3 with ID = 3 has maximal Vcal 61.1466 for pixel 5/77 mean/min/max = 47.6081/33.9555/61.2607
[18:05:31.927] INFO: roc 4 with ID = 4 has maximal Vcal 63.73 for pixel 21/76 mean/min/max = 48.0012/31.9375/64.0649
[18:05:31.928] INFO: roc 5 with ID = 5 has maximal Vcal 57.4793 for pixel 20/56 mean/min/max = 44.9478/32.3881/57.5075
[18:05:31.928] INFO: roc 6 with ID = 6 has maximal Vcal 58.7693 for pixel 45/5 mean/min/max = 46.0868/33.2859/58.8878
[18:05:31.929] INFO: roc 7 with ID = 7 has maximal Vcal 59.5139 for pixel 2/53 mean/min/max = 45.6247/31.7251/59.5243
[18:05:31.929] INFO: roc 8 with ID = 8 has maximal Vcal 60.9862 for pixel 51/43 mean/min/max = 46.9818/32.9456/61.0181
[18:05:31.930] INFO: roc 9 with ID = 9 has maximal Vcal 67.1461 for pixel 22/5 mean/min/max = 50.0304/32.7997/67.2611
[18:05:31.930] INFO: roc 10 with ID = 10 has maximal Vcal 61.7905 for pixel 51/11 mean/min/max = 46.7017/31.277/62.1264
[18:05:31.931] INFO: roc 11 with ID = 11 has maximal Vcal 60.0288 for pixel 9/5 mean/min/max = 45.9589/31.7093/60.2086
[18:05:31.931] INFO: roc 12 with ID = 12 has maximal Vcal 59.1403 for pixel 9/78 mean/min/max = 45.5272/31.7593/59.2952
[18:05:31.932] INFO: roc 13 with ID = 13 has maximal Vcal 62.5739 for pixel 4/66 mean/min/max = 47.6736/32.756/62.5911
[18:05:31.932] INFO: roc 14 with ID = 14 has maximal Vcal 59.3364 for pixel 16/70 mean/min/max = 45.1774/30.9223/59.4325
[18:05:31.933] INFO: roc 15 with ID = 15 has maximal Vcal 58.4361 for pixel 10/45 mean/min/max = 45.2706/32.0187/58.5226
[18:05:31.933] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:06:55.201] INFO: Test took 83268ms.
[18:06:57.514] INFO: ---> dac: vcal name: TrimThr2 ntrig: 10 dacrange: 0 .. 199 (20/5) hits flags = 16 (plus default)
[18:06:57.528] INFO: dacScan step from 0 .. 19
[18:06:57.528] INFO: dacScan split into 2 runs with ntrig = 5
[18:06:57.528] INFO: run 1 of 2
[18:07:11.126] INFO: Test took 13598ms.
[18:07:11.192] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:07:11.195] INFO: run 2 of 2
[18:07:24.870] INFO: Test took 13675ms.
[18:07:24.924] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:07:24.927] INFO: dacScan step from 20 .. 39
[18:07:24.927] INFO: dacScan split into 2 runs with ntrig = 5
[18:07:24.927] INFO: run 1 of 2
[18:07:41.140] INFO: Test took 16213ms.
[18:07:41.394] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:07:41.455] INFO: run 2 of 2
[18:07:57.557] INFO: Test took 16102ms.
[18:07:57.801] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:07:57.857] INFO: dacScan step from 40 .. 59
[18:07:57.857] INFO: dacScan split into 2 runs with ntrig = 5
[18:07:57.857] INFO: run 1 of 2
[18:08:16.595] INFO: Test took 18738ms.
[18:08:16.934] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:08:17.016] INFO: run 2 of 2
[18:08:35.761] INFO: Test took 18745ms.
[18:08:36.192] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:08:36.259] INFO: dacScan step from 60 .. 79
[18:08:36.259] INFO: dacScan split into 2 runs with ntrig = 5
[18:08:36.259] INFO: run 1 of 2
[18:08:55.074] INFO: Test took 18815ms.
[18:08:55.499] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:08:55.597] INFO: run 2 of 2
[18:09:14.464] INFO: Test took 18867ms.
[18:09:14.803] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:09:14.888] INFO: dacScan step from 80 .. 99
[18:09:14.889] INFO: dacScan split into 2 runs with ntrig = 5
[18:09:14.889] INFO: run 1 of 2
[18:09:33.777] INFO: Test took 18888ms.
[18:09:34.114] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:09:34.214] INFO: run 2 of 2
[18:09:53.011] INFO: Test took 18796ms.
[18:09:53.344] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:09:53.444] INFO: dacScan step from 100 .. 119
[18:09:53.444] INFO: dacScan split into 2 runs with ntrig = 5
[18:09:53.444] INFO: run 1 of 2
[18:10:12.409] INFO: Test took 18965ms.
[18:10:12.743] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:10:12.845] INFO: run 2 of 2
[18:10:31.753] INFO: Test took 18908ms.
[18:10:32.093] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:10:32.196] INFO: dacScan step from 120 .. 139
[18:10:32.196] INFO: dacScan split into 2 runs with ntrig = 5
[18:10:32.196] INFO: run 1 of 2
[18:10:52.631] INFO: Test took 20435ms.
[18:10:52.965] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:10:53.048] INFO: run 2 of 2
[18:11:13.511] INFO: Test took 20462ms.
[18:11:13.849] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:11:13.933] INFO: dacScan step from 140 .. 159
[18:11:13.933] INFO: dacScan split into 2 runs with ntrig = 5
[18:11:13.933] INFO: run 1 of 2
[18:11:33.147] INFO: Test took 19214ms.
[18:11:33.480] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:11:33.560] INFO: run 2 of 2
[18:11:52.614] INFO: Test took 19054ms.
[18:11:52.959] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:11:53.041] INFO: dacScan step from 160 .. 179
[18:11:53.041] INFO: dacScan split into 2 runs with ntrig = 5
[18:11:53.041] INFO: run 1 of 2
[18:12:12.082] INFO: Test took 19041ms.
[18:12:12.398] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:12:12.477] INFO: run 2 of 2
[18:12:31.475] INFO: Test took 18998ms.
[18:12:31.811] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:12:31.909] INFO: dacScan step from 180 .. 199
[18:12:31.909] INFO: dacScan split into 2 runs with ntrig = 5
[18:12:31.909] INFO: run 1 of 2
[18:12:51.816] INFO: Test took 19906ms.
[18:12:52.125] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:12:52.200] INFO: run 2 of 2
[18:13:11.980] INFO: Test took 19780ms.
[18:13:12.314] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:13:57.926] INFO: ---> TrimStepCorr4 extremal thresholds: 0.037003 .. 255.000000
[18:13:58.076] INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 4 dacrange: 0 .. 255 (20/-1) hits flags = 16 (plus default)
[18:13:58.091] INFO: dacScan step from 0 .. 19
[18:13:58.091] INFO: dacScan split into 1 runs with ntrig = 4
[18:13:58.091] INFO: run 1 of 1
[18:14:10.514] INFO: Test took 12423ms.
[18:14:10.562] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:14:10.563] INFO: dacScan step from 20 .. 39
[18:14:10.563] INFO: dacScan split into 1 runs with ntrig = 4
[18:14:10.563] INFO: run 1 of 1
[18:14:23.973] INFO: Test took 13410ms.
[18:14:24.113] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:14:24.147] INFO: dacScan step from 40 .. 59
[18:14:24.147] INFO: dacScan split into 1 runs with ntrig = 4
[18:14:24.147] INFO: run 1 of 1
[18:14:40.723] INFO: Test took 16575ms.
[18:14:41.013] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:14:41.093] INFO: dacScan step from 60 .. 79
[18:14:41.093] INFO: dacScan split into 1 runs with ntrig = 4
[18:14:41.093] INFO: run 1 of 1
[18:14:57.779] INFO: Test took 16686ms.
[18:14:58.061] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:14:58.145] INFO: dacScan step from 80 .. 99
[18:14:58.145] INFO: dacScan split into 1 runs with ntrig = 4
[18:14:58.145] INFO: run 1 of 1
[18:15:14.961] INFO: Test took 16816ms.
[18:15:15.248] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:15:15.319] INFO: dacScan step from 100 .. 119
[18:15:15.319] INFO: dacScan split into 1 runs with ntrig = 4
[18:15:15.319] INFO: run 1 of 1
[18:15:32.153] INFO: Test took 16834ms.
[18:15:32.438] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:15:32.508] INFO: dacScan step from 120 .. 139
[18:15:32.508] INFO: dacScan split into 1 runs with ntrig = 4
[18:15:32.508] INFO: run 1 of 1
[18:15:50.809] INFO: Test took 18301ms.
[18:15:51.106] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:15:51.187] INFO: dacScan step from 140 .. 159
[18:15:51.187] INFO: dacScan split into 1 runs with ntrig = 4
[18:15:51.187] INFO: run 1 of 1
[18:16:08.108] INFO: Test took 16921ms.
[18:16:08.371] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:16:08.444] INFO: dacScan step from 160 .. 179
[18:16:08.445] INFO: dacScan split into 1 runs with ntrig = 4
[18:16:08.445] INFO: run 1 of 1
[18:16:25.302] INFO: Test took 16857ms.
[18:16:25.579] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:16:25.658] INFO: dacScan step from 180 .. 199
[18:16:25.658] INFO: dacScan split into 1 runs with ntrig = 4
[18:16:25.658] INFO: run 1 of 1
[18:16:43.223] INFO: Test took 17565ms.
[18:16:43.523] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:16:43.603] INFO: dacScan step from 200 .. 219
[18:16:43.604] INFO: dacScan split into 1 runs with ntrig = 4
[18:16:43.604] INFO: run 1 of 1
[18:17:00.383] INFO: Test took 16779ms.
[18:17:00.666] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:17:00.750] INFO: dacScan step from 220 .. 239
[18:17:00.750] INFO: dacScan split into 1 runs with ntrig = 4
[18:17:00.750] INFO: run 1 of 1
[18:17:17.468] INFO: Test took 16718ms.
[18:17:17.754] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:17:17.834] INFO: dacScan step from 240 .. 255
[18:17:17.834] INFO: dacScan split into 1 runs with ntrig = 4
[18:17:17.834] INFO: run 1 of 1
[18:17:31.842] INFO: Test took 14008ms.
[18:17:32.093] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:18:29.236] INFO: ---> TrimStepCorr2 extremal thresholds: 4.500000 .. 44.982805
[18:18:29.419] INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 4 dacrange: 4 .. 54 (20/-1) hits flags = 16 (plus default)
[18:18:29.434] INFO: dacScan step from 4 .. 23
[18:18:29.435] INFO: dacScan split into 1 runs with ntrig = 4
[18:18:29.435] INFO: run 1 of 1
[18:18:41.812] INFO: Test took 12377ms.
[18:18:41.857] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:18:41.857] INFO: dacScan step from 24 .. 43
[18:18:41.857] INFO: dacScan split into 1 runs with ntrig = 4
[18:18:41.857] INFO: run 1 of 1
[18:18:55.986] INFO: Test took 14128ms.
[18:18:56.188] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:18:56.243] INFO: dacScan step from 44 .. 54
[18:18:56.243] INFO: dacScan split into 1 runs with ntrig = 4
[18:18:56.243] INFO: run 1 of 1
[18:19:06.697] INFO: Test took 10454ms.
[18:19:06.861] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:19:32.226] INFO: ---> TrimStepCorr1a extremal thresholds: 10.373623 .. 40.324999
[18:19:32.375] INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 4 dacrange: 0 .. 50 (20/-1) hits flags = 16 (plus default)
[18:19:32.390] INFO: dacScan step from 0 .. 19
[18:19:32.390] INFO: dacScan split into 1 runs with ntrig = 4
[18:19:32.390] INFO: run 1 of 1
[18:19:44.668] INFO: Test took 12278ms.
[18:19:44.711] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:19:44.711] INFO: dacScan step from 20 .. 39
[18:19:44.711] INFO: dacScan split into 1 runs with ntrig = 4
[18:19:44.711] INFO: run 1 of 1
[18:19:57.906] INFO: Test took 13195ms.
[18:19:58.094] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:19:58.134] INFO: dacScan step from 40 .. 50
[18:19:58.134] INFO: dacScan split into 1 runs with ntrig = 4
[18:19:58.134] INFO: run 1 of 1
[18:20:08.640] INFO: Test took 10506ms.
[18:20:08.853] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:20:34.091] INFO: ---> TrimStepCorr1b extremal thresholds: 0.342881 .. 39.217318
[18:20:34.250] INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 4 dacrange: 0 .. 49 (20/-1) hits flags = 16 (plus default)
[18:20:34.265] INFO: dacScan step from 0 .. 19
[18:20:34.265] INFO: dacScan split into 1 runs with ntrig = 4
[18:20:34.265] INFO: run 1 of 1
[18:20:46.552] INFO: Test took 12287ms.
[18:20:46.614] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:20:46.614] INFO: dacScan step from 20 .. 39
[18:20:46.614] INFO: dacScan split into 1 runs with ntrig = 4
[18:20:46.614] INFO: run 1 of 1
[18:20:59.839] INFO: Test took 13225ms.
[18:20:59.972] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:21:00.008] INFO: dacScan step from 40 .. 49
[18:21:00.008] INFO: dacScan split into 1 runs with ntrig = 4
[18:21:00.008] INFO: run 1 of 1
[18:21:09.641] INFO: Test took 9632ms.
[18:21:09.797] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:21:34.694] INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[18:21:34.694] INFO: ---> dac: vcal name: TrimThrFinal ntrig: 10 dacrange: 15 .. 55 (20/5) hits flags = 16 (plus default)
[18:21:34.709] INFO: dacScan step from 15 .. 34
[18:21:34.709] INFO: dacScan split into 2 runs with ntrig = 5
[18:21:34.709] INFO: run 1 of 2
[18:21:48.529] INFO: Test took 13820ms.
[18:21:48.613] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:21:48.627] INFO: run 2 of 2
[18:22:02.625] INFO: Test took 13997ms.
[18:22:02.714] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:22:02.730] INFO: dacScan step from 35 .. 54
[18:22:02.730] INFO: dacScan split into 2 runs with ntrig = 5
[18:22:02.730] INFO: run 1 of 2
[18:22:21.574] INFO: Test took 18844ms.
[18:22:21.889] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:22:21.972] INFO: run 2 of 2
[18:22:40.509] INFO: Test took 18537ms.
[18:22:40.898] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:22:40.998] INFO: dacScan step from 55 .. 55
[18:22:40.998] INFO: dacScan split into 2 runs with ntrig = 5
[18:22:40.998] INFO: run 1 of 2
[18:22:44.781] INFO: Test took 3783ms.
[18:22:44.813] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:22:44.824] INFO: run 2 of 2
[18:22:48.519] INFO: Test took 3695ms.
[18:22:48.540] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:23:11.265] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C0.dat
[18:23:11.266] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C1.dat
[18:23:11.266] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C2.dat
[18:23:11.266] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C3.dat
[18:23:11.266] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C4.dat
[18:23:11.266] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C5.dat
[18:23:11.266] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C6.dat
[18:23:11.267] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C7.dat
[18:23:11.267] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C8.dat
[18:23:11.267] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C9.dat
[18:23:11.267] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C10.dat
[18:23:11.267] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C11.dat
[18:23:11.267] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C12.dat
[18:23:11.267] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C13.dat
[18:23:11.267] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C14.dat
[18:23:11.268] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C15.dat
[18:23:11.268] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/trimParameters35_C0.dat
[18:23:11.283] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/trimParameters35_C1.dat
[18:23:11.298] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/trimParameters35_C2.dat
[18:23:11.313] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/trimParameters35_C3.dat
[18:23:11.327] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/trimParameters35_C4.dat
[18:23:11.341] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/trimParameters35_C5.dat
[18:23:11.356] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/trimParameters35_C6.dat
[18:23:11.371] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/trimParameters35_C7.dat
[18:23:11.386] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/trimParameters35_C8.dat
[18:23:11.401] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/trimParameters35_C9.dat
[18:23:11.416] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/trimParameters35_C10.dat
[18:23:11.431] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/trimParameters35_C11.dat
[18:23:11.446] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/trimParameters35_C12.dat
[18:23:11.462] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/trimParameters35_C13.dat
[18:23:11.477] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/trimParameters35_C14.dat
[18:23:11.492] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/trimParameters35_C15.dat
[18:23:11.507] INFO: PixTestTrim::trimTest() done
[18:23:11.507] INFO: vtrim: 123 151 117 121 115 102 105 116 101 142 104 105 106 114 122 104
[18:23:11.507] INFO: vthrcomp: 106 109 91 105 88 93 89 87 105 105 80 101 97 105 97 91
[18:23:11.507] INFO: vcal mean: 35.09 35.09 35.05 35.05 35.04 35.06 35.06 35.08 35.06 35.06 35.03 35.03 35.05 35.08 35.02 35.06
[18:23:11.507] INFO: vcal RMS: 1.06 1.22 1.12 0.99 1.12 1.05 1.08 1.07 0.99 1.37 1.12 1.13 1.25 1.16 1.23 1.19
[18:23:11.507] INFO: bits mean: 8.64 8.16 10.21 9.11 9.55 10.34 9.58 9.87 9.04 9.35 9.76 9.75 9.81 9.41 10.66 10.16
[18:23:11.507] INFO: bits RMS: 2.59 2.19 2.33 2.44 2.55 2.27 2.50 2.56 2.66 2.36 2.64 2.59 2.57 2.50 2.28 2.41
[18:23:11.520] INFO: ----------------------------------------------------------------------
[18:23:11.520] INFO: PixTestTrim::trimBitTest() ntrig = 10, vtrims = 254 126 63 32
[18:23:11.520] INFO: ----------------------------------------------------------------------
[18:23:11.527] INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 10 dacrange: 0 .. 199 (20/5) hits flags = 16 (plus default)
[18:23:11.543] INFO: dacScan step from 0 .. 19
[18:23:11.543] INFO: dacScan split into 2 runs with ntrig = 5
[18:23:11.543] INFO: run 1 of 2
[18:23:25.178] INFO: Test took 13635ms.
[18:23:25.228] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:23:25.228] INFO: run 2 of 2
[18:23:38.807] INFO: Test took 13579ms.
[18:23:38.858] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:23:38.858] INFO: dacScan step from 20 .. 39
[18:23:38.858] INFO: dacScan split into 2 runs with ntrig = 5
[18:23:38.858] INFO: run 1 of 2
[18:23:52.456] INFO: Test took 13598ms.
[18:23:52.497] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:23:52.497] INFO: run 2 of 2
[18:24:06.045] INFO: Test took 13547ms.
[18:24:06.094] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:24:06.094] INFO: dacScan step from 40 .. 59
[18:24:06.094] INFO: dacScan split into 2 runs with ntrig = 5
[18:24:06.094] INFO: run 1 of 2
[18:24:19.763] INFO: Test took 13668ms.
[18:24:19.808] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:24:19.808] INFO: run 2 of 2
[18:24:33.348] INFO: Test took 13539ms.
[18:24:33.395] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:24:33.395] INFO: dacScan step from 60 .. 79
[18:24:33.395] INFO: dacScan split into 2 runs with ntrig = 5
[18:24:33.395] INFO: run 1 of 2
[18:24:46.991] INFO: Test took 13596ms.
[18:24:47.040] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:24:47.040] INFO: run 2 of 2
[18:25:00.649] INFO: Test took 13609ms.
[18:25:00.689] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:25:00.689] INFO: dacScan step from 80 .. 99
[18:25:00.690] INFO: dacScan split into 2 runs with ntrig = 5
[18:25:00.690] INFO: run 1 of 2
[18:25:14.288] INFO: Test took 13598ms.
[18:25:14.334] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:25:14.334] INFO: run 2 of 2
[18:25:27.889] INFO: Test took 13555ms.
[18:25:27.937] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:25:27.938] INFO: dacScan step from 100 .. 119
[18:25:27.938] INFO: dacScan split into 2 runs with ntrig = 5
[18:25:27.938] INFO: run 1 of 2
[18:25:42.725] INFO: Test took 14787ms.
[18:25:42.864] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:25:42.890] INFO: run 2 of 2
[18:25:57.605] INFO: Test took 14715ms.
[18:25:57.743] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:25:57.765] INFO: dacScan step from 120 .. 139
[18:25:57.765] INFO: dacScan split into 2 runs with ntrig = 5
[18:25:57.765] INFO: run 1 of 2
[18:26:16.696] INFO: Test took 18931ms.
[18:26:16.985] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:26:17.050] INFO: run 2 of 2
[18:26:36.112] INFO: Test took 19062ms.
[18:26:36.405] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:26:36.473] INFO: dacScan step from 140 .. 159
[18:26:36.473] INFO: dacScan split into 2 runs with ntrig = 5
[18:26:36.473] INFO: run 1 of 2
[18:26:55.717] INFO: Test took 19244ms.
[18:26:55.003] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:26:56.077] INFO: run 2 of 2
[18:27:15.203] INFO: Test took 19126ms.
[18:27:15.543] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:27:15.627] INFO: dacScan step from 160 .. 179
[18:27:15.627] INFO: dacScan split into 2 runs with ntrig = 5
[18:27:15.627] INFO: run 1 of 2
[18:27:34.932] INFO: Test took 19305ms.
[18:27:35.339] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:27:35.422] INFO: run 2 of 2
[18:27:54.828] INFO: Test took 19406ms.
[18:27:55.148] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:27:55.227] INFO: dacScan step from 180 .. 199
[18:27:55.227] INFO: dacScan split into 2 runs with ntrig = 5
[18:27:55.227] INFO: run 1 of 2
[18:28:15.165] INFO: Test took 19938ms.
[18:28:15.493] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:28:15.565] INFO: run 2 of 2
[18:28:35.669] INFO: Test took 20103ms.
[18:28:36.007] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:29:21.387] INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 10 dacrange: 0 .. 186 (20/5) hits flags = 16 (plus default)
[18:29:21.401] INFO: dacScan step from 0 .. 19
[18:29:21.401] INFO: dacScan split into 2 runs with ntrig = 5
[18:29:21.401] INFO: run 1 of 2
[18:29:35.073] INFO: Test took 13672ms.
[18:29:35.118] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:29:35.118] INFO: run 2 of 2
[18:29:48.758] INFO: Test took 13640ms.
[18:29:48.809] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:29:48.809] INFO: dacScan step from 20 .. 39
[18:29:48.809] INFO: dacScan split into 2 runs with ntrig = 5
[18:29:48.809] INFO: run 1 of 2
[18:30:02.315] INFO: Test took 13506ms.
[18:30:02.360] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:30:02.360] INFO: run 2 of 2
[18:30:15.974] INFO: Test took 13614ms.
[18:30:16.019] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:30:16.019] INFO: dacScan step from 40 .. 59
[18:30:16.019] INFO: dacScan split into 2 runs with ntrig = 5
[18:30:16.019] INFO: run 1 of 2
[18:30:29.586] INFO: Test took 13566ms.
[18:30:29.631] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:30:29.631] INFO: run 2 of 2
[18:30:43.239] INFO: Test took 13607ms.
[18:30:43.285] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:30:43.285] INFO: dacScan step from 60 .. 79
[18:30:43.285] INFO: dacScan split into 2 runs with ntrig = 5
[18:30:43.285] INFO: run 1 of 2
[18:30:56.835] INFO: Test took 13550ms.
[18:30:56.879] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:30:56.879] INFO: run 2 of 2
[18:31:10.541] INFO: Test took 13662ms.
[18:31:10.582] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:31:10.583] INFO: dacScan step from 80 .. 99
[18:31:10.583] INFO: dacScan split into 2 runs with ntrig = 5
[18:31:10.583] INFO: run 1 of 2
[18:31:24.296] INFO: Test took 13713ms.
[18:31:24.368] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:31:24.373] INFO: run 2 of 2
[18:31:38.118] INFO: Test took 13745ms.
[18:31:38.190] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:31:38.196] INFO: dacScan step from 100 .. 119
[18:31:38.197] INFO: dacScan split into 2 runs with ntrig = 5
[18:31:38.197] INFO: run 1 of 2
[18:31:54.302] INFO: Test took 16105ms.
[18:31:54.530] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:31:54.578] INFO: run 2 of 2
[18:32:10.716] INFO: Test took 16138ms.
[18:32:10.939] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:32:10.986] INFO: dacScan step from 120 .. 139
[18:32:10.986] INFO: dacScan split into 2 runs with ntrig = 5
[18:32:10.986] INFO: run 1 of 2
[18:32:30.953] INFO: Test took 19967ms.
[18:32:31.262] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:32:31.336] INFO: run 2 of 2
[18:32:51.204] INFO: Test took 19868ms.
[18:32:51.525] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:32:51.602] INFO: dacScan step from 140 .. 159
[18:32:51.602] INFO: dacScan split into 2 runs with ntrig = 5
[18:32:51.602] INFO: run 1 of 2
[18:33:10.890] INFO: Test took 19288ms.
[18:33:11.220] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:33:11.302] INFO: run 2 of 2
[18:33:30.527] INFO: Test took 19225ms.
[18:33:30.844] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:33:30.928] INFO: dacScan step from 160 .. 179
[18:33:30.928] INFO: dacScan split into 2 runs with ntrig = 5
[18:33:30.928] INFO: run 1 of 2
[18:33:50.038] INFO: Test took 19109ms.
[18:33:50.372] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:33:50.453] INFO: run 2 of 2
[18:34:09.742] INFO: Test took 19289ms.
[18:34:10.084] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:34:10.163] INFO: dacScan step from 180 .. 186
[18:34:10.163] INFO: dacScan split into 2 runs with ntrig = 5
[18:34:10.163] INFO: run 1 of 2
[18:34:19.252] INFO: Test took 9088ms.
[18:34:19.371] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:34:19.404] INFO: run 2 of 2
[18:34:28.585] INFO: Test took 9181ms.
[18:34:28.708] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:35:11.339] INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 10 dacrange: 0 .. 176 (20/5) hits flags = 16 (plus default)
[18:35:11.354] INFO: dacScan step from 0 .. 19
[18:35:11.355] INFO: dacScan split into 2 runs with ntrig = 5
[18:35:11.355] INFO: run 1 of 2
[18:35:24.982] INFO: Test took 13627ms.
[18:35:25.028] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:35:25.028] INFO: run 2 of 2
[18:35:38.750] INFO: Test took 13722ms.
[18:35:38.790] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:35:38.790] INFO: dacScan step from 20 .. 39
[18:35:38.790] INFO: dacScan split into 2 runs with ntrig = 5
[18:35:38.790] INFO: run 1 of 2
[18:35:52.445] INFO: Test took 13654ms.
[18:35:52.489] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:35:52.489] INFO: run 2 of 2
[18:36:06.153] INFO: Test took 13664ms.
[18:36:06.192] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:36:06.192] INFO: dacScan step from 40 .. 59
[18:36:06.192] INFO: dacScan split into 2 runs with ntrig = 5
[18:36:06.192] INFO: run 1 of 2
[18:36:19.860] INFO: Test took 13668ms.
[18:36:19.906] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:36:19.906] INFO: run 2 of 2
[18:36:33.625] INFO: Test took 13719ms.
[18:36:33.667] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:36:33.667] INFO: dacScan step from 60 .. 79
[18:36:33.667] INFO: dacScan split into 2 runs with ntrig = 5
[18:36:33.667] INFO: run 1 of 2
[18:36:47.350] INFO: Test took 13682ms.
[18:36:47.396] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:36:47.396] INFO: run 2 of 2
[18:37:00.995] INFO: Test took 13599ms.
[18:37:01.041] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:37:01.041] INFO: dacScan step from 80 .. 99
[18:37:01.041] INFO: dacScan split into 2 runs with ntrig = 5
[18:37:01.041] INFO: run 1 of 2
[18:37:14.802] INFO: Test took 13761ms.
[18:37:14.867] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:37:14.872] INFO: run 2 of 2
[18:37:28.736] INFO: Test took 13863ms.
[18:37:28.798] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:37:28.802] INFO: dacScan step from 100 .. 119
[18:37:28.802] INFO: dacScan split into 2 runs with ntrig = 5
[18:37:28.802] INFO: run 1 of 2
[18:37:44.954] INFO: Test took 16151ms.
[18:37:45.178] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:37:45.223] INFO: run 2 of 2
[18:38:01.305] INFO: Test took 16082ms.
[18:38:01.527] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:38:01.574] INFO: dacScan step from 120 .. 139
[18:38:01.574] INFO: dacScan split into 2 runs with ntrig = 5
[18:38:01.574] INFO: run 1 of 2
[18:38:21.542] INFO: Test took 19968ms.
[18:38:21.858] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:38:21.934] INFO: run 2 of 2
[18:38:41.961] INFO: Test took 20027ms.
[18:38:42.391] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:38:42.469] INFO: dacScan step from 140 .. 159
[18:38:42.470] INFO: dacScan split into 2 runs with ntrig = 5
[18:38:42.470] INFO: run 1 of 2
[18:39:01.773] INFO: Test took 19303ms.
[18:39:02.099] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:39:02.183] INFO: run 2 of 2
[18:39:21.361] INFO: Test took 19178ms.
[18:39:21.698] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:39:21.783] INFO: dacScan step from 160 .. 176
[18:39:21.783] INFO: dacScan split into 2 runs with ntrig = 5
[18:39:21.783] INFO: run 1 of 2
[18:39:38.596] INFO: Test took 16813ms.
[18:39:38.864] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:39:38.928] INFO: run 2 of 2
[18:39:55.695] INFO: Test took 16767ms.
[18:39:55.980] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:40:36.012] INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 10 dacrange: 0 .. 173 (20/5) hits flags = 16 (plus default)
[18:40:36.029] INFO: dacScan step from 0 .. 19
[18:40:36.029] INFO: dacScan split into 2 runs with ntrig = 5
[18:40:36.029] INFO: run 1 of 2
[18:40:49.750] INFO: Test took 13721ms.
[18:40:49.796] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:40:49.796] INFO: run 2 of 2
[18:41:03.474] INFO: Test took 13677ms.
[18:41:03.513] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:41:03.513] INFO: dacScan step from 20 .. 39
[18:41:03.513] INFO: dacScan split into 2 runs with ntrig = 5
[18:41:03.513] INFO: run 1 of 2
[18:41:17.273] INFO: Test took 13759ms.
[18:41:17.320] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:41:17.320] INFO: run 2 of 2
[18:41:30.986] INFO: Test took 13665ms.
[18:41:31.033] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:41:31.033] INFO: dacScan step from 40 .. 59
[18:41:31.033] INFO: dacScan split into 2 runs with ntrig = 5
[18:41:31.033] INFO: run 1 of 2
[18:41:44.691] INFO: Test took 13658ms.
[18:41:44.733] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:41:44.733] INFO: run 2 of 2
[18:41:58.337] INFO: Test took 13604ms.
[18:41:58.381] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:41:58.381] INFO: dacScan step from 60 .. 79
[18:41:58.381] INFO: dacScan split into 2 runs with ntrig = 5
[18:41:58.381] INFO: run 1 of 2
[18:42:11.940] INFO: Test took 13559ms.
[18:42:11.983] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:42:11.983] INFO: run 2 of 2
[18:42:25.611] INFO: Test took 13627ms.
[18:42:25.656] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:42:25.656] INFO: dacScan step from 80 .. 99
[18:42:25.656] INFO: dacScan split into 2 runs with ntrig = 5
[18:42:25.656] INFO: run 1 of 2
[18:42:39.490] INFO: Test took 13834ms.
[18:42:39.561] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:42:39.570] INFO: run 2 of 2
[18:42:53.340] INFO: Test took 13770ms.
[18:42:53.413] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:42:53.418] INFO: dacScan step from 100 .. 119
[18:42:53.418] INFO: dacScan split into 2 runs with ntrig = 5
[18:42:53.418] INFO: run 1 of 2
[18:43:09.514] INFO: Test took 16095ms.
[18:43:09.729] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:43:09.776] INFO: run 2 of 2
[18:43:25.895] INFO: Test took 16119ms.
[18:43:26.109] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:43:26.154] INFO: dacScan step from 120 .. 139
[18:43:26.154] INFO: dacScan split into 2 runs with ntrig = 5
[18:43:26.154] INFO: run 1 of 2
[18:43:46.032] INFO: Test took 19878ms.
[18:43:46.351] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:43:46.429] INFO: run 2 of 2
[18:44:06.350] INFO: Test took 19921ms.
[18:44:06.691] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:44:06.774] INFO: dacScan step from 140 .. 159
[18:44:06.774] INFO: dacScan split into 2 runs with ntrig = 5
[18:44:06.774] INFO: run 1 of 2
[18:44:25.991] INFO: Test took 19216ms.
[18:44:26.328] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:44:26.416] INFO: run 2 of 2
[18:44:45.608] INFO: Test took 19191ms.
[18:44:45.949] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:44:46.023] INFO: dacScan step from 160 .. 173
[18:44:46.023] INFO: dacScan split into 2 runs with ntrig = 5
[18:44:46.023] INFO: run 1 of 2
[18:45:00.339] INFO: Test took 14315ms.
[18:45:00.567] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:45:00.631] INFO: run 2 of 2
[18:45:14.999] INFO: Test took 14368ms.
[18:45:15.238] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:45:55.114] INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 10 dacrange: 0 .. 173 (20/5) hits flags = 16 (plus default)
[18:45:55.128] INFO: dacScan step from 0 .. 19
[18:45:55.128] INFO: dacScan split into 2 runs with ntrig = 5
[18:45:55.128] INFO: run 1 of 2
[18:46:08.816] INFO: Test took 13688ms.
[18:46:08.858] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:46:08.858] INFO: run 2 of 2
[18:46:22.545] INFO: Test took 13686ms.
[18:46:22.594] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:46:22.594] INFO: dacScan step from 20 .. 39
[18:46:22.594] INFO: dacScan split into 2 runs with ntrig = 5
[18:46:22.594] INFO: run 1 of 2
[18:46:36.340] INFO: Test took 13746ms.
[18:46:36.382] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:46:36.382] INFO: run 2 of 2
[18:46:50.007] INFO: Test took 13625ms.
[18:46:50.053] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:46:50.053] INFO: dacScan step from 40 .. 59
[18:46:50.053] INFO: dacScan split into 2 runs with ntrig = 5
[18:46:50.053] INFO: run 1 of 2
[18:47:03.654] INFO: Test took 13601ms.
[18:47:03.691] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:47:03.691] INFO: run 2 of 2
[18:47:17.264] INFO: Test took 13572ms.
[18:47:17.308] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:47:17.308] INFO: dacScan step from 60 .. 79
[18:47:17.308] INFO: dacScan split into 2 runs with ntrig = 5
[18:47:17.308] INFO: run 1 of 2
[18:47:30.853] INFO: Test took 13545ms.
[18:47:30.895] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:47:30.895] INFO: run 2 of 2
[18:47:44.435] INFO: Test took 13540ms.
[18:47:44.479] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:47:44.479] INFO: dacScan step from 80 .. 99
[18:47:44.479] INFO: dacScan split into 2 runs with ntrig = 5
[18:47:44.479] INFO: run 1 of 2
[18:47:58.295] INFO: Test took 13816ms.
[18:47:58.367] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:47:58.372] INFO: run 2 of 2
[18:48:12.218] INFO: Test took 13846ms.
[18:48:12.295] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:48:12.300] INFO: dacScan step from 100 .. 119
[18:48:12.300] INFO: dacScan split into 2 runs with ntrig = 5
[18:48:12.300] INFO: run 1 of 2
[18:48:28.480] INFO: Test took 16180ms.
[18:48:28.688] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:48:28.731] INFO: run 2 of 2
[18:48:44.907] INFO: Test took 16176ms.
[18:48:45.141] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:48:45.190] INFO: dacScan step from 120 .. 139
[18:48:45.190] INFO: dacScan split into 2 runs with ntrig = 5
[18:48:45.190] INFO: run 1 of 2
[18:49:05.163] INFO: Test took 19973ms.
[18:49:05.490] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:49:05.562] INFO: run 2 of 2
[18:49:25.498] INFO: Test took 19936ms.
[18:49:25.834] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:49:25.915] INFO: dacScan step from 140 .. 159
[18:49:25.915] INFO: dacScan split into 2 runs with ntrig = 5
[18:49:25.915] INFO: run 1 of 2
[18:49:45.242] INFO: Test took 19327ms.
[18:49:45.569] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:49:45.658] INFO: run 2 of 2
[18:50:04.821] INFO: Test took 19163ms.
[18:50:05.141] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:50:05.216] INFO: dacScan step from 160 .. 173
[18:50:05.216] INFO: dacScan split into 2 runs with ntrig = 5
[18:50:05.216] INFO: run 1 of 2
[18:50:19.442] INFO: Test took 14226ms.
[18:50:19.675] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:50:19.738] INFO: run 2 of 2
[18:50:34.030] INFO: Test took 14292ms.
[18:50:34.259] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:51:13.533] INFO: PixTestTrim::trimBitTest() done
[18:51:13.534] INFO: PixTestTrim::doTest() done, duration: 3089 seconds
[18:51:14.527] INFO: ######################################################################
[18:51:14.527] INFO: PixTestPhOptimization::doTest() Ntrig = 10
[18:51:14.527] INFO: ######################################################################
[18:51:18.800] INFO: Test took 4272ms.
[18:51:18.836] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:51:23.312] INFO: Test took 4274ms.
[18:51:23.460] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:51:27.699] INFO: Test took 4220ms.
[18:51:27.845] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:51:27.857] INFO: The DUT currently contains the following objects:
[18:51:27.857] INFO: 2 TBM Cores tbm08c (2 ON)
[18:51:27.857] INFO: TBM Core alpha (0): 7 registers set
[18:51:27.857] INFO: TBM Core beta (1): 7 registers set
[18:51:27.857] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[18:51:27.857] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:27.857] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:27.857] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:27.857] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:27.857] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:27.857] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:27.857] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:27.857] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:27.857] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:27.857] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:27.857] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:27.857] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:27.857] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:27.857] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:27.857] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:27.857] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:28.957] INFO: Test took 1100ms.
[18:51:28.959] INFO: The DUT currently contains the following objects:
[18:51:28.960] INFO: 2 TBM Cores tbm08c (2 ON)
[18:51:28.960] INFO: TBM Core alpha (0): 7 registers set
[18:51:28.960] INFO: TBM Core beta (1): 7 registers set
[18:51:28.960] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[18:51:28.960] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:28.960] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:28.960] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:28.960] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:28.960] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:28.960] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:28.960] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:28.960] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:28.960] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:28.960] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:28.960] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:28.960] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:28.960] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:28.960] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:28.960] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:28.960] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:30.059] INFO: Test took 1099ms.
[18:51:30.061] INFO: The DUT currently contains the following objects:
[18:51:30.061] INFO: 2 TBM Cores tbm08c (2 ON)
[18:51:30.061] INFO: TBM Core alpha (0): 7 registers set
[18:51:30.061] INFO: TBM Core beta (1): 7 registers set
[18:51:30.061] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[18:51:30.061] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:30.061] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:30.061] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:30.061] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:30.061] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:30.061] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:30.061] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:30.061] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:30.061] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:30.061] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:30.061] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:30.061] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:30.061] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:30.061] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:30.061] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:30.061] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:31.158] INFO: Test took 1097ms.
[18:51:31.159] INFO: The DUT currently contains the following objects:
[18:51:31.159] INFO: 2 TBM Cores tbm08c (2 ON)
[18:51:31.159] INFO: TBM Core alpha (0): 7 registers set
[18:51:31.159] INFO: TBM Core beta (1): 7 registers set
[18:51:31.159] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[18:51:31.159] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:31.159] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:31.159] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:31.159] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:31.159] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:31.160] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:31.160] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:31.160] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:31.160] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:31.160] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:31.160] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:31.160] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:31.160] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:31.160] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:31.160] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:31.160] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:32.256] INFO: Test took 1096ms.
[18:51:32.258] INFO: The DUT currently contains the following objects:
[18:51:32.258] INFO: 2 TBM Cores tbm08c (2 ON)
[18:51:32.258] INFO: TBM Core alpha (0): 7 registers set
[18:51:32.258] INFO: TBM Core beta (1): 7 registers set
[18:51:32.258] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[18:51:32.258] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:32.258] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:32.258] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:32.258] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:32.258] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:32.258] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:32.258] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:32.258] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:32.258] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:32.258] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:32.258] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:32.258] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:32.258] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:32.258] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:32.258] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:32.258] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:33.355] INFO: Test took 1097ms.
[18:51:33.357] INFO: The DUT currently contains the following objects:
[18:51:33.357] INFO: 2 TBM Cores tbm08c (2 ON)
[18:51:33.357] INFO: TBM Core alpha (0): 7 registers set
[18:51:33.357] INFO: TBM Core beta (1): 7 registers set
[18:51:33.358] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[18:51:33.358] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:33.358] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:33.358] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:33.358] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:33.358] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:33.358] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:33.358] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:33.358] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:33.358] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:33.358] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:33.358] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:33.358] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:33.358] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:33.358] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:33.358] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:33.358] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:34.456] INFO: Test took 1098ms.
[18:51:34.457] INFO: The DUT currently contains the following objects:
[18:51:34.457] INFO: 2 TBM Cores tbm08c (2 ON)
[18:51:34.457] INFO: TBM Core alpha (0): 7 registers set
[18:51:34.457] INFO: TBM Core beta (1): 7 registers set
[18:51:34.457] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[18:51:34.457] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:34.457] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:34.457] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:34.457] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:34.457] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:34.457] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:34.457] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:34.457] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:34.457] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:34.457] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:34.457] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:34.457] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:34.457] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:34.457] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:34.457] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:34.457] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:35.556] INFO: Test took 1099ms.
[18:51:35.558] INFO: The DUT currently contains the following objects:
[18:51:35.558] INFO: 2 TBM Cores tbm08c (2 ON)
[18:51:35.558] INFO: TBM Core alpha (0): 7 registers set
[18:51:35.559] INFO: TBM Core beta (1): 7 registers set
[18:51:35.559] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[18:51:35.559] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:35.559] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:35.559] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:35.559] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:35.559] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:35.559] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:35.559] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:35.559] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:35.559] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:35.559] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:35.559] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:35.559] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:35.559] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:35.559] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:35.559] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:35.559] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:36.654] INFO: Test took 1095ms.
[18:51:36.656] INFO: The DUT currently contains the following objects:
[18:51:36.656] INFO: 2 TBM Cores tbm08c (2 ON)
[18:51:36.656] INFO: TBM Core alpha (0): 7 registers set
[18:51:36.656] INFO: TBM Core beta (1): 7 registers set
[18:51:36.656] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[18:51:36.656] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:36.656] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:36.656] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:36.656] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:36.656] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:36.656] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:36.656] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:36.656] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:36.656] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:36.656] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:36.656] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:36.656] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:36.656] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:36.656] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:36.656] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:36.656] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:37.756] INFO: Test took 1100ms.
[18:51:37.758] INFO: The DUT currently contains the following objects:
[18:51:37.758] INFO: 2 TBM Cores tbm08c (2 ON)
[18:51:37.758] INFO: TBM Core alpha (0): 7 registers set
[18:51:37.758] INFO: TBM Core beta (1): 7 registers set
[18:51:37.758] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[18:51:37.758] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:37.758] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:37.758] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:37.758] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:37.758] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:37.758] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:37.758] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:37.758] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:37.758] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:37.758] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:37.758] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:37.758] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:37.758] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:37.758] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:37.758] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:37.758] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:38.855] INFO: Test took 1097ms.
[18:51:38.857] INFO: The DUT currently contains the following objects:
[18:51:38.857] INFO: 2 TBM Cores tbm08c (2 ON)
[18:51:38.857] INFO: TBM Core alpha (0): 7 registers set
[18:51:38.857] INFO: TBM Core beta (1): 7 registers set
[18:51:38.858] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[18:51:38.858] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:38.858] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:38.858] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:38.858] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:38.858] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:38.858] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:38.858] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:38.858] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:38.858] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:38.858] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:38.858] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:38.858] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:38.858] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:38.858] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:38.858] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:38.858] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:39.958] INFO: Test took 1100ms.
[18:51:39.960] INFO: The DUT currently contains the following objects:
[18:51:39.960] INFO: 2 TBM Cores tbm08c (2 ON)
[18:51:39.960] INFO: TBM Core alpha (0): 7 registers set
[18:51:39.961] INFO: TBM Core beta (1): 7 registers set
[18:51:39.961] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[18:51:39.961] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:39.961] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:39.961] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:39.961] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:39.961] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:39.961] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:39.961] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:39.961] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:39.961] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:39.961] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:39.961] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:39.961] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:39.961] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:39.961] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:39.961] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:39.961] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:41.057] INFO: Test took 1096ms.
[18:51:41.059] INFO: The DUT currently contains the following objects:
[18:51:41.059] INFO: 2 TBM Cores tbm08c (2 ON)
[18:51:41.059] INFO: TBM Core alpha (0): 7 registers set
[18:51:41.059] INFO: TBM Core beta (1): 7 registers set
[18:51:41.059] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[18:51:41.059] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:41.059] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:41.059] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:41.059] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:41.059] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:41.059] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:41.059] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:41.059] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:41.059] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:41.059] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:41.059] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:41.059] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:41.059] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:41.059] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:41.059] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:41.060] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:42.161] INFO: Test took 1101ms.
[18:51:42.162] INFO: The DUT currently contains the following objects:
[18:51:42.163] INFO: 2 TBM Cores tbm08c (2 ON)
[18:51:42.163] INFO: TBM Core alpha (0): 7 registers set
[18:51:42.163] INFO: TBM Core beta (1): 7 registers set
[18:51:42.163] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[18:51:42.163] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:42.163] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:42.163] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:42.163] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:42.163] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:42.163] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:42.163] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:42.163] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:42.163] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:42.163] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:42.163] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:42.163] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:42.163] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:42.163] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:42.163] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:42.163] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:43.263] INFO: Test took 1100ms.
[18:51:43.265] INFO: The DUT currently contains the following objects:
[18:51:43.266] INFO: 2 TBM Cores tbm08c (2 ON)
[18:51:43.266] INFO: TBM Core alpha (0): 7 registers set
[18:51:43.266] INFO: TBM Core beta (1): 7 registers set
[18:51:43.266] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[18:51:43.266] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:43.266] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:43.266] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:43.266] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:43.266] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:43.266] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:43.266] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:43.266] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:43.266] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:43.266] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:43.266] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:43.266] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:43.266] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:43.266] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:43.266] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:43.266] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:44.365] INFO: Test took 1099ms.
[18:51:44.367] INFO: The DUT currently contains the following objects:
[18:51:44.367] INFO: 2 TBM Cores tbm08c (2 ON)
[18:51:44.367] INFO: TBM Core alpha (0): 7 registers set
[18:51:44.368] INFO: TBM Core beta (1): 7 registers set
[18:51:44.368] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[18:51:44.368] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:44.368] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:44.368] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:44.368] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:44.368] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:44.368] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:44.368] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:44.368] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:44.368] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:44.368] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:44.368] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:44.368] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:44.368] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:44.368] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:44.368] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:44.368] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:51:45.463] INFO: Test took 1095ms.
[18:51:45.469] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:54:58.579] INFO: Test took 193110ms.
[18:55:02.070] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:58:15.366] INFO: Test took 193296ms.
[18:58:18.766] INFO: safety margin for low PH: adding 0, margin is now 20
[18:58:18.777] INFO: safety margin for low PH: adding 0, margin is now 20
[18:58:18.789] INFO: safety margin for low PH: adding 0, margin is now 20
[18:58:18.800] INFO: safety margin for low PH: adding 0, margin is now 20
[18:58:18.812] INFO: safety margin for low PH: adding 0, margin is now 20
[18:58:18.823] INFO: safety margin for low PH: adding 0, margin is now 20
[18:58:18.833] INFO: safety margin for low PH: adding 0, margin is now 20
[18:58:18.844] INFO: safety margin for low PH: adding 0, margin is now 20
[18:58:18.856] INFO: safety margin for low PH: adding 0, margin is now 20
[18:58:18.866] INFO: safety margin for low PH: adding 0, margin is now 20
[18:58:18.877] INFO: safety margin for low PH: adding 0, margin is now 20
[18:58:18.889] INFO: safety margin for low PH: adding 0, margin is now 20
[18:58:18.899] INFO: safety margin for low PH: adding 0, margin is now 20
[18:58:18.910] INFO: safety margin for low PH: adding 0, margin is now 20
[18:58:18.921] INFO: safety margin for low PH: adding 0, margin is now 20
[18:58:18.933] INFO: safety margin for low PH: adding 0, margin is now 20
[18:58:18.002] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C0.dat
[18:58:18.002] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C1.dat
[18:58:18.002] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C2.dat
[18:58:18.003] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C3.dat
[18:58:18.003] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C4.dat
[18:58:19.003] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C5.dat
[18:58:19.004] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C6.dat
[18:58:19.004] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C7.dat
[18:58:19.004] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C8.dat
[18:58:19.005] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C9.dat
[18:58:19.005] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C10.dat
[18:58:19.005] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C11.dat
[18:58:19.006] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C12.dat
[18:58:19.006] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C13.dat
[18:58:19.006] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C14.dat
[18:58:19.007] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C15.dat
[18:58:23.211] INFO: Test took 4199ms.
[18:58:27.799] INFO: Test took 4211ms.
[18:58:32.494] INFO: Test took 4283ms.
[18:58:32.867] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:58:33.776] INFO: Test took 909ms.
[18:58:33.781] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:58:34.876] INFO: Test took 1096ms.
[18:58:34.882] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:58:35.982] INFO: Test took 1100ms.
[18:58:35.988] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:58:37.086] INFO: Test took 1098ms.
[18:58:37.092] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:58:38.191] INFO: Test took 1099ms.
[18:58:38.195] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:58:39.290] INFO: Test took 1095ms.
[18:58:39.295] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:58:40.392] INFO: Test took 1098ms.
[18:58:40.398] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:58:41.496] INFO: Test took 1098ms.
[18:58:41.503] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:58:42.599] INFO: Test took 1096ms.
[18:58:42.604] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:58:43.699] INFO: Test took 1096ms.
[18:58:43.703] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:58:44.803] INFO: Test took 1100ms.
[18:58:44.809] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:58:45.907] INFO: Test took 1099ms.
[18:58:45.914] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:58:47.012] INFO: Test took 1098ms.
[18:58:47.019] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:58:48.115] INFO: Test took 1096ms.
[18:58:48.119] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:58:49.215] INFO: Test took 1096ms.
[18:58:49.222] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:58:50.321] INFO: Test took 1099ms.
[18:58:50.328] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:58:51.426] INFO: Test took 1098ms.
[18:58:51.431] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:58:52.527] INFO: Test took 1096ms.
[18:58:52.531] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:58:53.628] INFO: Test took 1097ms.
[18:58:53.633] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:58:54.730] INFO: Test took 1097ms.
[18:58:54.736] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:58:55.834] INFO: Test took 1098ms.
[18:58:55.841] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:58:56.937] INFO: Test took 1096ms.
[18:58:56.942] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:58:58.038] INFO: Test took 1097ms.
[18:58:58.044] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:58:59.143] INFO: Test took 1100ms.
[18:58:59.148] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:59:00.245] INFO: Test took 1097ms.
[18:59:00.252] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:59:01.346] INFO: Test took 1095ms.
[18:59:01.350] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:59:02.448] INFO: Test took 1098ms.
[18:59:02.453] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:59:03.551] INFO: Test took 1099ms.
[18:59:03.557] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:59:04.655] INFO: Test took 1098ms.
[18:59:04.662] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:59:05.759] INFO: Test took 1098ms.
[18:59:05.764] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:59:06.861] INFO: Test took 1097ms.
[18:59:06.866] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:59:07.963] INFO: Test took 1097ms.
[18:59:08.567] INFO: PixTestPhOptimization::doTest() done, duration: 474 seconds
[18:59:08.567] INFO: PH scale (per ROC): 70 76 78 87 85 83 66 81 74 70 78 68 77 75 80 81
[18:59:08.567] INFO: PH offset (per ROC): 167 154 157 149 166 156 161 142 162 174 167 164 153 167 160 158
[18:59:08.796] INFO: ######################################################################
[18:59:08.796] INFO: PixTestGainPedestal::fullTest() ntrig = 10
[18:59:08.796] INFO: ######################################################################
[18:59:08.814] INFO: scanning low vcal = 10
[18:59:12.580] INFO: Test took 3766ms.
[18:59:12.588] INFO: scanning low vcal = 20
[18:59:16.323] INFO: Test took 3735ms.
[18:59:16.334] INFO: scanning low vcal = 30
[18:59:20.126] INFO: Test took 3792ms.
[18:59:20.145] INFO: scanning low vcal = 40
[18:59:24.360] INFO: Test took 4215ms.
[18:59:24.507] INFO: scanning low vcal = 50
[18:59:28.802] INFO: Test took 4295ms.
[18:59:28.950] INFO: scanning low vcal = 60
[18:59:33.243] INFO: Test took 4293ms.
[18:59:33.395] INFO: scanning low vcal = 70
[18:59:37.662] INFO: Test took 4267ms.
[18:59:37.809] INFO: scanning low vcal = 80
[18:59:42.104] INFO: Test took 4295ms.
[18:59:42.256] INFO: scanning low vcal = 90
[18:59:46.515] INFO: Test took 4259ms.
[18:59:46.664] INFO: scanning low vcal = 100
[18:59:51.015] INFO: Test took 4351ms.
[18:59:51.167] INFO: scanning low vcal = 110
[18:59:55.473] INFO: Test took 4306ms.
[18:59:55.623] INFO: scanning low vcal = 120
[18:59:59.964] INFO: Test took 4341ms.
[19:00:00.106] INFO: scanning low vcal = 130
[19:00:04.564] INFO: Test took 4458ms.
[19:00:04.715] INFO: scanning low vcal = 140
[19:00:09.086] INFO: Test took 4371ms.
[19:00:09.242] INFO: scanning low vcal = 150
[19:00:13.578] INFO: Test took 4336ms.
[19:00:13.728] INFO: scanning low vcal = 160
[19:00:18.082] INFO: Test took 4354ms.
[19:00:18.235] INFO: scanning low vcal = 170
[19:00:22.526] INFO: Test took 4291ms.
[19:00:22.673] INFO: scanning low vcal = 180
[19:00:27.013] INFO: Test took 4340ms.
[19:00:27.156] INFO: scanning low vcal = 190
[19:00:31.484] INFO: Test took 4328ms.
[19:00:31.620] INFO: scanning low vcal = 200
[19:00:35.908] INFO: Test took 4288ms.
[19:00:36.049] INFO: scanning low vcal = 210
[19:00:40.372] INFO: Test took 4323ms.
[19:00:40.512] INFO: scanning low vcal = 220
[19:00:44.826] INFO: Test took 4314ms.
[19:00:44.970] INFO: scanning low vcal = 230
[19:00:49.216] INFO: Test took 4246ms.
[19:00:49.363] INFO: scanning low vcal = 240
[19:00:53.716] INFO: Test took 4353ms.
[19:00:53.860] INFO: scanning low vcal = 250
[19:00:58.178] INFO: Test took 4318ms.
[19:00:58.326] INFO: scanning high vcal = 30 (= 210 in low range)
[19:01:02.661] INFO: Test took 4334ms.
[19:01:02.854] INFO: scanning high vcal = 50 (= 350 in low range)
[19:01:07.249] INFO: Test took 4395ms.
[19:01:07.407] INFO: scanning high vcal = 70 (= 490 in low range)
[19:01:11.758] INFO: Test took 4351ms.
[19:01:11.945] INFO: scanning high vcal = 90 (= 630 in low range)
[19:01:16.337] INFO: Test took 4392ms.
[19:01:16.480] INFO: scanning high vcal = 200 (= 1400 in low range)
[19:01:20.746] INFO: Test took 4266ms.
[19:01:21.883] INFO: PixTestGainPedestal::measure() done
[19:02:18.768] INFO: PixTestGainPedestal::fit() done
[19:02:18.768] INFO: non-linearity mean: 0.953 0.960 0.961 0.957 0.959 0.951 0.954 0.951 0.955 0.957 0.955 0.955 0.960 0.955 0.956 0.957
[19:02:18.768] INFO: non-linearity RMS: 0.005 0.006 0.005 0.005 0.006 0.007 0.006 0.006 0.006 0.007 0.007 0.006 0.004 0.006 0.005 0.005
[19:02:18.768] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/phCalibrationFitErr35_C0.dat
[19:02:18.795] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/phCalibrationFitErr35_C1.dat
[19:02:18.818] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/phCalibrationFitErr35_C2.dat
[19:02:18.841] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/phCalibrationFitErr35_C3.dat
[19:02:18.864] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/phCalibrationFitErr35_C4.dat
[19:02:18.888] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/phCalibrationFitErr35_C5.dat
[19:02:18.912] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/phCalibrationFitErr35_C6.dat
[19:02:18.935] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/phCalibrationFitErr35_C7.dat
[19:02:18.959] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/phCalibrationFitErr35_C8.dat
[19:02:18.983] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/phCalibrationFitErr35_C9.dat
[19:02:19.008] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/phCalibrationFitErr35_C10.dat
[19:02:19.032] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/phCalibrationFitErr35_C11.dat
[19:02:19.058] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/phCalibrationFitErr35_C12.dat
[19:02:19.085] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/phCalibrationFitErr35_C13.dat
[19:02:19.111] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/phCalibrationFitErr35_C14.dat
[19:02:19.137] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/phCalibrationFitErr35_C15.dat
[19:02:19.163] INFO: PixTestGainPedestal::doTest() done, duration: 190 seconds
[19:02:19.171] INFO: readReadbackCal: /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C0.dat .. /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C15.dat
[19:02:19.173] INFO: PixTestReadback::doTest() start.
[19:02:19.174] INFO: PixTestReadback::RES sent once
[19:02:35.800] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C0.dat
[19:02:35.801] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C1.dat
[19:02:35.801] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C2.dat
[19:02:35.801] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C3.dat
[19:02:35.801] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C4.dat
[19:02:35.801] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C5.dat
[19:02:35.801] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C6.dat
[19:02:35.802] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C7.dat
[19:02:35.802] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C8.dat
[19:02:35.802] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C9.dat
[19:02:35.802] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C10.dat
[19:02:35.802] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C11.dat
[19:02:35.802] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C12.dat
[19:02:35.802] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C13.dat
[19:02:35.802] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C14.dat
[19:02:35.802] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C15.dat
[19:02:35.851] INFO: PixTestPattern:: pg_setup set to default.
[19:02:35.851] INFO: PixTestReadback::RES sent once
[19:02:52.376] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C0.dat
[19:02:52.377] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C1.dat
[19:02:52.377] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C2.dat
[19:02:52.377] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C3.dat
[19:02:52.377] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C4.dat
[19:02:52.377] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C5.dat
[19:02:52.377] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C6.dat
[19:02:52.378] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C7.dat
[19:02:52.378] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C8.dat
[19:02:52.378] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C9.dat
[19:02:52.378] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C10.dat
[19:02:52.378] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C11.dat
[19:02:52.378] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C12.dat
[19:02:52.379] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C13.dat
[19:02:52.379] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C14.dat
[19:02:52.379] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C15.dat
[19:02:52.432] INFO: PixTestPattern:: pg_setup set to default.
[19:02:52.433] INFO: PixTestReadback::RES sent once
[19:03:05.225] INFO: PixTestPattern:: pg_setup set to default.
[19:03:05.225] INFO: Vbg will be calibrated using Vd calibration
[19:03:05.225] INFO: /*/*/*/*::: ROC 0: uncalibrated Vbg = 153.6calibrated Vbg = 1.24836 :::*/*/*/*/
[19:03:05.225] INFO: /*/*/*/*::: ROC 1: uncalibrated Vbg = 153calibrated Vbg = 1.24788 :::*/*/*/*/
[19:03:05.225] INFO: /*/*/*/*::: ROC 2: uncalibrated Vbg = 147.9calibrated Vbg = 1.25718 :::*/*/*/*/
[19:03:05.225] INFO: /*/*/*/*::: ROC 3: uncalibrated Vbg = 155.2calibrated Vbg = 1.25238 :::*/*/*/*/
[19:03:05.225] INFO: /*/*/*/*::: ROC 4: uncalibrated Vbg = 149.8calibrated Vbg = 1.2681 :::*/*/*/*/
[19:03:05.225] INFO: /*/*/*/*::: ROC 5: uncalibrated Vbg = 156.2calibrated Vbg = 1.26035 :::*/*/*/*/
[19:03:05.225] INFO: /*/*/*/*::: ROC 6: uncalibrated Vbg = 157.2calibrated Vbg = 1.26268 :::*/*/*/*/
[19:03:05.225] INFO: /*/*/*/*::: ROC 7: uncalibrated Vbg = 151calibrated Vbg = 1.27061 :::*/*/*/*/
[19:03:05.225] INFO: /*/*/*/*::: ROC 8: uncalibrated Vbg = 152.8calibrated Vbg = 1.2697 :::*/*/*/*/
[19:03:05.225] INFO: /*/*/*/*::: ROC 9: uncalibrated Vbg = 155.2calibrated Vbg = 1.26869 :::*/*/*/*/
[19:03:05.225] INFO: /*/*/*/*::: ROC 10: uncalibrated Vbg = 154calibrated Vbg = 1.26759 :::*/*/*/*/
[19:03:05.225] INFO: /*/*/*/*::: ROC 11: uncalibrated Vbg = 162.3calibrated Vbg = 1.26166 :::*/*/*/*/
[19:03:05.225] INFO: /*/*/*/*::: ROC 12: uncalibrated Vbg = 155.2calibrated Vbg = 1.2524 :::*/*/*/*/
[19:03:05.225] INFO: /*/*/*/*::: ROC 13: uncalibrated Vbg = 161.9calibrated Vbg = 1.2388 :::*/*/*/*/
[19:03:05.225] INFO: /*/*/*/*::: ROC 14: uncalibrated Vbg = 155calibrated Vbg = 1.24463 :::*/*/*/*/
[19:03:05.225] INFO: /*/*/*/*::: ROC 15: uncalibrated Vbg = 157.4calibrated Vbg = 1.24552 :::*/*/*/*/
[19:03:05.229] INFO: PixTestReadback::RES sent once
[19:07:00.893] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C0.dat
[19:07:00.893] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C1.dat
[19:07:00.893] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C2.dat
[19:07:00.893] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C3.dat
[19:07:00.893] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C4.dat
[19:07:00.894] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C5.dat
[19:07:00.894] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C6.dat
[19:07:00.894] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C7.dat
[19:07:00.894] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C8.dat
[19:07:00.894] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C9.dat
[19:07:00.894] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C10.dat
[19:07:00.894] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C11.dat
[19:07:00.894] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C12.dat
[19:07:00.894] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C13.dat
[19:07:00.894] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C14.dat
[19:07:00.894] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4560_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C15.dat
[19:07:00.948] INFO: PixTestPattern:: pg_setup set to default.
[19:07:00.951] INFO: PixTestReadback::doTest() done
[19:07:00.970] INFO: enter test to run
[19:07:00.970] INFO: test: q no parameter change
[19:07:01.161] QUIET: Connection to board 173 closed.
[19:07:01.164] INFO: pXar: this is the end, my friend