[17:13:57.442] INFO: *** Welcome to pxar ***
[17:13:57.442] INFO: *** Today: 2015/08/04
[17:13:57.443] INFO: readRocDacs: /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters_C0.dat .. /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters_C15.dat
[17:13:57.444] INFO: readTbmDacs: /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/tbmParameters_C0a.dat .. /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/tbmParameters_C0b.dat
[17:13:57.444] INFO: readMaskFile: /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/defaultMaskFile.dat
[17:13:57.444] INFO: readTrimFile: /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/trimParameters_C0.dat .. /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/trimParameters_C15.dat
[17:13:57.545] INFO: clk: 4
[17:13:57.545] INFO: ctr: 4
[17:13:57.545] INFO: sda: 19
[17:13:57.545] INFO: tin: 9
[17:13:57.545] INFO: level: 15
[17:13:57.545] INFO: triggerdelay: 0
[17:13:57.545] QUIET: Instanciating API for pxar prod-01+36~geb5ac3f
[17:13:57.545] INFO: Log level: INFO
[17:13:57.558] INFO: Found DTB DTB_WZ4WY6
[17:13:57.570] QUIET: Connection to board DTB_WZ4WY6 opened.
[17:13:57.573] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 175
HW version: DTB1.2
FW version: 4.0
SW version: 4.0
USB id: DTB_WZ4WY6
MAC address: 40D8551180AF
Hostname: pixelDTB175
Comment:
------------------------------------------------------
[17:13:57.576] INFO: RPC call hashes of host and DTB match: 447413373
[17:13:59.315] INFO: DUT info:
[17:13:59.315] INFO: The DUT currently contains the following objects:
[17:13:59.315] INFO: 2 TBM Cores tbm08c (2 ON)
[17:13:59.315] INFO: TBM Core alpha (0): 7 registers set
[17:13:59.315] INFO: TBM Core beta (1): 7 registers set
[17:13:59.315] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[17:13:59.315] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[17:13:59.315] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[17:13:59.315] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[17:13:59.315] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[17:13:59.315] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[17:13:59.315] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[17:13:59.315] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[17:13:59.315] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[17:13:59.315] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[17:13:59.315] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[17:13:59.315] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[17:13:59.315] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[17:13:59.316] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[17:13:59.316] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[17:13:59.316] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[17:13:59.316] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[17:13:59.717] INFO: enter 'restricted' command line mode
[17:13:59.717] INFO: enter test to run
[17:13:59.717] INFO: test: pretest no parameter change
[17:13:59.717] INFO: running: pretest
[17:13:59.722] INFO: ######################################################################
[17:13:59.722] INFO: PixTestPretest::doTest()
[17:13:59.722] INFO: ######################################################################
[17:13:59.724] INFO: ----------------------------------------------------------------------
[17:13:59.724] INFO: PixTestPretest::programROC()
[17:13:59.724] INFO: ----------------------------------------------------------------------
[17:14:17.747] INFO: PixTestPretest::programROC() done: ROCs are all programmable
[17:14:17.747] INFO: IA differences per ROC: 17.7 18.5 19.3 18.5 20.1 17.7 20.9 19.3 19.3 21.7 18.5 20.1 16.9 19.3 18.5 18.5
[17:14:17.838] INFO: ----------------------------------------------------------------------
[17:14:17.838] INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[17:14:17.838] INFO: ----------------------------------------------------------------------
[17:14:37.519] INFO: PixTestPretest::setVana() done, Module Ia 385.9 mA = 24.1188 mA/ROC
[17:14:37.523] INFO: ----------------------------------------------------------------------
[17:14:37.523] INFO: PixTestPretest::findWorkingPixel()
[17:14:37.523] INFO: ----------------------------------------------------------------------
[17:14:45.005] INFO: Test took 7471ms.
[17:14:45.329] INFO: Found working pixel in all ROCs: col/row = 12/22
[17:14:45.388] INFO: ----------------------------------------------------------------------
[17:14:45.388] INFO: PixTestPretest::setVthrCompCalDel()
[17:14:45.388] INFO: ----------------------------------------------------------------------
[17:14:52.858] INFO: Test took 7462ms.
[17:14:53.247] INFO: PixTestPretest::setVthrCompCalDel() done
[17:14:53.247] INFO: CalDel: 108 145 124 125 141 136 126 106 124 137 133 130 123 112 130 133
[17:14:53.247] INFO: VthrComp: 51 51 54 51 51 51 51 51 51 51 51 51 54 51 51 51
[17:14:53.253] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters_C0.dat
[17:14:53.253] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters_C1.dat
[17:14:53.253] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters_C2.dat
[17:14:53.254] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters_C3.dat
[17:14:53.254] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters_C4.dat
[17:14:53.254] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters_C5.dat
[17:14:53.254] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters_C6.dat
[17:14:53.254] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters_C7.dat
[17:14:53.254] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters_C8.dat
[17:14:53.255] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters_C9.dat
[17:14:53.255] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters_C10.dat
[17:14:53.255] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters_C11.dat
[17:14:53.255] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters_C12.dat
[17:14:53.255] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters_C13.dat
[17:14:53.255] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters_C14.dat
[17:14:53.256] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters_C15.dat
[17:14:53.256] INFO: PixTestPretest::doTest() done, duration: 53 seconds
[17:14:53.384] INFO: enter test to run
[17:14:53.384] INFO: test: fulltest no parameter change
[17:14:53.384] INFO: running: fulltest
[17:14:53.384] INFO: ######################################################################
[17:14:53.384] INFO: PixTestFullTest::doTest()
[17:14:53.384] INFO: ######################################################################
[17:14:53.385] INFO: ######################################################################
[17:14:53.385] INFO: PixTestAlive::doTest()
[17:14:53.385] INFO: ######################################################################
[17:14:53.387] INFO: ----------------------------------------------------------------------
[17:14:53.387] 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.387] INFO: ----------------------------------------------------------------------
[17:14:57.080] INFO: Test took 3691ms.
[17:14:57.119] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:14:57.374] INFO: PixTestAlive::aliveTest() done
[17:14:57.374] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 5 0 0 0 0 0 0
[17:14:57.376] INFO: ----------------------------------------------------------------------
[17:14:57.376] 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:57.376] INFO: ----------------------------------------------------------------------
[17:15:00.285] INFO: Test took 2906ms.
[17:15:00.292] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:15:00.293] INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[17:15:00.549] INFO: PixTestAlive::maskTest() done
[17:15:00.549] 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:00.551] INFO: ----------------------------------------------------------------------
[17:15:00.551] 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:00.551] INFO: ----------------------------------------------------------------------
[17:15:04.290] INFO: Test took 3736ms.
[17:15:04.328] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:15:04.582] INFO: PixTestAlive::addressDecodingTest() done
[17:15:04.582] 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:04.582] INFO: PixTestAlive::doTest() done, duration: 11 seconds
[17:15:04.593] INFO: ######################################################################
[17:15:04.593] INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[17:15:04.593] INFO: ######################################################################
[17:15:04.598] INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (30/5) hits flags = 2 (plus default)
[17:15:04.620] INFO: dacScan step from 0 .. 29
[17:15:04.620] INFO: dacScan split into 1 runs with ntrig = 5
[17:15:04.620] INFO: run 1 of 1
[17:15:24.262] INFO: Test took 19642ms.
[17:15:24.332] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:15:24.332] INFO: dacScan step from 30 .. 59
[17:15:24.332] INFO: dacScan split into 1 runs with ntrig = 5
[17:15:24.332] INFO: run 1 of 1
[17:15:44.397] INFO: Test took 20065ms.
[17:15:44.512] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:15:44.524] INFO: dacScan step from 60 .. 89
[17:15:44.524] INFO: dacScan split into 1 runs with ntrig = 5
[17:15:44.524] INFO: run 1 of 1
[17:16:09.854] INFO: Test took 25330ms.
[17:16:10.292] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:16:10.393] INFO: dacScan step from 90 .. 119
[17:16:10.393] INFO: dacScan split into 1 runs with ntrig = 5
[17:16:10.393] INFO: run 1 of 1
[17:16:37.935] INFO: Test took 27542ms.
[17:16:38.442] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:16:38.564] INFO: dacScan step from 120 .. 149
[17:16:38.564] INFO: dacScan split into 1 runs with ntrig = 5
[17:16:38.564] INFO: run 1 of 1
[17:17:02.980] INFO: Test took 24415ms.
[17:17:03.383] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:17:47.546] INFO: PixTestBBMap::doTest() done, duration: 162 seconds
[17:17:47.546] INFO: number of dead bumps (per ROC): 0 0 0 0 0 0 0 0 0 2 0 0 0 0 0 0
[17:17:47.546] INFO: separation cut (per ROC): 116 95 120 109 106 101 119 146 115 99 97 102 105 117 103 134
[17:17:47.666] INFO: ######################################################################
[17:17:47.666] INFO: PixTestScurves::fullTest() ntrig = 50, dacs/step = -1, ntrig/step = 1
[17:17:47.666] INFO: ######################################################################
[17:17:47.667] INFO: ----------------------------------------------------------------------
[17:17:47.667] INFO: PixTestScurves::scurves(Vcal), ntrig = 50, dacs/step = -1, ntrig/step = 1
[17:17:47.667] INFO: ----------------------------------------------------------------------
[17:17:47.667] INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 0 .. 149 (-1/1) hits flags = 16 (plus default)
[17:17:47.682] INFO: dacScan split into 50 runs with ntrig = 1
[17:17:47.682] INFO: run 1 of 50
[17:18:36.558] INFO: Test took 48876ms.
[17:18:36.990] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:18:37.289] INFO: run 2 of 50
[17:19:26.182] INFO: Test took 48893ms.
[17:19:26.607] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:19:26.947] INFO: run 3 of 50
[17:20:15.832] INFO: Test took 48885ms.
[17:20:16.260] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:20:16.531] INFO: run 4 of 50
[17:21:05.339] INFO: Test took 48808ms.
[17:21:05.820] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:21:06.147] INFO: run 5 of 50
[17:21:55.053] INFO: Test took 48906ms.
[17:21:55.494] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:21:55.720] INFO: run 6 of 50
[17:22:44.554] INFO: Test took 48834ms.
[17:22:44.989] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:22:45.209] INFO: run 7 of 50
[17:23:34.077] INFO: Test took 48868ms.
[17:23:34.512] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:23:34.740] INFO: run 8 of 50
[17:24:23.551] INFO: Test took 48811ms.
[17:24:24.077] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:24:24.275] INFO: run 9 of 50
[17:25:12.992] INFO: Test took 48717ms.
[17:25:13.460] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:25:13.665] INFO: run 10 of 50
[17:26:02.561] INFO: Test took 48896ms.
[17:26:03.042] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:26:03.247] INFO: run 11 of 50
[17:26:52.092] INFO: Test took 48844ms.
[17:26:52.654] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:26:52.869] INFO: run 12 of 50
[17:27:41.662] INFO: Test took 48793ms.
[17:27:42.164] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:27:42.377] INFO: run 13 of 50
[17:28:31.155] INFO: Test took 48778ms.
[17:28:31.720] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:28:31.923] INFO: run 14 of 50
[17:29:20.741] INFO: Test took 48817ms.
[17:29:21.301] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:29:21.509] INFO: run 15 of 50
[17:30:10.337] INFO: Test took 48828ms.
[17:30:10.781] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:30:10.997] INFO: run 16 of 50
[17:30:59.794] INFO: Test took 48797ms.
[17:31:00.241] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:31:00.505] INFO: run 17 of 50
[17:31:49.334] INFO: Test took 48829ms.
[17:31:49.744] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:31:49.973] INFO: run 18 of 50
[17:32:38.771] INFO: Test took 48797ms.
[17:32:39.206] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:32:39.424] INFO: run 19 of 50
[17:33:28.273] INFO: Test took 48849ms.
[17:33:28.788] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:33:29.053] INFO: run 20 of 50
[17:34:17.913] INFO: Test took 48860ms.
[17:34:18.370] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:34:18.581] INFO: run 21 of 50
[17:35:07.415] INFO: Test took 48834ms.
[17:35:07.845] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:35:08.054] INFO: run 22 of 50
[17:35:56.879] INFO: Test took 48825ms.
[17:35:57.315] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:35:57.514] INFO: run 23 of 50
[17:36:46.411] INFO: Test took 48896ms.
[17:36:46.810] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:36:47.004] INFO: run 24 of 50
[17:37:35.904] INFO: Test took 48899ms.
[17:37:36.312] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:37:36.525] INFO: run 25 of 50
[17:38:25.430] INFO: Test took 48905ms.
[17:38:25.869] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:38:26.078] INFO: run 26 of 50
[17:39:15.007] INFO: Test took 48929ms.
[17:39:15.456] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:39:15.667] INFO: run 27 of 50
[17:40:04.528] INFO: Test took 48861ms.
[17:40:04.958] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:40:05.162] INFO: run 28 of 50
[17:40:54.045] INFO: Test took 48883ms.
[17:40:54.464] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:40:54.666] INFO: run 29 of 50
[17:41:43.566] INFO: Test took 48900ms.
[17:41:43.000] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:41:44.208] INFO: run 30 of 50
[17:42:33.103] INFO: Test took 48895ms.
[17:42:33.502] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:42:33.693] INFO: run 31 of 50
[17:43:22.616] INFO: Test took 48922ms.
[17:43:23.044] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:43:23.241] INFO: run 32 of 50
[17:44:12.153] INFO: Test took 48911ms.
[17:44:12.603] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:44:12.817] INFO: run 33 of 50
[17:45:01.725] INFO: Test took 48908ms.
[17:45:02.145] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:45:02.352] INFO: run 34 of 50
[17:45:51.364] INFO: Test took 49012ms.
[17:45:51.815] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:45:52.027] INFO: run 35 of 50
[17:46:40.921] INFO: Test took 48894ms.
[17:46:41.343] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:46:41.555] INFO: run 36 of 50
[17:47:30.595] INFO: Test took 49040ms.
[17:47:31.004] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:47:31.211] INFO: run 37 of 50
[17:48:20.137] INFO: Test took 48925ms.
[17:48:20.534] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:48:20.723] INFO: run 38 of 50
[17:49:09.632] INFO: Test took 48908ms.
[17:49:10.053] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:49:10.261] INFO: run 39 of 50
[17:49:59.193] INFO: Test took 48932ms.
[17:49:59.623] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:49:59.836] INFO: run 40 of 50
[17:50:48.866] INFO: Test took 49030ms.
[17:50:49.251] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:50:49.450] INFO: run 41 of 50
[17:51:38.503] INFO: Test took 49053ms.
[17:51:38.903] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:51:39.111] INFO: run 42 of 50
[17:52:28.130] INFO: Test took 49019ms.
[17:52:28.554] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:52:28.768] INFO: run 43 of 50
[17:53:17.753] INFO: Test took 48985ms.
[17:53:18.170] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:53:18.367] INFO: run 44 of 50
[17:54:07.398] INFO: Test took 49031ms.
[17:54:07.781] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:54:07.973] INFO: run 45 of 50
[17:54:57.030] INFO: Test took 49057ms.
[17:54:57.460] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:54:57.670] INFO: run 46 of 50
[17:55:46.742] INFO: Test took 49072ms.
[17:55:47.181] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:55:47.394] INFO: run 47 of 50
[17:56:36.459] INFO: Test took 49065ms.
[17:56:36.869] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:56:37.064] INFO: run 48 of 50
[17:57:26.109] INFO: Test took 49045ms.
[17:57:26.534] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:57:26.758] INFO: run 49 of 50
[17:58:15.994] INFO: Test took 49236ms.
[17:58:16.408] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:58:16.614] INFO: run 50 of 50
[17:59:05.741] INFO: Test took 49127ms.
[17:59:06.261] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:59:06.496] INFO: dumping ASCII scurve output file: SCurveData
[17:59:09.083] INFO: dumping ASCII scurve output file: SCurveData
[17:59:11.659] INFO: dumping ASCII scurve output file: SCurveData
[17:59:14.285] INFO: dumping ASCII scurve output file: SCurveData
[17:59:16.899] INFO: dumping ASCII scurve output file: SCurveData
[17:59:19.612] INFO: dumping ASCII scurve output file: SCurveData
[17:59:22.508] INFO: dumping ASCII scurve output file: SCurveData
[17:59:25.369] INFO: dumping ASCII scurve output file: SCurveData
[17:59:28.222] INFO: dumping ASCII scurve output file: SCurveData
[17:59:31.033] INFO: dumping ASCII scurve output file: SCurveData
[17:59:33.770] INFO: dumping ASCII scurve output file: SCurveData
[17:59:36.452] INFO: dumping ASCII scurve output file: SCurveData
[17:59:39.317] INFO: dumping ASCII scurve output file: SCurveData
[17:59:42.081] INFO: dumping ASCII scurve output file: SCurveData
[17:59:44.768] INFO: dumping ASCII scurve output file: SCurveData
[17:59:47.449] INFO: dumping ASCII scurve output file: SCurveData
[17:59:49.894] INFO: PixTestScurves::scurves() done
[17:59:49.894] INFO: Vcal mean: 96.58 86.82 109.77 93.01 93.83 93.31 94.77 108.96 94.48 84.99 87.28 91.56 104.43 109.45 90.73 97.87
[17:59:49.894] INFO: Vcal RMS: 5.22 6.20 5.43 5.39 5.83 6.13 5.60 6.04 7.09 5.75 5.40 5.46 6.10 5.46 6.02 5.65
[17:59:49.894] INFO: PixTestScurves::fullTest() done, duration: 2522 seconds
[17:59:50.024] INFO: ######################################################################
[17:59:50.024] INFO: PixTestTrim::doTest()
[17:59:50.024] INFO: ######################################################################
[17:59:50.026] INFO: ----------------------------------------------------------------------
[17:59:50.026] INFO: PixTestTrim::trimTest() ntrig = 10, vcal = 35
[17:59:50.026] INFO: ----------------------------------------------------------------------
[17:59:50.183] INFO: ---> VthrComp thr map (minimal VthrComp)
[17:59:50.183] INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 5 dacrange: 0 .. 159 (20/-1) hits flags = 16 (plus default)
[17:59:50.199] INFO: dacScan step from 0 .. 19
[17:59:50.199] INFO: dacScan split into 1 runs with ntrig = 5
[17:59:50.199] INFO: run 1 of 1
[18:00:04.538] INFO: Test took 14340ms.
[18:00:04.588] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:00:04.589] INFO: dacScan step from 20 .. 39
[18:00:04.589] INFO: dacScan split into 1 runs with ntrig = 5
[18:00:04.589] INFO: run 1 of 1
[18:00:18.954] INFO: Test took 14365ms.
[18:00:18.999] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:00:18.999] INFO: dacScan step from 40 .. 59
[18:00:18.999] INFO: dacScan split into 1 runs with ntrig = 5
[18:00:18.999] INFO: run 1 of 1
[18:00:33.257] INFO: Test took 14257ms.
[18:00:33.299] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:00:33.299] INFO: dacScan step from 60 .. 79
[18:00:33.299] INFO: dacScan split into 1 runs with ntrig = 5
[18:00:33.299] INFO: run 1 of 1
[18:00:47.527] INFO: Test took 14228ms.
[18:00:47.571] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:00:47.571] INFO: dacScan step from 80 .. 99
[18:00:47.571] INFO: dacScan split into 1 runs with ntrig = 5
[18:00:47.571] INFO: run 1 of 1
[18:01:02.008] INFO: Test took 14437ms.
[18:01:02.085] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:01:02.090] INFO: dacScan step from 100 .. 119
[18:01:02.090] INFO: dacScan split into 1 runs with ntrig = 5
[18:01:02.090] INFO: run 1 of 1
[18:01:19.150] INFO: Test took 17060ms.
[18:01:19.434] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:01:19.496] INFO: dacScan step from 120 .. 139
[18:01:19.496] INFO: dacScan split into 1 runs with ntrig = 5
[18:01:19.496] INFO: run 1 of 1
[18:01:37.615] INFO: Test took 18118ms.
[18:01:37.879] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:01:37.942] INFO: dacScan step from 140 .. 159
[18:01:37.942] INFO: dacScan split into 1 runs with ntrig = 5
[18:01:37.942] INFO: run 1 of 1
[18:01:53.325] INFO: Test took 15383ms.
[18:01:53.499] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:02:35.451] INFO: ROC 0 VthrComp = 101
[18:02:35.451] INFO: ROC 1 VthrComp = 85
[18:02:35.451] INFO: ROC 2 VthrComp = 108
[18:02:35.451] INFO: ROC 3 VthrComp = 97
[18:02:35.451] INFO: ROC 4 VthrComp = 92
[18:02:35.452] INFO: ROC 5 VthrComp = 91
[18:02:35.452] INFO: ROC 6 VthrComp = 94
[18:02:35.452] INFO: ROC 7 VthrComp = 105
[18:02:35.452] INFO: ROC 8 VthrComp = 92
[18:02:35.452] INFO: ROC 9 VthrComp = 91
[18:02:35.452] INFO: ROC 10 VthrComp = 91
[18:02:35.452] INFO: ROC 11 VthrComp = 96
[18:02:35.452] INFO: ROC 12 VthrComp = 99
[18:02:35.453] INFO: ROC 13 VthrComp = 110
[18:02:35.453] INFO: ROC 14 VthrComp = 92
[18:02:35.453] INFO: ROC 15 VthrComp = 98
[18:02:35.453] INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[18:02:35.453] INFO: ---> dac: vcal name: TrimThr1 ntrig: 5 dacrange: 0 .. 159 (20/-1) hits flags = 16 (plus default)
[18:02:35.468] INFO: dacScan step from 0 .. 19
[18:02:35.468] INFO: dacScan split into 1 runs with ntrig = 5
[18:02:35.468] INFO: run 1 of 1
[18:02:49.628] INFO: Test took 14160ms.
[18:02:49.671] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:02:49.671] INFO: dacScan step from 20 .. 39
[18:02:49.671] INFO: dacScan split into 1 runs with ntrig = 5
[18:02:49.671] INFO: run 1 of 1
[18:03:03.918] INFO: Test took 14247ms.
[18:03:03.981] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:03:03.986] INFO: dacScan step from 40 .. 59
[18:03:03.986] INFO: dacScan split into 1 runs with ntrig = 5
[18:03:03.986] INFO: run 1 of 1
[18:03:21.473] INFO: Test took 17487ms.
[18:03:21.729] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:03:21.791] INFO: dacScan step from 60 .. 79
[18:03:21.791] INFO: dacScan split into 1 runs with ntrig = 5
[18:03:21.791] INFO: run 1 of 1
[18:03:41.192] INFO: Test took 19400ms.
[18:03:41.536] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:03:41.623] INFO: dacScan step from 80 .. 99
[18:03:41.623] INFO: dacScan split into 1 runs with ntrig = 5
[18:03:41.623] INFO: run 1 of 1
[18:04:01.281] INFO: Test took 19658ms.
[18:04:01.612] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:04:01.689] INFO: dacScan step from 100 .. 119
[18:04:01.689] INFO: dacScan split into 1 runs with ntrig = 5
[18:04:01.689] INFO: run 1 of 1
[18:04:21.318] INFO: Test took 19629ms.
[18:04:21.660] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:04:21.737] INFO: dacScan step from 120 .. 139
[18:04:21.737] INFO: dacScan split into 1 runs with ntrig = 5
[18:04:21.737] INFO: run 1 of 1
[18:04:41.362] INFO: Test took 19624ms.
[18:04:41.678] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:04:41.752] INFO: dacScan step from 140 .. 159
[18:04:41.752] INFO: dacScan split into 1 runs with ntrig = 5
[18:04:41.752] INFO: run 1 of 1
[18:05:01.115] INFO: Test took 19363ms.
[18:05:01.542] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:05:48.253] INFO: roc 0 with ID = 0 has maximal Vcal 58.3468 for pixel 12/21 mean/min/max = 45.2775/31.8026/58.7523
[18:05:48.253] INFO: roc 1 with ID = 1 has maximal Vcal 64.7725 for pixel 0/14 mean/min/max = 48.0717/31.3197/64.8238
[18:05:48.254] INFO: roc 2 with ID = 2 has maximal Vcal 64.8666 for pixel 4/20 mean/min/max = 49.514/33.9149/65.113
[18:05:48.254] INFO: roc 3 with ID = 3 has maximal Vcal 57.9826 for pixel 51/79 mean/min/max = 44.6233/31.2601/57.9865
[18:05:48.255] INFO: roc 4 with ID = 4 has maximal Vcal 62.7256 for pixel 51/18 mean/min/max = 47.3388/31.8862/62.7913
[18:05:48.255] INFO: roc 5 with ID = 5 has maximal Vcal 63.5937 for pixel 10/25 mean/min/max = 47.555/31.4156/63.6944
[18:05:48.256] INFO: roc 6 with ID = 6 has maximal Vcal 60.7417 for pixel 20/1 mean/min/max = 46.4524/32.123/60.7817
[18:05:48.257] INFO: roc 7 with ID = 7 has maximal Vcal 66.5632 for pixel 1/79 mean/min/max = 50.4607/33.8255/67.0959
[18:05:48.257] INFO: roc 8 with ID = 8 has maximal Vcal 64.0899 for pixel 11/75 mean/min/max = 47.683/31.1069/64.2591
[18:05:48.258] INFO: roc 9 with ID = 9 has maximal Vcal 57.8239 for pixel 21/55 mean/min/max = 45.042/31.7829/58.3012
[18:05:48.259] INFO: roc 10 with ID = 10 has maximal Vcal 58.3362 for pixel 3/7 mean/min/max = 45.4821/32.1381/58.8261
[18:05:48.259] INFO: roc 11 with ID = 11 has maximal Vcal 59.8657 for pixel 0/76 mean/min/max = 45.2906/30.7143/59.8668
[18:05:48.260] INFO: roc 12 with ID = 12 has maximal Vcal 63.782 for pixel 5/5 mean/min/max = 47.9563/31.7605/64.1521
[18:05:48.260] INFO: roc 13 with ID = 13 has maximal Vcal 64.1243 for pixel 22/5 mean/min/max = 49.272/34.408/64.136
[18:05:48.261] INFO: roc 14 with ID = 14 has maximal Vcal 60.1268 for pixel 0/61 mean/min/max = 46.0465/31.9343/60.1586
[18:05:48.262] INFO: roc 15 with ID = 15 has maximal Vcal 59.9747 for pixel 22/75 mean/min/max = 45.8394/31.4795/60.1994
[18:05:48.262] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:07:09.633] INFO: Test took 81371ms.
[18:07:11.889] INFO: ---> dac: vcal name: TrimThr2 ntrig: 10 dacrange: 0 .. 199 (20/5) hits flags = 16 (plus default)
[18:07:11.904] INFO: dacScan step from 0 .. 19
[18:07:11.904] INFO: dacScan split into 2 runs with ntrig = 5
[18:07:11.904] INFO: run 1 of 2
[18:07:26.147] INFO: Test took 14243ms.
[18:07:26.208] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:07:26.211] INFO: run 2 of 2
[18:07:40.403] INFO: Test took 14192ms.
[18:07:40.463] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:07:40.468] INFO: dacScan step from 20 .. 39
[18:07:40.468] INFO: dacScan split into 2 runs with ntrig = 5
[18:07:40.468] INFO: run 1 of 2
[18:07:57.194] INFO: Test took 16726ms.
[18:07:57.426] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:07:57.479] INFO: run 2 of 2
[18:08:14.122] INFO: Test took 16642ms.
[18:08:14.357] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:08:14.412] INFO: dacScan step from 40 .. 59
[18:08:14.412] INFO: dacScan split into 2 runs with ntrig = 5
[18:08:14.412] INFO: run 1 of 2
[18:08:33.736] INFO: Test took 19324ms.
[18:08:34.074] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:08:34.160] INFO: run 2 of 2
[18:08:53.416] INFO: Test took 19256ms.
[18:08:53.759] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:08:53.843] INFO: dacScan step from 60 .. 79
[18:08:53.843] INFO: dacScan split into 2 runs with ntrig = 5
[18:08:53.843] INFO: run 1 of 2
[18:09:13.107] INFO: Test took 19264ms.
[18:09:13.406] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:09:13.486] INFO: run 2 of 2
[18:09:32.795] INFO: Test took 19309ms.
[18:09:33.122] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:09:33.202] INFO: dacScan step from 80 .. 99
[18:09:33.202] INFO: dacScan split into 2 runs with ntrig = 5
[18:09:33.202] INFO: run 1 of 2
[18:09:52.431] INFO: Test took 19229ms.
[18:09:52.765] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:09:52.836] INFO: run 2 of 2
[18:10:12.070] INFO: Test took 19234ms.
[18:10:12.411] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:10:12.494] INFO: dacScan step from 100 .. 119
[18:10:12.494] INFO: dacScan split into 2 runs with ntrig = 5
[18:10:12.494] INFO: run 1 of 2
[18:10:31.783] INFO: Test took 19289ms.
[18:10:32.132] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:10:32.220] INFO: run 2 of 2
[18:10:51.438] INFO: Test took 19218ms.
[18:10:51.752] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:10:51.845] INFO: dacScan step from 120 .. 139
[18:10:51.845] INFO: dacScan split into 2 runs with ntrig = 5
[18:10:51.845] INFO: run 1 of 2
[18:11:11.137] INFO: Test took 19292ms.
[18:11:11.469] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:11:11.575] INFO: run 2 of 2
[18:11:30.786] INFO: Test took 19211ms.
[18:11:31.128] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:11:31.213] INFO: dacScan step from 140 .. 159
[18:11:31.213] INFO: dacScan split into 2 runs with ntrig = 5
[18:11:31.213] INFO: run 1 of 2
[18:11:50.497] INFO: Test took 19284ms.
[18:11:50.830] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:11:50.911] INFO: run 2 of 2
[18:12:10.158] INFO: Test took 19246ms.
[18:12:10.499] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:12:10.567] INFO: dacScan step from 160 .. 179
[18:12:10.567] INFO: dacScan split into 2 runs with ntrig = 5
[18:12:10.567] INFO: run 1 of 2
[18:12:29.976] INFO: Test took 19409ms.
[18:12:30.320] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:12:30.403] INFO: run 2 of 2
[18:12:49.777] INFO: Test took 19374ms.
[18:12:50.119] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:12:50.202] INFO: dacScan step from 180 .. 199
[18:12:50.202] INFO: dacScan split into 2 runs with ntrig = 5
[18:12:50.202] INFO: run 1 of 2
[18:13:10.412] INFO: Test took 20210ms.
[18:13:10.751] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:13:10.832] INFO: run 2 of 2
[18:13:31.056] INFO: Test took 20224ms.
[18:13:31.461] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:14:20.354] INFO: ---> TrimStepCorr4 extremal thresholds: 0.023349 .. 255.000000
[18:14:20.507] INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 4 dacrange: 0 .. 255 (20/-1) hits flags = 16 (plus default)
[18:14:20.522] INFO: dacScan step from 0 .. 19
[18:14:20.522] INFO: dacScan split into 1 runs with ntrig = 4
[18:14:20.522] INFO: run 1 of 1
[18:14:33.397] INFO: Test took 12875ms.
[18:14:33.441] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:14:33.441] INFO: dacScan step from 20 .. 39
[18:14:33.441] INFO: dacScan split into 1 runs with ntrig = 4
[18:14:33.441] INFO: run 1 of 1
[18:14:47.260] INFO: Test took 13819ms.
[18:14:47.400] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:14:47.434] INFO: dacScan step from 40 .. 59
[18:14:47.434] INFO: dacScan split into 1 runs with ntrig = 4
[18:14:47.434] INFO: run 1 of 1
[18:15:04.362] INFO: Test took 16928ms.
[18:15:04.651] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:15:04.735] INFO: dacScan step from 60 .. 79
[18:15:04.735] INFO: dacScan split into 1 runs with ntrig = 4
[18:15:04.735] INFO: run 1 of 1
[18:15:21.969] INFO: Test took 17234ms.
[18:15:22.261] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:15:22.345] INFO: dacScan step from 80 .. 99
[18:15:22.345] INFO: dacScan split into 1 runs with ntrig = 4
[18:15:22.345] INFO: run 1 of 1
[18:15:39.505] INFO: Test took 17160ms.
[18:15:39.793] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:15:39.875] INFO: dacScan step from 100 .. 119
[18:15:39.875] INFO: dacScan split into 1 runs with ntrig = 4
[18:15:39.875] INFO: run 1 of 1
[18:15:57.068] INFO: Test took 17193ms.
[18:15:57.356] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:15:57.441] INFO: dacScan step from 120 .. 139
[18:15:57.441] INFO: dacScan split into 1 runs with ntrig = 4
[18:15:57.441] INFO: run 1 of 1
[18:16:14.612] INFO: Test took 17171ms.
[18:16:14.893] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:16:14.973] INFO: dacScan step from 140 .. 159
[18:16:14.973] INFO: dacScan split into 1 runs with ntrig = 4
[18:16:14.973] INFO: run 1 of 1
[18:16:32.053] INFO: Test took 17080ms.
[18:16:32.333] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:16:32.416] INFO: dacScan step from 160 .. 179
[18:16:32.416] INFO: dacScan split into 1 runs with ntrig = 4
[18:16:32.416] INFO: run 1 of 1
[18:16:49.721] INFO: Test took 17305ms.
[18:16:50.015] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:16:50.099] INFO: dacScan step from 180 .. 199
[18:16:50.099] INFO: dacScan split into 1 runs with ntrig = 4
[18:16:50.099] INFO: run 1 of 1
[18:17:08.291] INFO: Test took 18192ms.
[18:17:08.603] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:17:08.692] INFO: dacScan step from 200 .. 219
[18:17:08.692] INFO: dacScan split into 1 runs with ntrig = 4
[18:17:08.692] INFO: run 1 of 1
[18:17:25.902] INFO: Test took 17210ms.
[18:17:26.218] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:17:26.300] INFO: dacScan step from 220 .. 239
[18:17:26.300] INFO: dacScan split into 1 runs with ntrig = 4
[18:17:26.300] INFO: run 1 of 1
[18:17:43.458] INFO: Test took 17158ms.
[18:17:43.844] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:17:43.927] INFO: dacScan step from 240 .. 255
[18:17:43.927] INFO: dacScan split into 1 runs with ntrig = 4
[18:17:43.927] INFO: run 1 of 1
[18:17:58.339] INFO: Test took 14412ms.
[18:17:58.596] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:18:55.193] INFO: ---> TrimStepCorr2 extremal thresholds: 2.086550 .. 110.124778
[18:18:55.333] INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 4 dacrange: 2 .. 120 (20/-1) hits flags = 16 (plus default)
[18:18:55.348] INFO: dacScan step from 2 .. 21
[18:18:55.348] INFO: dacScan split into 1 runs with ntrig = 4
[18:18:55.348] INFO: run 1 of 1
[18:19:08.169] INFO: Test took 12820ms.
[18:19:08.214] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:19:08.214] INFO: dacScan step from 22 .. 41
[18:19:08.214] INFO: dacScan split into 1 runs with ntrig = 4
[18:19:08.214] INFO: run 1 of 1
[18:19:22.428] INFO: Test took 14214ms.
[18:19:22.597] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:19:22.641] INFO: dacScan step from 42 .. 61
[18:19:22.641] INFO: dacScan split into 1 runs with ntrig = 4
[18:19:22.641] INFO: run 1 of 1
[18:19:39.820] INFO: Test took 17179ms.
[18:19:40.131] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:19:40.216] INFO: dacScan step from 62 .. 81
[18:19:40.216] INFO: dacScan split into 1 runs with ntrig = 4
[18:19:40.216] INFO: run 1 of 1
[18:19:57.579] INFO: Test took 17363ms.
[18:19:57.893] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:19:57.984] INFO: dacScan step from 82 .. 101
[18:19:57.984] INFO: dacScan split into 1 runs with ntrig = 4
[18:19:57.984] INFO: run 1 of 1
[18:20:15.174] INFO: Test took 17190ms.
[18:20:15.511] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:20:15.595] INFO: dacScan step from 102 .. 120
[18:20:15.595] INFO: dacScan split into 1 runs with ntrig = 4
[18:20:15.595] INFO: run 1 of 1
[18:20:32.360] INFO: Test took 16765ms.
[18:20:32.645] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:21:13.335] INFO: ---> TrimStepCorr1a extremal thresholds: 1.990075 .. 90.728317
[18:21:13.477] INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 4 dacrange: 1 .. 100 (20/-1) hits flags = 16 (plus default)
[18:21:13.492] INFO: dacScan step from 1 .. 20
[18:21:13.492] INFO: dacScan split into 1 runs with ntrig = 4
[18:21:13.492] INFO: run 1 of 1
[18:21:26.359] INFO: Test took 12867ms.
[18:21:26.405] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:21:26.405] INFO: dacScan step from 21 .. 40
[18:21:26.405] INFO: dacScan split into 1 runs with ntrig = 4
[18:21:26.405] INFO: run 1 of 1
[18:21:40.494] INFO: Test took 14089ms.
[18:21:40.643] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:21:40.683] INFO: dacScan step from 41 .. 60
[18:21:40.683] INFO: dacScan split into 1 runs with ntrig = 4
[18:21:40.683] INFO: run 1 of 1
[18:21:57.894] INFO: Test took 17211ms.
[18:21:58.201] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:21:58.285] INFO: dacScan step from 61 .. 80
[18:21:58.285] INFO: dacScan split into 1 runs with ntrig = 4
[18:21:58.285] INFO: run 1 of 1
[18:22:15.693] INFO: Test took 17407ms.
[18:22:16.091] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:22:16.178] INFO: dacScan step from 81 .. 100
[18:22:16.178] INFO: dacScan split into 1 runs with ntrig = 4
[18:22:16.178] INFO: run 1 of 1
[18:22:33.555] INFO: Test took 17377ms.
[18:22:33.823] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:23:11.520] INFO: ---> TrimStepCorr1b extremal thresholds: 0.222764 .. 78.023926
[18:23:11.679] INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 4 dacrange: 0 .. 88 (20/-1) hits flags = 16 (plus default)
[18:23:11.695] INFO: dacScan step from 0 .. 19
[18:23:11.695] INFO: dacScan split into 1 runs with ntrig = 4
[18:23:11.695] INFO: run 1 of 1
[18:23:24.561] INFO: Test took 12866ms.
[18:23:24.604] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:23:24.604] INFO: dacScan step from 20 .. 39
[18:23:24.604] INFO: dacScan split into 1 runs with ntrig = 4
[18:23:24.604] INFO: run 1 of 1
[18:23:38.365] INFO: Test took 13761ms.
[18:23:38.503] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:23:38.537] INFO: dacScan step from 40 .. 59
[18:23:38.537] INFO: dacScan split into 1 runs with ntrig = 4
[18:23:38.537] INFO: run 1 of 1
[18:23:55.695] INFO: Test took 17157ms.
[18:23:55.985] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:23:56.069] INFO: dacScan step from 60 .. 79
[18:23:56.069] INFO: dacScan split into 1 runs with ntrig = 4
[18:23:56.069] INFO: run 1 of 1
[18:24:13.471] INFO: Test took 17402ms.
[18:24:13.750] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:24:13.830] INFO: dacScan step from 80 .. 88
[18:24:13.830] INFO: dacScan split into 1 runs with ntrig = 4
[18:24:13.830] INFO: run 1 of 1
[18:24:23.401] INFO: Test took 9571ms.
[18:24:23.524] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:24:56.563] INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[18:24:56.563] INFO: ---> dac: vcal name: TrimThrFinal ntrig: 10 dacrange: 15 .. 55 (20/5) hits flags = 16 (plus default)
[18:24:56.578] INFO: dacScan step from 15 .. 34
[18:24:56.578] INFO: dacScan split into 2 runs with ntrig = 5
[18:24:56.579] INFO: run 1 of 2
[18:25:10.950] INFO: Test took 14371ms.
[18:25:11.031] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:25:11.046] INFO: run 2 of 2
[18:25:25.422] INFO: Test took 14376ms.
[18:25:25.509] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:25:25.526] INFO: dacScan step from 35 .. 54
[18:25:25.526] INFO: dacScan split into 2 runs with ntrig = 5
[18:25:25.526] INFO: run 1 of 2
[18:25:44.471] INFO: Test took 18945ms.
[18:25:44.815] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:25:44.886] INFO: run 2 of 2
[18:26:03.887] INFO: Test took 19001ms.
[18:26:04.281] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:26:04.377] INFO: dacScan step from 55 .. 55
[18:26:04.377] INFO: dacScan split into 2 runs with ntrig = 5
[18:26:04.377] INFO: run 1 of 2
[18:26:08.472] INFO: Test took 4095ms.
[18:26:08.493] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:26:08.500] INFO: run 2 of 2
[18:26:12.499] INFO: Test took 3999ms.
[18:26:12.519] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:26:34.379] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C0.dat
[18:26:34.379] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C1.dat
[18:26:34.379] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C2.dat
[18:26:34.379] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C3.dat
[18:26:34.380] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C4.dat
[18:26:34.380] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C5.dat
[18:26:34.380] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C6.dat
[18:26:34.380] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C7.dat
[18:26:34.380] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C8.dat
[18:26:34.380] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C9.dat
[18:26:34.380] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C10.dat
[18:26:34.380] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C11.dat
[18:26:34.380] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C12.dat
[18:26:34.380] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C13.dat
[18:26:34.381] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C14.dat
[18:26:34.381] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C15.dat
[18:26:34.381] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/trimParameters35_C0.dat
[18:26:34.392] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/trimParameters35_C1.dat
[18:26:34.403] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/trimParameters35_C2.dat
[18:26:34.414] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/trimParameters35_C3.dat
[18:26:34.425] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/trimParameters35_C4.dat
[18:26:34.436] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/trimParameters35_C5.dat
[18:26:34.447] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/trimParameters35_C6.dat
[18:26:34.458] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/trimParameters35_C7.dat
[18:26:34.469] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/trimParameters35_C8.dat
[18:26:34.481] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/trimParameters35_C9.dat
[18:26:34.492] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/trimParameters35_C10.dat
[18:26:34.504] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/trimParameters35_C11.dat
[18:26:34.516] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/trimParameters35_C12.dat
[18:26:34.529] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/trimParameters35_C13.dat
[18:26:34.540] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/trimParameters35_C14.dat
[18:26:34.553] INFO: write trim parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/trimParameters35_C15.dat
[18:26:34.564] INFO: PixTestTrim::trimTest() done
[18:26:34.564] INFO: vtrim: 118 98 117 94 102 115 114 138 108 114 102 104 107 136 100 109
[18:26:34.564] INFO: vthrcomp: 101 85 108 97 92 91 94 105 92 91 91 96 99 110 92 98
[18:26:34.564] INFO: vcal mean: 35.02 35.10 35.11 35.02 35.06 35.07 35.07 35.11 35.05 35.01 35.09 35.02 35.10 35.11 35.08 35.04
[18:26:34.564] INFO: vcal RMS: 1.07 1.32 1.12 1.22 1.12 1.12 1.16 1.13 1.29 1.37 1.05 1.02 1.38 1.07 1.10 1.11
[18:26:34.564] INFO: bits mean: 10.27 9.15 9.17 10.13 9.40 9.92 10.13 8.69 9.92 10.30 9.84 9.58 9.37 8.86 9.47 9.98
[18:26:34.564] INFO: bits RMS: 2.35 2.74 2.32 2.53 2.58 2.42 2.30 2.45 2.46 2.30 2.52 2.81 2.62 2.36 2.75 2.47
[18:26:34.577] INFO: ----------------------------------------------------------------------
[18:26:34.577] INFO: PixTestTrim::trimBitTest() ntrig = 10, vtrims = 254 126 63 32
[18:26:34.577] INFO: ----------------------------------------------------------------------
[18:26:34.582] INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 10 dacrange: 0 .. 199 (20/5) hits flags = 16 (plus default)
[18:26:34.597] INFO: dacScan step from 0 .. 19
[18:26:34.597] INFO: dacScan split into 2 runs with ntrig = 5
[18:26:34.597] INFO: run 1 of 2
[18:26:48.791] INFO: Test took 14194ms.
[18:26:48.845] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:26:48.845] INFO: run 2 of 2
[18:27:02.979] INFO: Test took 14133ms.
[18:27:03.031] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:27:03.031] INFO: dacScan step from 20 .. 39
[18:27:03.031] INFO: dacScan split into 2 runs with ntrig = 5
[18:27:03.031] INFO: run 1 of 2
[18:27:17.138] INFO: Test took 14107ms.
[18:27:17.179] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:27:17.179] INFO: run 2 of 2
[18:27:31.452] INFO: Test took 14272ms.
[18:27:31.499] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:27:31.499] INFO: dacScan step from 40 .. 59
[18:27:31.499] INFO: dacScan split into 2 runs with ntrig = 5
[18:27:31.499] INFO: run 1 of 2
[18:27:45.762] INFO: Test took 14263ms.
[18:27:45.825] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:27:45.825] INFO: run 2 of 2
[18:27:59.969] INFO: Test took 14144ms.
[18:28:00.019] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:28:00.019] INFO: dacScan step from 60 .. 79
[18:28:00.019] INFO: dacScan split into 2 runs with ntrig = 5
[18:28:00.019] INFO: run 1 of 2
[18:28:14.146] INFO: Test took 14126ms.
[18:28:14.194] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:28:14.194] INFO: run 2 of 2
[18:28:28.415] INFO: Test took 14220ms.
[18:28:28.465] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:28:28.465] INFO: dacScan step from 80 .. 99
[18:28:28.465] INFO: dacScan split into 2 runs with ntrig = 5
[18:28:28.465] INFO: run 1 of 2
[18:28:42.568] INFO: Test took 14103ms.
[18:28:42.620] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:28:42.620] INFO: run 2 of 2
[18:28:56.806] INFO: Test took 14185ms.
[18:28:56.859] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:28:56.860] INFO: dacScan step from 100 .. 119
[18:28:56.860] INFO: dacScan split into 2 runs with ntrig = 5
[18:28:56.860] INFO: run 1 of 2
[18:29:11.842] INFO: Test took 14982ms.
[18:29:11.980] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:29:11.999] INFO: run 2 of 2
[18:29:27.029] INFO: Test took 15029ms.
[18:29:27.149] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:29:27.166] INFO: dacScan step from 120 .. 139
[18:29:27.166] INFO: dacScan split into 2 runs with ntrig = 5
[18:29:27.166] INFO: run 1 of 2
[18:29:45.077] INFO: Test took 17910ms.
[18:29:45.371] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:29:45.437] INFO: run 2 of 2
[18:30:03.203] INFO: Test took 17766ms.
[18:30:03.493] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:30:03.556] INFO: dacScan step from 140 .. 159
[18:30:03.556] INFO: dacScan split into 2 runs with ntrig = 5
[18:30:03.556] INFO: run 1 of 2
[18:30:23.062] INFO: Test took 19505ms.
[18:30:23.396] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:30:23.477] INFO: run 2 of 2
[18:30:42.835] INFO: Test took 19357ms.
[18:30:43.166] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:30:43.251] INFO: dacScan step from 160 .. 179
[18:30:43.251] INFO: dacScan split into 2 runs with ntrig = 5
[18:30:43.251] INFO: run 1 of 2
[18:31:03.016] INFO: Test took 19765ms.
[18:31:03.414] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:31:03.497] INFO: run 2 of 2
[18:31:23.342] INFO: Test took 19845ms.
[18:31:23.678] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:31:23.760] INFO: dacScan step from 180 .. 199
[18:31:23.760] INFO: dacScan split into 2 runs with ntrig = 5
[18:31:23.760] INFO: run 1 of 2
[18:31:44.261] INFO: Test took 20501ms.
[18:31:44.573] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:31:44.656] INFO: run 2 of 2
[18:32:05.336] INFO: Test took 20680ms.
[18:32:05.664] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:32:48.126] INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 10 dacrange: 0 .. 182 (20/5) hits flags = 16 (plus default)
[18:32:48.141] INFO: dacScan step from 0 .. 19
[18:32:48.141] INFO: dacScan split into 2 runs with ntrig = 5
[18:32:48.141] INFO: run 1 of 2
[18:33:02.354] INFO: Test took 14213ms.
[18:33:02.401] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:33:02.401] INFO: run 2 of 2
[18:33:16.523] INFO: Test took 14122ms.
[18:33:16.579] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:33:16.579] INFO: dacScan step from 20 .. 39
[18:33:16.579] INFO: dacScan split into 2 runs with ntrig = 5
[18:33:16.579] INFO: run 1 of 2
[18:33:30.717] INFO: Test took 14138ms.
[18:33:30.764] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:33:30.764] INFO: run 2 of 2
[18:33:44.815] INFO: Test took 14051ms.
[18:33:44.864] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:33:44.864] INFO: dacScan step from 40 .. 59
[18:33:44.864] INFO: dacScan split into 2 runs with ntrig = 5
[18:33:44.864] INFO: run 1 of 2
[18:33:58.971] INFO: Test took 14107ms.
[18:33:59.022] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:33:59.022] INFO: run 2 of 2
[18:34:13.317] INFO: Test took 14295ms.
[18:34:13.363] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:34:13.363] INFO: dacScan step from 60 .. 79
[18:34:13.363] INFO: dacScan split into 2 runs with ntrig = 5
[18:34:13.363] INFO: run 1 of 2
[18:34:27.532] INFO: Test took 14169ms.
[18:34:27.584] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:34:27.584] INFO: run 2 of 2
[18:34:41.633] INFO: Test took 14049ms.
[18:34:41.685] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:34:41.685] INFO: dacScan step from 80 .. 99
[18:34:41.685] INFO: dacScan split into 2 runs with ntrig = 5
[18:34:41.685] INFO: run 1 of 2
[18:34:55.908] INFO: Test took 14223ms.
[18:34:56.012] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:34:56.015] INFO: run 2 of 2
[18:35:10.328] INFO: Test took 14313ms.
[18:35:10.392] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:35:10.394] INFO: dacScan step from 100 .. 119
[18:35:10.394] INFO: dacScan split into 2 runs with ntrig = 5
[18:35:10.394] INFO: run 1 of 2
[18:35:26.829] INFO: Test took 16435ms.
[18:35:27.044] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:35:27.088] INFO: run 2 of 2
[18:35:43.625] INFO: Test took 16537ms.
[18:35:43.831] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:35:43.875] INFO: dacScan step from 120 .. 139
[18:35:43.875] INFO: dacScan split into 2 runs with ntrig = 5
[18:35:43.875] INFO: run 1 of 2
[18:36:02.780] INFO: Test took 18905ms.
[18:36:03.093] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:36:03.163] INFO: run 2 of 2
[18:36:22.012] INFO: Test took 18848ms.
[18:36:22.318] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:36:22.383] INFO: dacScan step from 140 .. 159
[18:36:22.383] INFO: dacScan split into 2 runs with ntrig = 5
[18:36:22.383] INFO: run 1 of 2
[18:36:41.899] INFO: Test took 19515ms.
[18:36:42.224] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:36:42.307] INFO: run 2 of 2
[18:37:01.636] INFO: Test took 19329ms.
[18:37:01.968] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:37:02.040] INFO: dacScan step from 160 .. 179
[18:37:02.040] INFO: dacScan split into 2 runs with ntrig = 5
[18:37:02.040] INFO: run 1 of 2
[18:37:21.915] INFO: Test took 19875ms.
[18:37:22.239] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:37:22.319] INFO: run 2 of 2
[18:37:41.886] INFO: Test took 19567ms.
[18:37:42.221] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:37:42.307] INFO: dacScan step from 180 .. 182
[18:37:42.307] INFO: dacScan split into 2 runs with ntrig = 5
[18:37:42.307] INFO: run 1 of 2
[18:37:48.056] INFO: Test took 5749ms.
[18:37:48.109] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:37:48.124] INFO: run 2 of 2
[18:37:53.796] INFO: Test took 5672ms.
[18:37:53.847] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:38:34.392] INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 10 dacrange: 0 .. 188 (20/5) hits flags = 16 (plus default)
[18:38:34.412] INFO: dacScan step from 0 .. 19
[18:38:34.412] INFO: dacScan split into 2 runs with ntrig = 5
[18:38:34.412] INFO: run 1 of 2
[18:38:48.548] INFO: Test took 14136ms.
[18:38:48.599] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:38:48.599] INFO: run 2 of 2
[18:39:02.812] INFO: Test took 14213ms.
[18:39:02.862] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:39:02.862] INFO: dacScan step from 20 .. 39
[18:39:02.862] INFO: dacScan split into 2 runs with ntrig = 5
[18:39:02.862] INFO: run 1 of 2
[18:39:16.991] INFO: Test took 14128ms.
[18:39:17.041] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:39:17.041] INFO: run 2 of 2
[18:39:31.280] INFO: Test took 14238ms.
[18:39:31.327] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:39:31.327] INFO: dacScan step from 40 .. 59
[18:39:31.327] INFO: dacScan split into 2 runs with ntrig = 5
[18:39:31.327] INFO: run 1 of 2
[18:39:45.539] INFO: Test took 14212ms.
[18:39:45.586] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:39:45.586] INFO: run 2 of 2
[18:39:59.703] INFO: Test took 14117ms.
[18:39:59.753] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:39:59.754] INFO: dacScan step from 60 .. 79
[18:39:59.754] INFO: dacScan split into 2 runs with ntrig = 5
[18:39:59.754] INFO: run 1 of 2
[18:40:13.913] INFO: Test took 14159ms.
[18:40:13.961] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:40:13.961] INFO: run 2 of 2
[18:40:28.072] INFO: Test took 14111ms.
[18:40:28.123] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:40:28.124] INFO: dacScan step from 80 .. 99
[18:40:28.124] INFO: dacScan split into 2 runs with ntrig = 5
[18:40:28.124] INFO: run 1 of 2
[18:40:42.375] INFO: Test took 14251ms.
[18:40:42.437] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:40:42.440] INFO: run 2 of 2
[18:40:56.697] INFO: Test took 14257ms.
[18:40:56.760] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:40:56.764] INFO: dacScan step from 100 .. 119
[18:40:56.764] INFO: dacScan split into 2 runs with ntrig = 5
[18:40:56.764] INFO: run 1 of 2
[18:41:13.161] INFO: Test took 16397ms.
[18:41:13.359] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:41:13.399] INFO: run 2 of 2
[18:41:29.825] INFO: Test took 16426ms.
[18:41:30.039] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:41:30.084] INFO: dacScan step from 120 .. 139
[18:41:30.084] INFO: dacScan split into 2 runs with ntrig = 5
[18:41:30.084] INFO: run 1 of 2
[18:41:49.058] INFO: Test took 18974ms.
[18:41:49.380] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:41:49.457] INFO: run 2 of 2
[18:42:08.496] INFO: Test took 19039ms.
[18:42:08.796] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:42:08.873] INFO: dacScan step from 140 .. 159
[18:42:08.873] INFO: dacScan split into 2 runs with ntrig = 5
[18:42:08.873] INFO: run 1 of 2
[18:42:28.344] INFO: Test took 19471ms.
[18:42:28.679] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:42:28.758] INFO: run 2 of 2
[18:42:48.352] INFO: Test took 19594ms.
[18:42:48.686] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:42:48.769] INFO: dacScan step from 160 .. 179
[18:42:48.769] INFO: dacScan split into 2 runs with ntrig = 5
[18:42:48.769] INFO: run 1 of 2
[18:43:08.394] INFO: Test took 19625ms.
[18:43:08.722] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:43:08.801] INFO: run 2 of 2
[18:43:28.411] INFO: Test took 19610ms.
[18:43:28.726] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:43:28.807] INFO: dacScan step from 180 .. 188
[18:43:28.807] INFO: dacScan split into 2 runs with ntrig = 5
[18:43:28.807] INFO: run 1 of 2
[18:43:39.689] INFO: Test took 10882ms.
[18:43:39.841] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:43:39.879] INFO: run 2 of 2
[18:43:50.935] INFO: Test took 11055ms.
[18:43:51.080] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:44:33.309] INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 10 dacrange: 0 .. 168 (20/5) hits flags = 16 (plus default)
[18:44:33.329] INFO: dacScan step from 0 .. 19
[18:44:33.329] INFO: dacScan split into 2 runs with ntrig = 5
[18:44:33.329] INFO: run 1 of 2
[18:44:47.571] INFO: Test took 14242ms.
[18:44:47.619] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:44:47.619] INFO: run 2 of 2
[18:45:01.751] INFO: Test took 14132ms.
[18:45:01.802] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:45:01.802] INFO: dacScan step from 20 .. 39
[18:45:01.802] INFO: dacScan split into 2 runs with ntrig = 5
[18:45:01.802] INFO: run 1 of 2
[18:45:15.992] INFO: Test took 14190ms.
[18:45:16.056] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:45:16.056] INFO: run 2 of 2
[18:45:30.179] INFO: Test took 14122ms.
[18:45:30.223] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:45:30.224] INFO: dacScan step from 40 .. 59
[18:45:30.224] INFO: dacScan split into 2 runs with ntrig = 5
[18:45:30.224] INFO: run 1 of 2
[18:45:44.421] INFO: Test took 14197ms.
[18:45:44.473] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:45:44.473] INFO: run 2 of 2
[18:45:58.676] INFO: Test took 14203ms.
[18:45:58.725] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:45:58.725] INFO: dacScan step from 60 .. 79
[18:45:58.725] INFO: dacScan split into 2 runs with ntrig = 5
[18:45:58.725] INFO: run 1 of 2
[18:46:12.884] INFO: Test took 14159ms.
[18:46:12.928] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:46:12.928] INFO: run 2 of 2
[18:46:27.122] INFO: Test took 14194ms.
[18:46:27.166] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:46:27.166] INFO: dacScan step from 80 .. 99
[18:46:27.166] INFO: dacScan split into 2 runs with ntrig = 5
[18:46:27.166] INFO: run 1 of 2
[18:46:41.418] INFO: Test took 14252ms.
[18:46:41.481] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:46:41.484] INFO: run 2 of 2
[18:46:55.767] INFO: Test took 14283ms.
[18:46:55.828] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:46:55.834] INFO: dacScan step from 100 .. 119
[18:46:55.834] INFO: dacScan split into 2 runs with ntrig = 5
[18:46:55.834] INFO: run 1 of 2
[18:47:12.355] INFO: Test took 16520ms.
[18:47:12.553] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:47:12.593] INFO: run 2 of 2
[18:47:29.026] INFO: Test took 16433ms.
[18:47:29.245] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:47:29.292] INFO: dacScan step from 120 .. 139
[18:47:29.292] INFO: dacScan split into 2 runs with ntrig = 5
[18:47:29.292] INFO: run 1 of 2
[18:47:48.252] INFO: Test took 18960ms.
[18:47:48.560] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:47:48.630] INFO: run 2 of 2
[18:48:07.680] INFO: Test took 19049ms.
[18:48:07.002] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:48:08.082] INFO: dacScan step from 140 .. 159
[18:48:08.082] INFO: dacScan split into 2 runs with ntrig = 5
[18:48:08.083] INFO: run 1 of 2
[18:48:27.534] INFO: Test took 19451ms.
[18:48:27.947] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:48:28.028] INFO: run 2 of 2
[18:48:47.393] INFO: Test took 19365ms.
[18:48:47.727] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:48:47.813] INFO: dacScan step from 160 .. 168
[18:48:47.813] INFO: dacScan split into 2 runs with ntrig = 5
[18:48:47.813] INFO: run 1 of 2
[18:48:58.461] INFO: Test took 10648ms.
[18:48:58.617] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:48:58.657] INFO: run 2 of 2
[18:49:09.314] INFO: Test took 10656ms.
[18:49:09.472] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:49:48.109] INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 10 dacrange: 0 .. 168 (20/5) hits flags = 16 (plus default)
[18:49:48.122] INFO: dacScan step from 0 .. 19
[18:49:48.122] INFO: dacScan split into 2 runs with ntrig = 5
[18:49:48.122] INFO: run 1 of 2
[18:50:02.188] INFO: Test took 14065ms.
[18:50:02.230] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:50:02.230] INFO: run 2 of 2
[18:50:16.307] INFO: Test took 14077ms.
[18:50:16.355] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:50:16.355] INFO: dacScan step from 20 .. 39
[18:50:16.355] INFO: dacScan split into 2 runs with ntrig = 5
[18:50:16.355] INFO: run 1 of 2
[18:50:30.493] INFO: Test took 14138ms.
[18:50:30.543] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:50:30.543] INFO: run 2 of 2
[18:50:44.789] INFO: Test took 14246ms.
[18:50:44.836] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:50:44.836] INFO: dacScan step from 40 .. 59
[18:50:44.836] INFO: dacScan split into 2 runs with ntrig = 5
[18:50:44.836] INFO: run 1 of 2
[18:50:59.135] INFO: Test took 14298ms.
[18:50:59.186] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:50:59.186] INFO: run 2 of 2
[18:51:13.302] INFO: Test took 14116ms.
[18:51:13.348] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:51:13.349] INFO: dacScan step from 60 .. 79
[18:51:13.349] INFO: dacScan split into 2 runs with ntrig = 5
[18:51:13.349] INFO: run 1 of 2
[18:51:27.480] INFO: Test took 14131ms.
[18:51:27.529] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:51:27.529] INFO: run 2 of 2
[18:51:41.780] INFO: Test took 14251ms.
[18:51:41.827] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:51:41.827] INFO: dacScan step from 80 .. 99
[18:51:41.827] INFO: dacScan split into 2 runs with ntrig = 5
[18:51:41.827] INFO: run 1 of 2
[18:51:56.077] INFO: Test took 14250ms.
[18:51:56.138] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:51:56.141] INFO: run 2 of 2
[18:52:10.351] INFO: Test took 14210ms.
[18:52:10.404] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:52:10.407] INFO: dacScan step from 100 .. 119
[18:52:10.407] INFO: dacScan split into 2 runs with ntrig = 5
[18:52:10.407] INFO: run 1 of 2
[18:52:26.832] INFO: Test took 16425ms.
[18:52:27.038] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:52:27.101] INFO: run 2 of 2
[18:52:43.541] INFO: Test took 16440ms.
[18:52:43.752] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:52:43.795] INFO: dacScan step from 120 .. 139
[18:52:43.796] INFO: dacScan split into 2 runs with ntrig = 5
[18:52:43.796] INFO: run 1 of 2
[18:53:02.570] INFO: Test took 18774ms.
[18:53:02.908] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:53:02.997] INFO: run 2 of 2
[18:53:21.702] INFO: Test took 18705ms.
[18:53:22.014] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:53:22.089] INFO: dacScan step from 140 .. 159
[18:53:22.089] INFO: dacScan split into 2 runs with ntrig = 5
[18:53:22.089] INFO: run 1 of 2
[18:53:41.553] INFO: Test took 19464ms.
[18:53:41.893] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:53:41.972] INFO: run 2 of 2
[18:54:01.365] INFO: Test took 19393ms.
[18:54:01.730] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:54:01.814] INFO: dacScan step from 160 .. 168
[18:54:01.814] INFO: dacScan split into 2 runs with ntrig = 5
[18:54:01.814] INFO: run 1 of 2
[18:54:12.488] INFO: Test took 10674ms.
[18:54:12.634] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:54:12.673] INFO: run 2 of 2
[18:54:23.333] INFO: Test took 10661ms.
[18:54:23.484] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:55:01.360] INFO: PixTestTrim::trimBitTest() done
[18:55:01.361] INFO: PixTestTrim::doTest() done, duration: 3311 seconds
[18:55:02.422] INFO: ######################################################################
[18:55:02.422] INFO: PixTestPhOptimization::doTest() Ntrig = 10
[18:55:02.422] INFO: ######################################################################
[18:55:06.144] INFO: Test took 3721ms.
[18:55:06.189] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:55:10.112] INFO: Test took 3717ms.
[18:55:10.252] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:55:13.994] INFO: Test took 3724ms.
[18:55:14.146] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:55:17.853] INFO: Test took 3693ms.
[18:55:17.998] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:55:21.699] INFO: Test took 3686ms.
[18:55:21.853] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:55:25.552] INFO: Test took 3685ms.
[18:55:25.704] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:55:29.419] INFO: Test took 3700ms.
[18:55:29.574] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:55:33.302] INFO: Test took 3711ms.
[18:55:33.447] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:55:37.108] INFO: Test took 3647ms.
[18:55:37.259] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:55:40.985] INFO: Test took 3712ms.
[18:55:41.124] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:55:44.844] INFO: Test took 3706ms.
[18:55:44.996] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:55:48.704] INFO: Test took 3694ms.
[18:55:48.854] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:55:52.542] INFO: Test took 3673ms.
[18:55:52.690] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:55:56.379] INFO: Test took 3674ms.
[18:55:56.506] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:56:00.214] INFO: Test took 3694ms.
[18:56:00.353] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:56:03.003] INFO: Test took 3633ms.
[18:56:04.144] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:56:07.837] INFO: Test took 3678ms.
[18:56:07.985] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:56:11.689] INFO: Test took 3687ms.
[18:56:11.833] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:56:15.570] INFO: Test took 3722ms.
[18:56:15.720] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:56:19.424] INFO: Test took 3688ms.
[18:56:19.585] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:56:23.355] INFO: Test took 3753ms.
[18:56:23.510] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:56:27.260] INFO: Test took 3734ms.
[18:56:27.400] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:56:31.122] INFO: Test took 3706ms.
[18:56:31.310] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:56:34.002] INFO: Test took 3675ms.
[18:56:35.155] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:56:38.869] INFO: Test took 3698ms.
[18:56:39.017] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:56:42.784] INFO: Test took 3752ms.
[18:56:42.917] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:56:46.614] INFO: Test took 3683ms.
[18:56:46.759] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:56:50.440] INFO: Test took 3666ms.
[18:56:50.583] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:56:54.332] INFO: Test took 3733ms.
[18:56:54.490] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:56:58.229] INFO: Test took 3724ms.
[18:56:58.368] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:57:02.060] INFO: Test took 3675ms.
[18:57:02.215] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:57:05.945] INFO: Test took 3715ms.
[18:57:06.100] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:57:09.809] INFO: Test took 3693ms.
[18:57:09.945] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:57:13.635] INFO: Test took 3673ms.
[18:57:13.785] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:57:17.537] INFO: Test took 3737ms.
[18:57:17.683] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:57:21.482] INFO: Test took 3784ms.
[18:57:21.674] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:57:25.511] INFO: Test took 3819ms.
[18:57:25.663] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:57:29.416] INFO: Test took 3736ms.
[18:57:29.559] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:57:33.281] INFO: Test took 3706ms.
[18:57:33.451] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:57:37.176] INFO: Test took 3708ms.
[18:57:37.328] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:57:41.129] INFO: Test took 3786ms.
[18:57:41.279] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:57:44.987] INFO: Test took 3693ms.
[18:57:45.124] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:57:48.843] INFO: Test took 3703ms.
[18:57:48.992] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:57:52.722] INFO: Test took 3716ms.
[18:57:52.868] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:57:56.603] INFO: Test took 3718ms.
[18:57:56.754] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:58:00.493] INFO: Test took 3724ms.
[18:58:00.649] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:58:04.427] INFO: Test took 3762ms.
[18:58:04.579] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:58:08.334] INFO: Test took 3739ms.
[18:58:08.466] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:58:12.194] INFO: Test took 3714ms.
[18:58:12.345] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:58:16.045] INFO: Test took 3684ms.
[18:58:16.201] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:58:19.921] INFO: Test took 3703ms.
[18:58:20.076] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:58:23.834] INFO: Test took 3741ms.
[18:58:23.991] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:58:27.763] INFO: Test took 3757ms.
[18:58:27.946] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:58:31.719] INFO: Test took 3756ms.
[18:58:31.853] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:58:31.865] INFO: The DUT currently contains the following objects:
[18:58:31.865] INFO: 2 TBM Cores tbm08c (2 ON)
[18:58:31.865] INFO: TBM Core alpha (0): 7 registers set
[18:58:31.865] INFO: TBM Core beta (1): 7 registers set
[18:58:31.865] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[18:58:31.865] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:31.865] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:31.865] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:31.865] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:31.865] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:31.865] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:31.865] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:31.865] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:31.865] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:31.865] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:31.866] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:31.866] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:31.866] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:31.866] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:31.866] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:31.866] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:32.968] INFO: Test took 1102ms.
[18:58:32.971] INFO: The DUT currently contains the following objects:
[18:58:32.971] INFO: 2 TBM Cores tbm08c (2 ON)
[18:58:32.971] INFO: TBM Core alpha (0): 7 registers set
[18:58:32.971] INFO: TBM Core beta (1): 7 registers set
[18:58:32.971] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[18:58:32.971] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:32.971] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:32.971] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:32.971] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:32.971] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:32.971] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:32.971] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:32.971] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:32.971] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:32.971] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:32.971] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:32.971] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:32.971] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:32.971] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:32.971] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:32.971] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:34.068] INFO: Test took 1097ms.
[18:58:34.070] INFO: The DUT currently contains the following objects:
[18:58:34.070] INFO: 2 TBM Cores tbm08c (2 ON)
[18:58:34.070] INFO: TBM Core alpha (0): 7 registers set
[18:58:34.070] INFO: TBM Core beta (1): 7 registers set
[18:58:34.070] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[18:58:34.070] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:34.070] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:34.070] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:34.070] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:34.070] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:34.070] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:34.070] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:34.070] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:34.070] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:34.070] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:34.070] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:34.070] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:34.070] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:34.070] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:34.070] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:34.070] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:35.171] INFO: Test took 1101ms.
[18:58:35.172] INFO: The DUT currently contains the following objects:
[18:58:35.172] INFO: 2 TBM Cores tbm08c (2 ON)
[18:58:35.172] INFO: TBM Core alpha (0): 7 registers set
[18:58:35.172] INFO: TBM Core beta (1): 7 registers set
[18:58:35.172] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[18:58:35.172] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:35.172] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:35.172] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:35.172] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:35.172] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:35.172] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:35.172] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:35.172] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:35.172] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:35.172] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:35.172] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:35.172] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:35.172] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:35.173] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:35.173] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:35.173] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:36.276] INFO: Test took 1103ms.
[18:58:36.279] INFO: The DUT currently contains the following objects:
[18:58:36.279] INFO: 2 TBM Cores tbm08c (2 ON)
[18:58:36.279] INFO: TBM Core alpha (0): 7 registers set
[18:58:36.279] INFO: TBM Core beta (1): 7 registers set
[18:58:36.279] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[18:58:36.279] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:36.279] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:36.279] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:36.279] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:36.279] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:36.279] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:36.279] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:36.279] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:36.279] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:36.279] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:36.279] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:36.279] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:36.279] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:36.279] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:36.279] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:36.279] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:37.379] INFO: Test took 1100ms.
[18:58:37.381] INFO: The DUT currently contains the following objects:
[18:58:37.381] INFO: 2 TBM Cores tbm08c (2 ON)
[18:58:37.381] INFO: TBM Core alpha (0): 7 registers set
[18:58:37.381] INFO: TBM Core beta (1): 7 registers set
[18:58:37.381] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[18:58:37.381] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:37.381] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:37.381] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:37.381] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:37.381] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:37.381] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:37.381] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:37.381] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:37.382] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:37.382] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:37.382] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:37.382] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:37.382] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:37.382] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:37.382] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:37.382] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:38.480] INFO: Test took 1098ms.
[18:58:38.481] INFO: The DUT currently contains the following objects:
[18:58:38.481] INFO: 2 TBM Cores tbm08c (2 ON)
[18:58:38.481] INFO: TBM Core alpha (0): 7 registers set
[18:58:38.481] INFO: TBM Core beta (1): 7 registers set
[18:58:38.481] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[18:58:38.481] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:38.481] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:38.481] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:38.481] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:38.481] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:38.481] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:38.481] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:38.481] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:38.481] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:38.481] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:38.481] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:38.481] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:38.481] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:38.481] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:38.481] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:38.481] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:39.583] INFO: Test took 1102ms.
[18:58:39.585] INFO: The DUT currently contains the following objects:
[18:58:39.585] INFO: 2 TBM Cores tbm08c (2 ON)
[18:58:39.585] INFO: TBM Core alpha (0): 7 registers set
[18:58:39.585] INFO: TBM Core beta (1): 7 registers set
[18:58:39.585] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[18:58:39.585] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:39.585] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:39.585] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:39.585] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:39.585] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:39.585] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:39.585] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:39.585] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:39.585] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:39.585] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:39.585] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:39.585] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:39.585] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:39.585] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:39.585] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:39.585] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:40.693] INFO: Test took 1108ms.
[18:58:40.695] INFO: The DUT currently contains the following objects:
[18:58:40.695] INFO: 2 TBM Cores tbm08c (2 ON)
[18:58:40.695] INFO: TBM Core alpha (0): 7 registers set
[18:58:40.695] INFO: TBM Core beta (1): 7 registers set
[18:58:40.695] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[18:58:40.695] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:40.695] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:40.696] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:40.696] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:40.696] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:40.696] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:40.696] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:40.696] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:40.696] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:40.696] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:40.696] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:40.696] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:40.696] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:40.696] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:40.696] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:40.696] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:41.795] INFO: Test took 1099ms.
[18:58:41.798] INFO: The DUT currently contains the following objects:
[18:58:41.798] INFO: 2 TBM Cores tbm08c (2 ON)
[18:58:41.798] INFO: TBM Core alpha (0): 7 registers set
[18:58:41.798] INFO: TBM Core beta (1): 7 registers set
[18:58:41.798] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[18:58:41.798] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:41.798] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:41.798] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:41.798] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:41.798] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:41.798] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:41.798] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:41.798] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:41.798] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:41.798] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:41.798] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:41.798] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:41.798] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:41.798] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:41.798] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:41.798] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:42.897] INFO: Test took 1099ms.
[18:58:42.898] INFO: The DUT currently contains the following objects:
[18:58:42.898] INFO: 2 TBM Cores tbm08c (2 ON)
[18:58:42.899] INFO: TBM Core alpha (0): 7 registers set
[18:58:42.899] INFO: TBM Core beta (1): 7 registers set
[18:58:42.899] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[18:58:42.899] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:42.899] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:42.899] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:42.899] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:42.899] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:42.899] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:42.899] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:42.899] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:42.899] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:42.899] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:42.899] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:42.899] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:42.899] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:42.899] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:42.899] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:42.899] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:43.997] INFO: Test took 1098ms.
[18:58:43.998] INFO: The DUT currently contains the following objects:
[18:58:43.998] INFO: 2 TBM Cores tbm08c (2 ON)
[18:58:43.998] INFO: TBM Core alpha (0): 7 registers set
[18:58:43.998] INFO: TBM Core beta (1): 7 registers set
[18:58:43.998] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[18:58:43.998] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:43.998] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:43.998] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:43.998] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:43.998] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:43.998] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:43.998] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:43.998] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:43.998] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:43.998] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:43.998] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:43.998] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:43.998] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:43.998] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:43.998] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:43.998] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:45.100] INFO: Test took 1102ms.
[18:58:45.101] INFO: The DUT currently contains the following objects:
[18:58:45.101] INFO: 2 TBM Cores tbm08c (2 ON)
[18:58:45.101] INFO: TBM Core alpha (0): 7 registers set
[18:58:45.101] INFO: TBM Core beta (1): 7 registers set
[18:58:45.101] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[18:58:45.101] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:45.101] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:45.101] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:45.101] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:45.101] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:45.101] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:45.101] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:45.101] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:45.102] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:45.102] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:45.102] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:45.102] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:45.102] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:45.102] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:45.102] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:45.102] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:46.204] INFO: Test took 1102ms.
[18:58:46.206] INFO: The DUT currently contains the following objects:
[18:58:46.206] INFO: 2 TBM Cores tbm08c (2 ON)
[18:58:46.206] INFO: TBM Core alpha (0): 7 registers set
[18:58:46.206] INFO: TBM Core beta (1): 7 registers set
[18:58:46.206] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[18:58:46.206] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:46.206] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:46.206] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:46.206] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:46.207] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:46.207] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:46.207] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:46.207] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:46.207] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:46.207] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:46.207] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:46.207] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:46.207] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:46.207] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:46.207] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:46.207] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:47.306] INFO: Test took 1099ms.
[18:58:47.308] INFO: The DUT currently contains the following objects:
[18:58:47.308] INFO: 2 TBM Cores tbm08c (2 ON)
[18:58:47.308] INFO: TBM Core alpha (0): 7 registers set
[18:58:47.308] INFO: TBM Core beta (1): 7 registers set
[18:58:47.308] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[18:58:47.308] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:47.308] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:47.308] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:47.308] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:47.308] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:47.308] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:47.308] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:47.308] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:47.308] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:47.308] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:47.308] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:47.308] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:47.308] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:47.308] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:47.308] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:47.308] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:48.408] INFO: Test took 1100ms.
[18:58:48.409] INFO: The DUT currently contains the following objects:
[18:58:48.409] INFO: 2 TBM Cores tbm08c (2 ON)
[18:58:48.409] INFO: TBM Core alpha (0): 7 registers set
[18:58:48.409] INFO: TBM Core beta (1): 7 registers set
[18:58:48.409] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[18:58:48.409] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:48.409] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:48.409] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:48.409] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:48.409] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:48.409] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:48.409] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:48.409] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:48.409] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:48.409] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:48.409] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:48.409] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:48.409] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:48.409] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:48.409] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:48.409] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[18:58:49.512] INFO: Test took 1103ms.
[18:58:49.520] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:02:00.779] INFO: Test took 191259ms.
[19:02:04.187] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:05:16.520] INFO: Test took 192333ms.
[19:05:20.140] INFO: safety margin for low PH: adding 0, margin is now 20
[19:05:20.150] INFO: safety margin for low PH: adding 0, margin is now 20
[19:05:20.160] INFO: safety margin for low PH: adding 0, margin is now 20
[19:05:20.170] INFO: safety margin for low PH: adding 0, margin is now 20
[19:05:20.181] INFO: safety margin for low PH: adding 0, margin is now 20
[19:05:20.190] INFO: safety margin for low PH: adding 0, margin is now 20
[19:05:20.200] INFO: safety margin for low PH: adding 0, margin is now 20
[19:05:20.210] INFO: safety margin for low PH: adding 0, margin is now 20
[19:05:20.221] INFO: safety margin for low PH: adding 0, margin is now 20
[19:05:20.231] INFO: safety margin for low PH: adding 0, margin is now 20
[19:05:20.241] INFO: safety margin for low PH: adding 0, margin is now 20
[19:05:20.251] INFO: safety margin for low PH: adding 0, margin is now 20
[19:05:20.262] INFO: safety margin for low PH: adding 1, margin is now 21
[19:05:20.272] INFO: safety margin for low PH: adding 2, margin is now 22
[19:05:20.282] INFO: safety margin for low PH: adding 3, margin is now 23
[19:05:20.293] INFO: safety margin for low PH: adding 0, margin is now 20
[19:05:20.302] INFO: safety margin for low PH: adding 0, margin is now 20
[19:05:20.312] INFO: safety margin for low PH: adding 0, margin is now 20
[19:05:20.322] INFO: safety margin for low PH: adding 0, margin is now 20
[19:05:20.398] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C0.dat
[19:05:20.398] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C1.dat
[19:05:20.398] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C2.dat
[19:05:20.398] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C3.dat
[19:05:20.398] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C4.dat
[19:05:20.399] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C5.dat
[19:05:20.399] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C6.dat
[19:05:20.399] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C7.dat
[19:05:20.399] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C8.dat
[19:05:20.399] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C9.dat
[19:05:20.399] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C10.dat
[19:05:20.399] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C11.dat
[19:05:20.399] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C12.dat
[19:05:20.400] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C13.dat
[19:05:20.400] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C14.dat
[19:05:20.400] INFO: write dac parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/dacParameters35_C15.dat
[19:05:24.110] INFO: Test took 3705ms.
[19:05:28.143] INFO: Test took 3666ms.
[19:05:32.226] INFO: Test took 3711ms.
[19:05:32.614] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:05:33.527] INFO: Test took 914ms.
[19:05:33.531] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:05:34.630] INFO: Test took 1099ms.
[19:05:34.635] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:05:35.736] INFO: Test took 1101ms.
[19:05:35.743] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:05:36.840] INFO: Test took 1097ms.
[19:05:36.846] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:05:37.948] INFO: Test took 1102ms.
[19:05:37.954] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:05:39.054] INFO: Test took 1100ms.
[19:05:39.061] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:05:40.162] INFO: Test took 1101ms.
[19:05:40.168] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:05:41.269] INFO: Test took 1101ms.
[19:05:41.272] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:05:42.368] INFO: Test took 1096ms.
[19:05:42.372] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:05:43.470] INFO: Test took 1098ms.
[19:05:43.475] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:05:44.575] INFO: Test took 1100ms.
[19:05:44.581] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:05:45.678] INFO: Test took 1097ms.
[19:05:45.684] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:05:46.784] INFO: Test took 1101ms.
[19:05:46.788] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:05:47.889] INFO: Test took 1101ms.
[19:05:47.894] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:05:48.995] INFO: Test took 1101ms.
[19:05:48.002] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:05:50.101] INFO: Test took 1100ms.
[19:05:50.107] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:05:51.207] INFO: Test took 1100ms.
[19:05:51.211] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:05:52.313] INFO: Test took 1102ms.
[19:05:52.320] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:05:53.418] INFO: Test took 1099ms.
[19:05:53.425] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:05:54.525] INFO: Test took 1101ms.
[19:05:54.530] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:05:55.632] INFO: Test took 1102ms.
[19:05:55.638] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:05:56.737] INFO: Test took 1099ms.
[19:05:56.740] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:05:57.843] INFO: Test took 1103ms.
[19:05:57.849] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:05:58.948] INFO: Test took 1099ms.
[19:05:58.954] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:06:00.058] INFO: Test took 1104ms.
[19:06:00.065] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:06:01.162] INFO: Test took 1098ms.
[19:06:01.166] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:06:02.268] INFO: Test took 1102ms.
[19:06:02.275] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:06:03.376] INFO: Test took 1102ms.
[19:06:03.384] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:06:04.483] INFO: Test took 1100ms.
[19:06:04.490] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:06:05.587] INFO: Test took 1098ms.
[19:06:05.594] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:06:06.693] INFO: Test took 1101ms.
[19:06:06.700] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:06:07.799] INFO: Test took 1100ms.
[19:06:08.418] INFO: PixTestPhOptimization::doTest() done, duration: 665 seconds
[19:06:08.418] INFO: PH scale (per ROC): 78 67 73 77 75 78 70 74 79 80 77 80 73 80 73 77
[19:06:08.418] INFO: PH offset (per ROC): 159 161 166 164 171 165 165 150 162 150 174 153 172 151 164 169
[19:06:08.645] INFO: ######################################################################
[19:06:08.645] INFO: PixTestGainPedestal::fullTest() ntrig = 10
[19:06:08.645] INFO: ######################################################################
[19:06:08.663] INFO: scanning low vcal = 10
[19:06:12.717] INFO: Test took 4054ms.
[19:06:12.724] INFO: scanning low vcal = 20
[19:06:16.766] INFO: Test took 4042ms.
[19:06:16.775] INFO: scanning low vcal = 30
[19:06:20.850] INFO: Test took 4075ms.
[19:06:20.867] INFO: scanning low vcal = 40
[19:06:25.397] INFO: Test took 4529ms.
[19:06:25.558] INFO: scanning low vcal = 50
[19:06:30.213] INFO: Test took 4655ms.
[19:06:30.356] INFO: scanning low vcal = 60
[19:06:35.013] INFO: Test took 4657ms.
[19:06:35.141] INFO: scanning low vcal = 70
[19:06:39.786] INFO: Test took 4645ms.
[19:06:39.922] INFO: scanning low vcal = 80
[19:06:44.613] INFO: Test took 4691ms.
[19:06:44.758] INFO: scanning low vcal = 90
[19:06:49.399] INFO: Test took 4641ms.
[19:06:49.530] INFO: scanning low vcal = 100
[19:06:54.198] INFO: Test took 4668ms.
[19:06:54.337] INFO: scanning low vcal = 110
[19:06:59.045] INFO: Test took 4708ms.
[19:06:59.171] INFO: scanning low vcal = 120
[19:07:03.785] INFO: Test took 4614ms.
[19:07:03.926] INFO: scanning low vcal = 130
[19:07:08.618] INFO: Test took 4692ms.
[19:07:08.746] INFO: scanning low vcal = 140
[19:07:13.435] INFO: Test took 4689ms.
[19:07:13.572] INFO: scanning low vcal = 150
[19:07:18.245] INFO: Test took 4673ms.
[19:07:18.379] INFO: scanning low vcal = 160
[19:07:23.057] INFO: Test took 4678ms.
[19:07:23.181] INFO: scanning low vcal = 170
[19:07:27.833] INFO: Test took 4652ms.
[19:07:27.969] INFO: scanning low vcal = 180
[19:07:32.634] INFO: Test took 4666ms.
[19:07:32.763] INFO: scanning low vcal = 190
[19:07:37.561] INFO: Test took 4798ms.
[19:07:37.686] INFO: scanning low vcal = 200
[19:07:42.308] INFO: Test took 4622ms.
[19:07:42.451] INFO: scanning low vcal = 210
[19:07:47.155] INFO: Test took 4704ms.
[19:07:47.286] INFO: scanning low vcal = 220
[19:07:51.978] INFO: Test took 4692ms.
[19:07:52.104] INFO: scanning low vcal = 230
[19:07:56.731] INFO: Test took 4627ms.
[19:07:56.864] INFO: scanning low vcal = 240
[19:08:01.554] INFO: Test took 4690ms.
[19:08:01.682] INFO: scanning low vcal = 250
[19:08:06.323] INFO: Test took 4641ms.
[19:08:06.462] INFO: scanning high vcal = 30 (= 210 in low range)
[19:08:11.135] INFO: Test took 4673ms.
[19:08:11.273] INFO: scanning high vcal = 50 (= 350 in low range)
[19:08:15.978] INFO: Test took 4705ms.
[19:08:16.108] INFO: scanning high vcal = 70 (= 490 in low range)
[19:08:20.767] INFO: Test took 4659ms.
[19:08:20.898] INFO: scanning high vcal = 90 (= 630 in low range)
[19:08:25.553] INFO: Test took 4654ms.
[19:08:25.672] INFO: scanning high vcal = 200 (= 1400 in low range)
[19:08:30.269] INFO: Test took 4597ms.
[19:08:31.142] INFO: PixTestGainPedestal::measure() done
[19:09:24.638] INFO: PixTestGainPedestal::fit() done
[19:09:24.638] INFO: non-linearity mean: 0.947 0.951 0.963 0.953 0.956 0.953 0.952 0.954 0.956 0.950 0.956 0.961 0.956 0.960 0.954 0.958
[19:09:24.638] INFO: non-linearity RMS: 0.008 0.007 0.007 0.006 0.006 0.005 0.007 0.007 0.007 0.005 0.006 0.005 0.006 0.005 0.006 0.006
[19:09:24.638] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/phCalibrationFitErr35_C0.dat
[19:09:24.664] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/phCalibrationFitErr35_C1.dat
[19:09:24.691] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/phCalibrationFitErr35_C2.dat
[19:09:24.717] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/phCalibrationFitErr35_C3.dat
[19:09:24.743] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/phCalibrationFitErr35_C4.dat
[19:09:24.769] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/phCalibrationFitErr35_C5.dat
[19:09:24.795] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/phCalibrationFitErr35_C6.dat
[19:09:24.822] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/phCalibrationFitErr35_C7.dat
[19:09:24.847] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/phCalibrationFitErr35_C8.dat
[19:09:24.874] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/phCalibrationFitErr35_C9.dat
[19:09:24.900] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/phCalibrationFitErr35_C10.dat
[19:09:24.926] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/phCalibrationFitErr35_C11.dat
[19:09:24.952] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/phCalibrationFitErr35_C12.dat
[19:09:24.978] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/phCalibrationFitErr35_C13.dat
[19:09:25.004] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/phCalibrationFitErr35_C14.dat
[19:09:25.030] INFO: write gain/ped parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/phCalibrationFitErr35_C15.dat
[19:09:25.056] INFO: PixTestGainPedestal::doTest() done, duration: 196 seconds
[19:09:25.065] INFO: readReadbackCal: /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C0.dat .. /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C15.dat
[19:09:25.067] INFO: PixTestReadback::doTest() start.
[19:09:25.068] INFO: PixTestReadback::RES sent once
[19:09:41.664] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C0.dat
[19:09:41.664] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C1.dat
[19:09:41.664] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C2.dat
[19:09:41.665] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C3.dat
[19:09:41.665] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C4.dat
[19:09:41.665] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C5.dat
[19:09:41.665] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C6.dat
[19:09:41.665] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C7.dat
[19:09:41.665] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C8.dat
[19:09:41.665] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C9.dat
[19:09:41.665] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C10.dat
[19:09:41.665] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C11.dat
[19:09:41.665] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C12.dat
[19:09:41.665] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C13.dat
[19:09:41.666] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C14.dat
[19:09:41.666] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C15.dat
[19:09:41.713] INFO: PixTestPattern:: pg_setup set to default.
[19:09:41.713] INFO: PixTestReadback::RES sent once
[19:09:58.224] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C0.dat
[19:09:58.224] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C1.dat
[19:09:58.224] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C2.dat
[19:09:58.225] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C3.dat
[19:09:58.225] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C4.dat
[19:09:58.225] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C5.dat
[19:09:58.225] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C6.dat
[19:09:58.225] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C7.dat
[19:09:58.225] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C8.dat
[19:09:58.225] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C9.dat
[19:09:58.225] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C10.dat
[19:09:58.225] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C11.dat
[19:09:58.225] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C12.dat
[19:09:58.225] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C13.dat
[19:09:58.226] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C14.dat
[19:09:58.226] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C15.dat
[19:09:58.276] INFO: PixTestPattern:: pg_setup set to default.
[19:09:58.277] INFO: PixTestReadback::RES sent once
[19:10:11.036] INFO: PixTestPattern:: pg_setup set to default.
[19:10:11.036] INFO: Vbg will be calibrated using Vd calibration
[19:10:11.037] INFO: /*/*/*/*::: ROC 0: uncalibrated Vbg = 153.9calibrated Vbg = 1.20727 :::*/*/*/*/
[19:10:11.037] INFO: /*/*/*/*::: ROC 1: uncalibrated Vbg = 157.5calibrated Vbg = 1.21658 :::*/*/*/*/
[19:10:11.037] INFO: /*/*/*/*::: ROC 2: uncalibrated Vbg = 147.2calibrated Vbg = 1.21326 :::*/*/*/*/
[19:10:11.037] INFO: /*/*/*/*::: ROC 3: uncalibrated Vbg = 152.5calibrated Vbg = 1.21799 :::*/*/*/*/
[19:10:11.037] INFO: /*/*/*/*::: ROC 4: uncalibrated Vbg = 152.2calibrated Vbg = 1.21386 :::*/*/*/*/
[19:10:11.037] INFO: /*/*/*/*::: ROC 5: uncalibrated Vbg = 161.4calibrated Vbg = 1.217 :::*/*/*/*/
[19:10:11.037] INFO: /*/*/*/*::: ROC 6: uncalibrated Vbg = 151.1calibrated Vbg = 1.21972 :::*/*/*/*/
[19:10:11.037] INFO: /*/*/*/*::: ROC 7: uncalibrated Vbg = 159.6calibrated Vbg = 1.21724 :::*/*/*/*/
[19:10:11.037] INFO: /*/*/*/*::: ROC 8: uncalibrated Vbg = 160.4calibrated Vbg = 1.22298 :::*/*/*/*/
[19:10:11.037] INFO: /*/*/*/*::: ROC 9: uncalibrated Vbg = 142.6calibrated Vbg = 1.22795 :::*/*/*/*/
[19:10:11.037] INFO: /*/*/*/*::: ROC 10: uncalibrated Vbg = 148.5calibrated Vbg = 1.22436 :::*/*/*/*/
[19:10:11.037] INFO: /*/*/*/*::: ROC 11: uncalibrated Vbg = 156.6calibrated Vbg = 1.22607 :::*/*/*/*/
[19:10:11.037] INFO: /*/*/*/*::: ROC 12: uncalibrated Vbg = 160.3calibrated Vbg = 1.21663 :::*/*/*/*/
[19:10:11.037] INFO: /*/*/*/*::: ROC 13: uncalibrated Vbg = 158.9calibrated Vbg = 1.20494 :::*/*/*/*/
[19:10:11.037] INFO: /*/*/*/*::: ROC 14: uncalibrated Vbg = 153.2calibrated Vbg = 1.20316 :::*/*/*/*/
[19:10:11.037] INFO: /*/*/*/*::: ROC 15: uncalibrated Vbg = 148.2calibrated Vbg = 1.21159 :::*/*/*/*/
[19:10:11.040] INFO: PixTestReadback::RES sent once
[19:14:06.343] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C0.dat
[19:14:06.343] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C1.dat
[19:14:06.343] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C2.dat
[19:14:06.343] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C3.dat
[19:14:06.343] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C4.dat
[19:14:06.343] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C5.dat
[19:14:06.343] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C6.dat
[19:14:06.343] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C7.dat
[19:14:06.344] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C8.dat
[19:14:06.344] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C9.dat
[19:14:06.344] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C10.dat
[19:14:06.344] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C11.dat
[19:14:06.344] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C12.dat
[19:14:06.344] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C13.dat
[19:14:06.344] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C14.dat
[19:14:06.344] INFO: write readback calibration parameters into /home/l_tester/ColdBox/ModuleTests/M4562_FullQualification_2015-08-04_11h20m_1438683615/002_Fulltest_m20/readbackCal_C15.dat
[19:14:06.394] INFO: PixTestPattern:: pg_setup set to default.
[19:14:06.398] INFO: PixTestReadback::doTest() done
[19:14:06.418] INFO: enter test to run
[19:14:06.418] INFO: test: q no parameter change
[19:14:06.702] QUIET: Connection to board 175 closed.
[19:14:06.705] INFO: pXar: this is the end, my friend