[09:06:32.421] <TB2> INFO: *** Welcome to pxar ***
[09:06:32.421] <TB2> INFO: *** Today: 2015/10/07
[09:06:32.457] <TB2> INFO: *** Version: 9da6
[09:06:32.457] <TB2> INFO: readRocDacs: /home/mameinha/data/R418_Fulltest_m20_2015-10-07_11h06m_1444208776//000_FulltestROC_m20//dacParameters_C0.dat .. /home/mameinha/data/R418_Fulltest_m20_2015-10-07_11h06m_1444208776//000_FulltestROC_m20//dacParameters_C0.dat
[09:06:32.458] <TB2> INFO: readTbmDacs: /home/mameinha/data/R418_Fulltest_m20_2015-10-07_11h06m_1444208776//000_FulltestROC_m20//tbmParameters_C0a.dat .. /home/mameinha/data/R418_Fulltest_m20_2015-10-07_11h06m_1444208776//000_FulltestROC_m20//tbmParameters_C4294967295b.dat
[09:06:32.458] <TB2> INFO: readMaskFile: /home/mameinha/data/R418_Fulltest_m20_2015-10-07_11h06m_1444208776//000_FulltestROC_m20//defaultMaskFile.dat
[09:06:32.459] <TB2> INFO: readTrimFile: /home/mameinha/data/R418_Fulltest_m20_2015-10-07_11h06m_1444208776//000_FulltestROC_m20//trimParameters_C0.dat .. /home/mameinha/data/R418_Fulltest_m20_2015-10-07_11h06m_1444208776//000_FulltestROC_m20//trimParameters_C0.dat
[09:06:32.469] <TB2> INFO: clk: 2
[09:06:32.469] <TB2> INFO: ctr: 2
[09:06:32.469] <TB2> INFO: sda: 17
[09:06:32.469] <TB2> INFO: tin: 7
[09:06:32.469] <TB2> INFO: level: 15
[09:06:32.469] <TB2> INFO: deser160phase: 4
[09:06:32.469] <TB2> QUIET: Instanciating API for pxar v2.6.0+20~g1a7f656
[09:06:32.469] <TB2> INFO: Log level: INFO
[09:06:32.474] <TB2> INFO: Found DTB DTB_WWXJGB
[09:06:32.483] <TB2> QUIET: Connection to board DTB_WWXJGB opened.
[09:06:32.486] <TB2> INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 137
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WWXJGB
MAC address: 40D855118089
Hostname: pixelDTB137
Comment:
------------------------------------------------------
[09:06:32.489] <TB2> INFO: RPC call hashes of host and DTB match: 398089610
[09:06:33.653] <TB2> INFO: DUT info:
[09:06:33.653] <TB2> INFO: The DUT currently contains the following objects:
[09:06:33.653] <TB2> INFO: 0 TBM Cores (0 ON)
[09:06:33.653] <TB2> INFO: 1 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[09:06:33.653] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[09:06:34.055] <TB2> INFO: enter 'restricted' command line mode
[09:06:34.055] <TB2> INFO: enter test to run
[09:06:34.055] <TB2> INFO: test: Setup no parameter change
[09:06:34.055] <TB2> INFO: running: setup
[09:06:34.060] <TB2> INFO: PixTestSetup::doTest() ntrig = 10

[09:06:34.060] <TB2> INFO: PixTestSetup:: pg set to RES|TOK
[09:06:34.060] <TB2> INFO: 0 1 2 3 4 5 6 7
[09:06:37.103] <TB2> INFO: 0: 000 000 084 07c 7f0 f00 000 000
[09:06:40.117] <TB2> INFO: 1: 000 008 084 87c <7f8>[*] f80 <7f8>[1] 000
[09:06:43.132] <TB2> INFO: 2: 000 008 084 87c <7f8>[*] f80 800 000
[09:06:46.147] <TB2> INFO: 3: 000 000 004 07c <7f8>[*] f80 800 000
[09:06:49.162] <TB2> INFO: 4: 000 004 004 47c <7f8>[*] f80 800 000
[09:06:52.177] <TB2> INFO: 5: 000 004 040 43c 3fc fc0 c00 000
[09:06:55.193] <TB2> INFO: 6: 000 004 040 43c 3fc fc0 c00 000
[09:06:58.208] <TB2> INFO: 7: c00 004 040 43c 3fc fc0 c00 000
[09:07:01.224] <TB2> INFO: 8: 000 000 000 03c 3fc fc0 c00 000
[09:07:04.240] <TB2> INFO: 9: 000 000 000 03c 3fc fc0 c00 000
[09:07:07.255] <TB2> INFO: 10: 000 000 020 21c 1fc fc0 c00 000
[09:07:10.270] <TB2> INFO: 11: 000 000 020 21c 1fc fe0 e00 000
[09:07:13.286] <TB2> INFO: 12: e00 000 020 21c 1fc fe0 e00 000
[09:07:16.301] <TB2> INFO: 13: 000 000 000 01c 1fc fe0 e00 000
[09:07:19.317] <TB2> INFO: 14: 000 000 010 11c 1fc fe0 e00 000
[09:07:22.333] <TB2> INFO: 15: e00 000 010 10c 0fc ff0 f00 000
[09:07:25.348] <TB2> INFO: 16: 000 000 010 10c 0fc ff0 f00 000
[09:07:28.363] <TB2> INFO: 17: 000 000 010 10c 0fc ff0 f00 000
[09:07:31.379] <TB2> INFO: 18: 000 000 000 00c 0fc ff0 f00 000
[09:07:34.394] <TB2> INFO: 19: 000 000 008 00c 0fc ff0 f00 000
[09:07:34.807] <TB2> INFO: Found good delays at CLK = 2, DESER160 = 4
[09:07:34.809] <TB2> INFO: PixTestSetup:: Write Tb parameters to file.
[09:07:35.160] <TB2> INFO: write dtb parameters into /home/mameinha/data/R418_Fulltest_m20_2015-10-07_11h06m_1444208776//000_FulltestROC_m20//tbParameters.dat
[09:07:35.163] <TB2> INFO: PixTestSetup::doTest() done for.
[09:07:35.191] <TB2> INFO: enter test to run
[09:07:35.191] <TB2> INFO: test: Pretest no parameter change
[09:07:35.191] <TB2> INFO: running: pretest
[09:07:35.193] <TB2> INFO: ----------------------------------------------------------------------
[09:07:35.193] <TB2> INFO: PixTestPretest::programROC()
[09:07:35.193] <TB2> INFO: ----------------------------------------------------------------------
[09:07:38.195] <TB2> INFO: PixTestPretest::programROC() done: ROCs are all programmable
[09:07:38.195] <TB2> INFO: IA differences per ROC: 19.3
[09:07:38.201] <TB2> INFO: enter test to run
[09:07:38.201] <TB2> INFO: test: Pretest no parameter change
[09:07:38.201] <TB2> INFO: running: pretest
[09:07:38.203] <TB2> INFO: ----------------------------------------------------------------------
[09:07:38.203] <TB2> INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[09:07:38.203] <TB2> INFO: ----------------------------------------------------------------------
[09:07:38.815] <TB2> INFO: PixTestPretest::setVana() done, Module Ia 24.1 mA = 24.1 mA/ROC
[09:07:38.815] <TB2> INFO: i(loss) [mA/ROC]: 20.1
[09:07:38.819] <TB2> INFO: enter test to run
[09:07:38.819] <TB2> INFO: test: Pretest no parameter change
[09:07:38.819] <TB2> INFO: running: pretest
[09:07:38.821] <TB2> INFO: ----------------------------------------------------------------------
[09:07:38.821] <TB2> INFO: PixTestPretest::findWorkingPixel()
[09:07:38.821] <TB2> INFO: ----------------------------------------------------------------------
[09:07:38.831] <TB2> INFO: Expecting 231680 events.
[09:07:41.123] <TB2> INFO: 231680 events read in total (1904ms).
[09:07:41.125] <TB2> INFO: Test took 2304ms.
[09:07:41.497] <TB2> INFO: Found working pixel in all ROCs: col/row = 12/22
[09:07:41.510] <TB2> INFO: enter test to run
[09:07:41.510] <TB2> INFO: test: Pretest no parameter change
[09:07:41.510] <TB2> INFO: running: pretest
[09:07:41.512] <TB2> INFO: ----------------------------------------------------------------------
[09:07:41.512] <TB2> INFO: PixTestPretest::setVthrCompCalDel()
[09:07:41.512] <TB2> INFO: ----------------------------------------------------------------------
[09:07:41.521] <TB2> INFO: Expecting 231680 events.
[09:07:43.811] <TB2> INFO: 231680 events read in total (1903ms).
[09:07:43.815] <TB2> INFO: Test took 2303ms.
[09:07:44.186] <TB2> INFO: PixTestPretest::setVthrCompCalDel() done
[09:07:44.186] <TB2> INFO: CalDel: 142
[09:07:44.186] <TB2> INFO: VthrComp: 51
[09:07:44.194] <TB2> INFO: enter test to run
[09:07:44.194] <TB2> INFO: test: Pretest no parameter change
[09:07:44.194] <TB2> INFO: running: pretest
[09:07:44.203] <TB2> INFO: write dac parameters into /home/mameinha/data/R418_Fulltest_m20_2015-10-07_11h06m_1444208776//000_FulltestROC_m20//dacParameters_C0.dat
[09:07:44.207] <TB2> INFO: enter test to run
[09:07:44.207] <TB2> INFO: test: PixelAlive no parameter change
[09:07:44.207] <TB2> INFO: running: pixelalive
[09:07:44.209] <TB2> INFO: ######################################################################
[09:07:44.209] <TB2> INFO: PixTestAlive::doTest()
[09:07:44.209] <TB2> INFO: ######################################################################
[09:07:44.210] <TB2> INFO: ----------------------------------------------------------------------
[09:07:44.210] <TB2> INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0)
[09:07:44.210] <TB2> INFO: ----------------------------------------------------------------------
[09:07:44.232] <TB2> INFO: Expecting 41600 events.
[09:07:45.091] <TB2> INFO: 41600 events read in total (472ms).
[09:07:45.093] <TB2> INFO: Test took 883ms.
[09:07:45.093] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:07:45.477] <TB2> INFO: PixTestAlive::aliveTest() done
[09:07:45.477] <TB2> INFO: number of dead pixels (per ROC): 0
[09:07:45.479] <TB2> INFO: ----------------------------------------------------------------------
[09:07:45.479] <TB2> INFO: PixTestAlive::maskTest() ntrig = 10, vcal = 200 (ctrlreg = 0)
[09:07:45.479] <TB2> INFO: ----------------------------------------------------------------------
[09:07:45.500] <TB2> INFO: Expecting 41600 events.
[09:07:46.304] <TB2> INFO: 41600 events read in total (417ms).
[09:07:46.305] <TB2> INFO: Test took 826ms.
[09:07:46.305] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:07:46.305] <TB2> INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C0_V0
[09:07:46.697] <TB2> INFO: PixTestAlive::maskTest() done
[09:07:46.697] <TB2> INFO: number of mask-defect pixels (per ROC): 0
[09:07:46.699] <TB2> INFO: ----------------------------------------------------------------------
[09:07:46.699] <TB2> INFO: PixTestAlive::addressDecodingTest() ntrig = 10, vcal = 200 (ctrlreg = 0)
[09:07:46.699] <TB2> INFO: ----------------------------------------------------------------------
[09:07:46.721] <TB2> INFO: Expecting 41600 events.
[09:07:47.573] <TB2> INFO: 41600 events read in total (465ms).
[09:07:47.574] <TB2> INFO: Test took 875ms.
[09:07:47.575] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:07:47.960] <TB2> INFO: PixTestAlive::addressDecodingTest() done
[09:07:47.960] <TB2> INFO: number of address-decoding pixels (per ROC): 0
[09:07:47.960] <TB2> INFO: PixTestAlive::doTest() done, duration: 3 seconds
[09:07:47.962] <TB2> INFO: enter test to run
[09:07:47.962] <TB2> INFO: test: Scurves no parameter change
[09:07:47.962] <TB2> INFO: running: scurves
[09:07:47.964] <TB2> INFO: ######################################################################
[09:07:47.964] <TB2> INFO: PixTestScurves::doTest() ntrig = 50
[09:07:47.964] <TB2> INFO: ######################################################################
[09:07:47.964] <TB2> INFO: ----------------------------------------------------------------------
[09:07:47.964] <TB2> INFO: PixTestScurves::scurves(Vcal), ntrig = 50, dacs/step = -1, ntrig/step = -1
[09:07:47.964] <TB2> INFO: ----------------------------------------------------------------------
[09:07:47.965] <TB2> INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 0 .. 200 (-1/-1) hits flags = 528 (plus default)
[09:07:47.981] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[09:07:47.981] <TB2> INFO: run 1 of 1
[09:07:48.001] <TB2> INFO: Expecting 41808000 events.
[09:10:18.031] <TB2> INFO: 19543000 events read in total (149643ms).
[09:12:42.323] <TB2> INFO: 38871600 events read in total (293935ms).
[09:13:05.282] <TB2> INFO: 41808000 events read in total (316894ms).
[09:13:05.326] <TB2> INFO: Test took 317345ms.
[09:13:05.347] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:13:07.452] <TB2> INFO: PixTestScurves::scurves() done
[09:13:07.452] <TB2> INFO: Vcal mean: 80.73
[09:13:07.452] <TB2> INFO: Vcal RMS: 4.34
[09:13:07.457] <TB2> INFO: enter test to run
[09:13:07.457] <TB2> INFO: test: Trim no parameter change
[09:13:07.457] <TB2> INFO: running: trim
[09:13:07.459] <TB2> INFO: ######################################################################
[09:13:07.459] <TB2> INFO: PixTestTrim::doTest()
[09:13:07.459] <TB2> INFO: ######################################################################
[09:13:07.461] <TB2> INFO: ----------------------------------------------------------------------
[09:13:07.461] <TB2> INFO: PixTestTrim::trimTest() ntrig = 10, vcal = 35
[09:13:07.461] <TB2> INFO: ----------------------------------------------------------------------
[09:13:07.466] <TB2> INFO: ---> VthrComp thr map (minimal VthrComp)
[09:13:07.466] <TB2> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 10 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[09:13:07.476] <TB2> INFO: dacScan split into 1 runs with ntrig = 10
[09:13:07.477] <TB2> INFO: run 1 of 1
[09:13:07.500] <TB2> INFO: Expecting 6281600 events.
[09:13:59.697] <TB2> INFO: 6281600 events read in total (51810ms).
[09:13:59.722] <TB2> INFO: Test took 52245ms.
[09:13:59.734] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:14:00.918] <TB2> INFO: ROC 0 VthrComp = 89
[09:14:00.918] <TB2> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[09:14:00.918] <TB2> INFO: ---> dac: vcal name: TrimThr1 ntrig: 10 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[09:14:00.926] <TB2> INFO: dacScan split into 1 runs with ntrig = 10
[09:14:00.926] <TB2> INFO: run 1 of 1
[09:14:00.946] <TB2> INFO: Expecting 6281600 events.
[09:14:53.071] <TB2> INFO: 6281600 events read in total (51738ms).
[09:14:53.114] <TB2> INFO: Test took 52188ms.
[09:14:53.134] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:14:54.426] <TB2> INFO: roc 0 with ID = 0 has maximal Vcal 56.795 for pixel 6/2 mean/min/max = 45.2139/33.0916/57.3363
[09:14:54.435] <TB2> INFO: Expecting 514560 events.
[09:14:58.636] <TB2> INFO: 514560 events read in total (3814ms).
[09:14:58.643] <TB2> INFO: Test took 4217ms.
[09:14:59.036] <TB2> INFO: ---> dac: vcal name: TrimThr2 ntrig: 10 dacrange: 0 .. 150 (-1/-1) hits flags = 528 (plus default)
[09:14:59.043] <TB2> INFO: dacScan split into 1 runs with ntrig = 10
[09:14:59.043] <TB2> INFO: run 1 of 1
[09:14:59.063] <TB2> INFO: Expecting 6281600 events.
[09:15:52.232] <TB2> INFO: 6281600 events read in total (52782ms).
[09:15:52.276] <TB2> INFO: Test took 53233ms.
[09:15:52.296] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:15:53.743] <TB2> INFO: ---> TrimStepCorr4 extremal thresholds: 14.100620 .. 47.692489
[09:15:53.747] <TB2> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 10 dacrange: 4 .. 57 (-1/-1) hits flags = 528 (plus default)
[09:15:53.755] <TB2> INFO: dacScan split into 1 runs with ntrig = 10
[09:15:53.755] <TB2> INFO: run 1 of 1
[09:15:53.775] <TB2> INFO: Expecting 2246400 events.
[09:16:12.060] <TB2> INFO: 2246400 events read in total (17898ms).
[09:16:12.070] <TB2> INFO: Test took 18315ms.
[09:16:12.074] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:16:12.901] <TB2> INFO: ---> TrimStepCorr2 extremal thresholds: 20.376358 .. 43.014138
[09:16:12.905] <TB2> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 10 dacrange: 10 .. 53 (-1/-1) hits flags = 528 (plus default)
[09:16:12.913] <TB2> INFO: dacScan split into 1 runs with ntrig = 10
[09:16:12.913] <TB2> INFO: run 1 of 1
[09:16:12.933] <TB2> INFO: Expecting 1830400 events.
[09:16:28.202] <TB2> INFO: 1830400 events read in total (14882ms).
[09:16:28.210] <TB2> INFO: Test took 15297ms.
[09:16:28.214] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:16:29.076] <TB2> INFO: ---> TrimStepCorr1a extremal thresholds: 24.837394 .. 39.572374
[09:16:29.081] <TB2> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 10 dacrange: 14 .. 49 (-1/-1) hits flags = 528 (plus default)
[09:16:29.088] <TB2> INFO: dacScan split into 1 runs with ntrig = 10
[09:16:29.088] <TB2> INFO: run 1 of 1
[09:16:29.108] <TB2> INFO: Expecting 1497600 events.
[09:16:41.430] <TB2> INFO: 1497600 events read in total (11935ms).
[09:16:41.438] <TB2> INFO: Test took 12350ms.
[09:16:41.443] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:16:42.315] <TB2> INFO: ---> TrimStepCorr1b extremal thresholds: 27.200836 .. 39.438250
[09:16:42.319] <TB2> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 10 dacrange: 17 .. 49 (-1/-1) hits flags = 528 (plus default)
[09:16:42.327] <TB2> INFO: dacScan split into 1 runs with ntrig = 10
[09:16:42.327] <TB2> INFO: run 1 of 1
[09:16:42.346] <TB2> INFO: Expecting 1372800 events.
[09:16:53.791] <TB2> INFO: 1372800 events read in total (11058ms).
[09:16:53.797] <TB2> INFO: Test took 11470ms.
[09:16:53.800] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:16:54.585] <TB2> INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[09:16:54.586] <TB2> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 10 dacrange: 15 .. 55 (-1/-1) hits flags = 528 (plus default)
[09:16:54.593] <TB2> INFO: dacScan split into 1 runs with ntrig = 10
[09:16:54.593] <TB2> INFO: run 1 of 1
[09:16:54.612] <TB2> INFO: Expecting 1705600 events.
[09:17:08.694] <TB2> INFO: 1705600 events read in total (13694ms).
[09:17:08.703] <TB2> INFO: Test took 14110ms.
[09:17:08.707] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:17:09.555] <TB2> INFO: write dac parameters into /home/mameinha/data/R418_Fulltest_m20_2015-10-07_11h06m_1444208776//000_FulltestROC_m20//dacParameters35_C0.dat
[09:17:09.561] <TB2> INFO: write trim parameters into /home/mameinha/data/R418_Fulltest_m20_2015-10-07_11h06m_1444208776//000_FulltestROC_m20//trimParameters35_C0.dat
[09:17:09.572] <TB2> INFO: PixTestTrim::trimTest() done
[09:17:09.572] <TB2> INFO: vtrim: 102
[09:17:09.572] <TB2> INFO: vthrcomp: 89
[09:17:09.572] <TB2> INFO: vcal mean: 34.99
[09:17:09.572] <TB2> INFO: vcal RMS: 0.70
[09:17:09.572] <TB2> INFO: bits mean: 9.20
[09:17:09.572] <TB2> INFO: bits RMS: 2.67
[09:17:09.577] <TB2> INFO: ----------------------------------------------------------------------
[09:17:09.577] <TB2> INFO: PixTestTrim::trimBitTest() ntrig = 10, vtrims = 254 126 63 32
[09:17:09.577] <TB2> INFO: ----------------------------------------------------------------------
[09:17:09.577] <TB2> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 10 dacrange: 0 .. 199 (-1/-1) hits flags = 528 (plus default)
[09:17:09.588] <TB2> INFO: dacScan split into 1 runs with ntrig = 10
[09:17:09.588] <TB2> INFO: run 1 of 1
[09:17:09.608] <TB2> INFO: Expecting 8320000 events.
[09:18:15.081] <TB2> INFO: 8320000 events read in total (65086ms).
[09:18:15.130] <TB2> INFO: Test took 65542ms.
[09:18:15.151] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:18:16.671] <TB2> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 10 dacrange: 0 .. 136 (-1/-1) hits flags = 528 (plus default)
[09:18:16.679] <TB2> INFO: dacScan split into 1 runs with ntrig = 10
[09:18:16.679] <TB2> INFO: run 1 of 1
[09:18:16.700] <TB2> INFO: Expecting 5699200 events.
[09:19:02.432] <TB2> INFO: 5699200 events read in total (45345ms).
[09:19:02.454] <TB2> INFO: Test took 45775ms.
[09:19:02.463] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:19:03.674] <TB2> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 10 dacrange: 0 .. 126 (-1/-1) hits flags = 528 (plus default)
[09:19:03.683] <TB2> INFO: dacScan split into 1 runs with ntrig = 10
[09:19:03.683] <TB2> INFO: run 1 of 1
[09:19:03.702] <TB2> INFO: Expecting 5283200 events.
[09:19:44.679] <TB2> INFO: 5283200 events read in total (40590ms).
[09:19:44.699] <TB2> INFO: Test took 41016ms.
[09:19:44.706] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:19:45.820] <TB2> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 10 dacrange: 0 .. 126 (-1/-1) hits flags = 528 (plus default)
[09:19:45.828] <TB2> INFO: dacScan split into 1 runs with ntrig = 10
[09:19:45.828] <TB2> INFO: run 1 of 1
[09:19:45.848] <TB2> INFO: Expecting 5283200 events.
[09:20:27.188] <TB2> INFO: 5283200 events read in total (40954ms).
[09:20:27.206] <TB2> INFO: Test took 41378ms.
[09:20:27.214] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:20:28.358] <TB2> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 10 dacrange: 0 .. 126 (-1/-1) hits flags = 528 (plus default)
[09:20:28.366] <TB2> INFO: dacScan split into 1 runs with ntrig = 10
[09:20:28.366] <TB2> INFO: run 1 of 1
[09:20:28.385] <TB2> INFO: Expecting 5283200 events.
[09:21:09.840] <TB2> INFO: 5283200 events read in total (41068ms).
[09:21:09.857] <TB2> INFO: Test took 41491ms.
[09:21:09.865] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:21:11.254] <TB2> INFO: PixTestTrim::trimBitTest() done
[09:21:11.255] <TB2> INFO: PixTestTrim::doTest() done, duration: 483 seconds
[09:21:11.297] <TB2> INFO: enter test to run
[09:21:11.297] <TB2> INFO: test: PhOptimization no parameter change
[09:21:11.297] <TB2> INFO: running: phoptimization
[09:21:11.297] <TB2> INFO: ######################################################################
[09:21:11.297] <TB2> INFO: PixTestPhOptimization::doTest() Ntrig = 10
[09:21:11.297] <TB2> INFO: ######################################################################
[09:21:11.318] <TB2> INFO: Expecting 41600 events.
[09:21:12.124] <TB2> INFO: 41600 events read in total (419ms).
[09:21:12.124] <TB2> INFO: Test took 826ms.
[09:21:12.124] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:21:12.515] <TB2> INFO: Expecting 41600 events.
[09:21:13.335] <TB2> INFO: 41600 events read in total (433ms).
[09:21:13.335] <TB2> INFO: Test took 1209ms.
[09:21:13.335] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:21:13.723] <TB2> INFO: Expecting 41600 events.
[09:21:14.558] <TB2> INFO: 41600 events read in total (448ms).
[09:21:14.558] <TB2> INFO: Test took 1221ms.
[09:21:14.559] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:21:14.947] <TB2> INFO: Expecting 2560 events.
[09:21:15.384] <TB2> INFO: 2560 events read in total (31ms).
[09:21:15.384] <TB2> INFO: Test took 825ms.
[09:21:15.779] <TB2> INFO: Expecting 655360 events.
[09:21:21.321] <TB2> INFO: 655360 events read in total (5155ms).
[09:21:21.330] <TB2> INFO: Test took 5945ms.
[09:21:21.618] <TB2> INFO: Expecting 655360 events.
[09:21:27.164] <TB2> INFO: 655360 events read in total (5159ms).
[09:21:27.172] <TB2> INFO: Test took 5828ms.
[09:21:27.200] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[09:21:27.324] <TB2> INFO: write dac parameters into /home/mameinha/data/R418_Fulltest_m20_2015-10-07_11h06m_1444208776//000_FulltestROC_m20//dacParameters35_C0.dat
[09:21:27.453] <TB2> INFO: Expecting 41600 events.
[09:21:28.258] <TB2> INFO: 41600 events read in total (417ms).
[09:21:28.258] <TB2> INFO: Test took 914ms.
[09:21:28.643] <TB2> INFO: Expecting 41600 events.
[09:21:29.450] <TB2> INFO: 41600 events read in total (419ms).
[09:21:29.450] <TB2> INFO: Test took 1191ms.
[09:21:29.832] <TB2> INFO: Expecting 41600 events.
[09:21:30.631] <TB2> INFO: 41600 events read in total (412ms).
[09:21:30.632] <TB2> INFO: Test took 1181ms.
[09:21:31.017] <TB2> INFO: Expecting 2560 events.
[09:21:31.439] <TB2> INFO: 2560 events read in total (34ms).
[09:21:31.439] <TB2> INFO: Test took 806ms.
[09:21:31.833] <TB2> INFO: Expecting 2560 events.
[09:21:32.254] <TB2> INFO: 2560 events read in total (34ms).
[09:21:32.255] <TB2> INFO: Test took 815ms.
[09:21:32.664] <TB2> INFO: PixTestPhOptimization::doTest() done, duration: 21 seconds
[09:21:32.664] <TB2> INFO: PH scale (per ROC): 94
[09:21:32.664] <TB2> INFO: PH offset (per ROC): 152
[09:21:32.683] <TB2> INFO: enter test to run
[09:21:32.683] <TB2> INFO: test: GainPedestal no parameter change
[09:21:32.683] <TB2> INFO: running: gainpedestal
[09:21:32.684] <TB2> INFO: ######################################################################
[09:21:32.684] <TB2> INFO: PixTestGainPedestal::doTest() ntrig = 10
[09:21:32.684] <TB2> INFO: ######################################################################
[09:21:32.694] <TB2> INFO: scanning low vcal = 10
[09:21:32.715] <TB2> INFO: Expecting 41600 events.
[09:21:33.811] <TB2> INFO: 41600 events read in total (709ms).
[09:21:33.811] <TB2> INFO: Test took 1117ms.
[09:21:33.812] <TB2> INFO: scanning low vcal = 20
[09:21:34.206] <TB2> INFO: Expecting 41600 events.
[09:21:35.315] <TB2> INFO: 41600 events read in total (722ms).
[09:21:35.315] <TB2> INFO: Test took 1503ms.
[09:21:35.315] <TB2> INFO: scanning low vcal = 30
[09:21:35.710] <TB2> INFO: Expecting 41600 events.
[09:21:36.817] <TB2> INFO: 41600 events read in total (720ms).
[09:21:36.817] <TB2> INFO: Test took 1502ms.
[09:21:36.818] <TB2> INFO: scanning low vcal = 40
[09:21:37.211] <TB2> INFO: Expecting 41600 events.
[09:21:38.373] <TB2> INFO: 41600 events read in total (775ms).
[09:21:38.374] <TB2> INFO: Test took 1556ms.
[09:21:38.374] <TB2> INFO: scanning low vcal = 50
[09:21:38.756] <TB2> INFO: Expecting 41600 events.
[09:21:39.926] <TB2> INFO: 41600 events read in total (783ms).
[09:21:39.926] <TB2> INFO: Test took 1552ms.
[09:21:39.927] <TB2> INFO: scanning low vcal = 60
[09:21:40.312] <TB2> INFO: Expecting 41600 events.
[09:21:41.463] <TB2> INFO: 41600 events read in total (764ms).
[09:21:41.464] <TB2> INFO: Test took 1537ms.
[09:21:41.464] <TB2> INFO: scanning low vcal = 70
[09:21:41.845] <TB2> INFO: Expecting 41600 events.
[09:21:43.017] <TB2> INFO: 41600 events read in total (785ms).
[09:21:43.017] <TB2> INFO: Test took 1553ms.
[09:21:43.018] <TB2> INFO: scanning low vcal = 80
[09:21:43.397] <TB2> INFO: Expecting 41600 events.
[09:21:44.570] <TB2> INFO: 41600 events read in total (786ms).
[09:21:44.570] <TB2> INFO: Test took 1552ms.
[09:21:44.571] <TB2> INFO: scanning low vcal = 90
[09:21:44.952] <TB2> INFO: Expecting 41600 events.
[09:21:46.118] <TB2> INFO: 41600 events read in total (779ms).
[09:21:46.119] <TB2> INFO: Test took 1548ms.
[09:21:46.119] <TB2> INFO: scanning low vcal = 100
[09:21:46.505] <TB2> INFO: Expecting 41600 events.
[09:21:47.675] <TB2> INFO: 41600 events read in total (783ms).
[09:21:47.675] <TB2> INFO: Test took 1556ms.
[09:21:47.676] <TB2> INFO: scanning low vcal = 110
[09:21:48.057] <TB2> INFO: Expecting 41600 events.
[09:21:49.242] <TB2> INFO: 41600 events read in total (799ms).
[09:21:49.243] <TB2> INFO: Test took 1567ms.
[09:21:49.244] <TB2> INFO: scanning low vcal = 120
[09:21:49.624] <TB2> INFO: Expecting 41600 events.
[09:21:50.774] <TB2> INFO: 41600 events read in total (763ms).
[09:21:50.775] <TB2> INFO: Test took 1531ms.
[09:21:50.775] <TB2> INFO: scanning low vcal = 130
[09:21:51.157] <TB2> INFO: Expecting 41600 events.
[09:21:52.288] <TB2> INFO: 41600 events read in total (744ms).
[09:21:52.289] <TB2> INFO: Test took 1514ms.
[09:21:52.289] <TB2> INFO: scanning low vcal = 140
[09:21:52.676] <TB2> INFO: Expecting 41600 events.
[09:21:53.837] <TB2> INFO: 41600 events read in total (773ms).
[09:21:53.838] <TB2> INFO: Test took 1548ms.
[09:21:53.838] <TB2> INFO: scanning low vcal = 150
[09:21:54.224] <TB2> INFO: Expecting 41600 events.
[09:21:55.386] <TB2> INFO: 41600 events read in total (775ms).
[09:21:55.386] <TB2> INFO: Test took 1548ms.
[09:21:55.387] <TB2> INFO: scanning low vcal = 160
[09:21:55.771] <TB2> INFO: Expecting 41600 events.
[09:21:56.923] <TB2> INFO: 41600 events read in total (765ms).
[09:21:56.924] <TB2> INFO: Test took 1537ms.
[09:21:56.924] <TB2> INFO: scanning low vcal = 170
[09:21:57.305] <TB2> INFO: Expecting 41600 events.
[09:21:58.455] <TB2> INFO: 41600 events read in total (763ms).
[09:21:58.455] <TB2> INFO: Test took 1531ms.
[09:21:58.456] <TB2> INFO: scanning low vcal = 180
[09:21:58.838] <TB2> INFO: Expecting 41600 events.
[09:21:59.993] <TB2> INFO: 41600 events read in total (768ms).
[09:21:59.994] <TB2> INFO: Test took 1538ms.
[09:21:59.994] <TB2> INFO: scanning low vcal = 190
[09:22:00.375] <TB2> INFO: Expecting 41600 events.
[09:22:01.536] <TB2> INFO: 41600 events read in total (774ms).
[09:22:01.537] <TB2> INFO: Test took 1543ms.
[09:22:01.537] <TB2> INFO: scanning low vcal = 200
[09:22:01.922] <TB2> INFO: Expecting 41600 events.
[09:22:03.074] <TB2> INFO: 41600 events read in total (765ms).
[09:22:03.074] <TB2> INFO: Test took 1537ms.
[09:22:03.075] <TB2> INFO: scanning low vcal = 210
[09:22:03.456] <TB2> INFO: Expecting 41600 events.
[09:22:04.606] <TB2> INFO: 41600 events read in total (763ms).
[09:22:04.606] <TB2> INFO: Test took 1531ms.
[09:22:04.607] <TB2> INFO: scanning low vcal = 220
[09:22:04.990] <TB2> INFO: Expecting 41600 events.
[09:22:06.145] <TB2> INFO: 41600 events read in total (763ms).
[09:22:06.146] <TB2> INFO: Test took 1539ms.
[09:22:06.146] <TB2> INFO: scanning low vcal = 230
[09:22:06.529] <TB2> INFO: Expecting 41600 events.
[09:22:07.681] <TB2> INFO: 41600 events read in total (765ms).
[09:22:07.682] <TB2> INFO: Test took 1536ms.
[09:22:07.682] <TB2> INFO: scanning low vcal = 240
[09:22:08.062] <TB2> INFO: Expecting 41600 events.
[09:22:09.226] <TB2> INFO: 41600 events read in total (777ms).
[09:22:09.226] <TB2> INFO: Test took 1544ms.
[09:22:09.227] <TB2> INFO: scanning low vcal = 250
[09:22:09.611] <TB2> INFO: Expecting 41600 events.
[09:22:10.757] <TB2> INFO: 41600 events read in total (759ms).
[09:22:10.757] <TB2> INFO: Test took 1530ms.
[09:22:10.758] <TB2> INFO: scanning high vcal = 30 (= 210 in low range)
[09:22:11.144] <TB2> INFO: Expecting 41600 events.
[09:22:12.306] <TB2> INFO: 41600 events read in total (775ms).
[09:22:12.306] <TB2> INFO: Test took 1548ms.
[09:22:12.307] <TB2> INFO: scanning high vcal = 50 (= 350 in low range)
[09:22:12.691] <TB2> INFO: Expecting 41600 events.
[09:22:13.843] <TB2> INFO: 41600 events read in total (765ms).
[09:22:13.844] <TB2> INFO: Test took 1537ms.
[09:22:13.844] <TB2> INFO: scanning high vcal = 70 (= 490 in low range)
[09:22:14.225] <TB2> INFO: Expecting 41600 events.
[09:22:15.387] <TB2> INFO: 41600 events read in total (775ms).
[09:22:15.388] <TB2> INFO: Test took 1544ms.
[09:22:15.388] <TB2> INFO: scanning high vcal = 90 (= 630 in low range)
[09:22:15.774] <TB2> INFO: Expecting 41600 events.
[09:22:16.953] <TB2> INFO: 41600 events read in total (792ms).
[09:22:16.954] <TB2> INFO: Test took 1566ms.
[09:22:16.954] <TB2> INFO: scanning high vcal = 200 (= 1400 in low range)
[09:22:17.336] <TB2> INFO: Expecting 41600 events.
[09:22:18.497] <TB2> INFO: 41600 events read in total (774ms).
[09:22:18.497] <TB2> INFO: Test took 1542ms.
[09:22:18.879] <TB2> INFO: PixTestGainPedestal::measure() done
[09:22:20.890] <TB2> INFO: PixTestGainPedestal::fit() done
[09:22:20.890] <TB2> INFO: non-linearity mean: 0.956
[09:22:20.890] <TB2> INFO: non-linearity RMS: 0.006
[09:22:20.890] <TB2> INFO: write gain/ped parameters into /home/mameinha/data/R418_Fulltest_m20_2015-10-07_11h06m_1444208776//000_FulltestROC_m20//phCalibrationFitErr35_C0.dat
[09:22:20.926] <TB2> INFO: PixTestGainPedestal::doTest() done, duration: 48 seconds
[09:22:20.926] <TB2> INFO: enter test to run
[09:22:20.926] <TB2> INFO: test: Readback no parameter change
[09:22:20.926] <TB2> INFO: running: readback
[09:22:20.926] <TB2> INFO: readReadbackCal: /home/mameinha/data/R418_Fulltest_m20_2015-10-07_11h06m_1444208776//000_FulltestROC_m20//readbackCal_C0.dat .. /home/mameinha/data/R418_Fulltest_m20_2015-10-07_11h06m_1444208776//000_FulltestROC_m20//readbackCal_C0.dat
[09:22:20.963] <TB2> INFO: ######################################################################
[09:22:20.963] <TB2> INFO: PixTestReadback::doTest()
[09:22:20.963] <TB2> INFO: ######################################################################
[09:22:20.964] <TB2> INFO: PixTestReadback::RES sent once
[09:22:32.745] <TB2> INFO: write readback calibration parameters into /home/mameinha/data/R418_Fulltest_m20_2015-10-07_11h06m_1444208776//000_FulltestROC_m20//readbackCal_C0.dat
[09:22:32.757] <TB2> INFO: PixTestPattern:: pg_setup set to default.
[09:22:32.757] <TB2> INFO: PixTestReadback::RES sent once
[09:22:43.868] <TB2> INFO: write readback calibration parameters into /home/mameinha/data/R418_Fulltest_m20_2015-10-07_11h06m_1444208776//000_FulltestROC_m20//readbackCal_C0.dat
[09:22:43.883] <TB2> INFO: PixTestPattern:: pg_setup set to default.
[09:22:43.883] <TB2> INFO: PixTestReadback::RES sent once
[09:22:52.219] <TB2> INFO: PixTestPattern:: pg_setup set to default.
[09:22:52.220] <TB2> INFO: Vbg will be calibrated using Vd calibration
[09:22:52.220] <TB2> INFO: /*/*/*/*::: ROC 0: uncalibrated Vbg = 147.6calibrated Vbg = 1.22756 :::*/*/*/*/
[09:22:52.595] <TB2> INFO: PixTestReadback::RES sent once
[09:23:01.454] <TB2> INFO: write readback calibration parameters into /home/mameinha/data/R418_Fulltest_m20_2015-10-07_11h06m_1444208776//000_FulltestROC_m20//readbackCal_C0.dat
[09:23:01.461] <TB2> INFO: PixTestPattern:: pg_setup set to default.
[09:23:01.461] <TB2> INFO: PixTestReadback::doTest() done
[09:23:01.528] <TB2> INFO: enter test to run
[09:23:01.529] <TB2> INFO: test: no parameter change
[09:23:01.592] <TB2> QUIET: Connection to board 137 closed.
[09:23:01.672] <TB2> INFO: pXar: this is the end, my friend