[12:48:53.097] <TB0> INFO: *** Welcome to pxar ***
[12:48:53.097] <TB0> INFO: *** Today: 2016/09/16
[12:48:54.681] <TB0> INFO: *** Version: fe94
[12:48:54.681] <TB0> INFO: readRocDacs: /usr/local/coldboxDATA/M2324_FullQualification_2016-09-16_14h37m_1474029479//000_FulltestPxar_m20//dacParameters_C0.dat .. /usr/local/coldboxDATA/M2324_FullQualification_2016-09-16_14h37m_1474029479//000_FulltestPxar_m20//dacParameters_C15.dat
[12:48:54.682] <TB0> INFO: readTbmDacs: /usr/local/coldboxDATA/M2324_FullQualification_2016-09-16_14h37m_1474029479//000_FulltestPxar_m20//tbmParameters_C0a.dat .. /usr/local/coldboxDATA/M2324_FullQualification_2016-09-16_14h37m_1474029479//000_FulltestPxar_m20//tbmParameters_C0b.dat
[12:48:54.682] <TB0> INFO: readMaskFile: /usr/local/coldboxDATA/M2324_FullQualification_2016-09-16_14h37m_1474029479//000_FulltestPxar_m20//defaultMaskFile.dat
[12:48:54.682] <TB0> INFO: readTrimFile: /usr/local/coldboxDATA/M2324_FullQualification_2016-09-16_14h37m_1474029479//000_FulltestPxar_m20//trimParameters_C0.dat .. /usr/local/coldboxDATA/M2324_FullQualification_2016-09-16_14h37m_1474029479//000_FulltestPxar_m20//trimParameters_C15.dat
[12:48:54.749] <TB0> INFO: clk: 4
[12:48:54.749] <TB0> INFO: ctr: 4
[12:48:54.749] <TB0> INFO: sda: 19
[12:48:54.749] <TB0> INFO: tin: 9
[12:48:54.749] <TB0> INFO: level: 15
[12:48:54.749] <TB0> INFO: triggerdelay: 0
[12:48:54.749] <TB0> QUIET: Instanciating API for pxar v2.7.6+55~gafdbfd9
[12:48:54.749] <TB0> INFO: Log level: INFO
[12:48:54.756] <TB0> INFO: Found DTB DTB_WS6AYH
[12:48:54.767] <TB0> QUIET: Connection to board DTB_WS6AYH opened.
[12:48:54.769] <TB0> INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 73
HW version: DTB1.2
FW version: 4.6
SW version: 4.7
Options:
USB id: DTB_WS6AYH
MAC address: 40D855118049
Hostname: pixelDTB073
Comment:
------------------------------------------------------
[12:48:54.771] <TB0> INFO: RPC call hashes of host and DTB match: 486171790
[12:48:56.269] <TB0> INFO: DUT info:
[12:48:56.269] <TB0> INFO: The DUT currently contains the following objects:
[12:48:56.269] <TB0> INFO: 2 TBM Cores tbm09c (2 ON)
[12:48:56.269] <TB0> INFO: TBM Core alpha (0): 7 registers set
[12:48:56.269] <TB0> INFO: TBM Core beta (1): 7 registers set
[12:48:56.269] <TB0> INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[12:48:56.269] <TB0> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[12:48:56.269] <TB0> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[12:48:56.269] <TB0> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[12:48:56.269] <TB0> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[12:48:56.269] <TB0> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[12:48:56.269] <TB0> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[12:48:56.269] <TB0> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[12:48:56.269] <TB0> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[12:48:56.269] <TB0> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[12:48:56.269] <TB0> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[12:48:56.269] <TB0> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[12:48:56.269] <TB0> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[12:48:56.269] <TB0> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[12:48:56.269] <TB0> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[12:48:56.269] <TB0> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[12:48:56.269] <TB0> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[12:48:56.670] <TB0> INFO: enter 'restricted' command line mode
[12:48:56.670] <TB0> INFO: enter test to run
[12:48:56.670] <TB0> INFO: test: pretest no parameter change
[12:48:56.670] <TB0> INFO: running: pretest
[12:48:56.674] <TB0> INFO: ----------------------------------------------------------------------
[12:48:56.674] <TB0> INFO: PixTestPretest::programROC()
[12:48:56.674] <TB0> INFO: ----------------------------------------------------------------------
[12:49:14.688] <TB0> INFO: PixTestPretest::programROC() done: ROCs are all programmable
[12:49:14.688] <TB0> INFO: IA differences per ROC: 17.7 17.7 17.7 18.5 20.1 19.3 16.9 16.1 20.1 18.5 19.3 18.5 18.5 19.3 21.7 21.7
[12:49:14.778] <TB0> INFO: enter test to run
[12:49:14.778] <TB0> INFO: test: pretest no parameter change
[12:49:14.778] <TB0> INFO: running: pretest
[12:49:14.779] <TB0> INFO: ----------------------------------------------------------------------
[12:49:14.779] <TB0> INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[12:49:14.779] <TB0> INFO: ----------------------------------------------------------------------
[12:49:36.039] <TB0> INFO: PixTestPretest::setVana() done, Module Ia 390.7 mA = 24.4187 mA/ROC
[12:49:36.039] <TB0> INFO: i(loss) [mA/ROC]: 19.3 18.5 19.3 19.3 20.1 20.1 19.3 19.3 19.3 18.5 18.5 19.3 19.3 20.1 19.3 18.5
[12:49:36.065] <TB0> INFO: enter test to run
[12:49:36.065] <TB0> INFO: test: pretest no parameter change
[12:49:36.065] <TB0> INFO: running: pretest
[12:49:36.065] <TB0> INFO: ----------------------------------------------------------------------
[12:49:36.065] <TB0> INFO: PixTestPretest::findTiming()
[12:49:36.065] <TB0> INFO: ----------------------------------------------------------------------
[12:49:36.065] <TB0> INFO: PixTestCmd::init()
[12:49:36.896] <TB0> WARNING: Not unmasking DUT, not setting Calibrate bits!
[12:51:07.035] <TB0> INFO: TBM phases: 160MHz: 7, 400MHz: 6, TBM delays: ROC(0/1):4, header/trailer: 1, token: 1
[12:51:07.035] <TB0> INFO: (success/tries = 100/100), width = 5
[12:51:07.035] <TB0> INFO: enter test to run
[12:51:07.035] <TB0> INFO: test: pretest no parameter change
[12:51:07.035] <TB0> INFO: running: pretest
[12:51:07.037] <TB0> INFO: ----------------------------------------------------------------------
[12:51:07.037] <TB0> INFO: PixTestPretest::findWorkingPixel()
[12:51:07.037] <TB0> INFO: ----------------------------------------------------------------------
[12:51:07.127] <TB0> INFO: Expecting 231680 events.
[12:51:12.698] <TB0> ERROR: <datapipe.cc/CheckEventValidity:L523> Channel 0 Number of ROCs (1) != Token Chain Length (4)
[12:51:12.746] <TB0> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (21) != TBM ID (2)
[12:51:31.010] <TB0> INFO: 231680 events read in total (23327ms).
[12:51:31.015] <TB0> INFO: Test took 23976ms.
[12:51:31.216] <TB0> INFO: Found working pixel in all ROCs: col/row = 12/22
[12:51:31.271] <TB0> INFO: enter test to run
[12:51:31.271] <TB0> INFO: test: pretest no parameter change
[12:51:31.271] <TB0> INFO: running: pretest
[12:51:31.272] <TB0> INFO: ----------------------------------------------------------------------
[12:51:31.272] <TB0> INFO: PixTestPretest::setVthrCompCalDel()
[12:51:31.272] <TB0> INFO: ----------------------------------------------------------------------
[12:51:31.364] <TB0> INFO: Expecting 231680 events.
[12:51:55.348] <TB0> INFO: 231680 events read in total (23428ms).
[12:51:55.355] <TB0> INFO: Test took 24080ms.
[12:51:55.565] <TB0> INFO: PixTestPretest::setVthrCompCalDel() done
[12:51:55.565] <TB0> INFO: CalDel: 139 128 148 143 141 153 127 141 141 157 138 139 148 134 148 168
[12:51:55.565] <TB0> INFO: VthrComp: 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51
[12:51:55.602] <TB0> INFO: enter test to run
[12:51:55.602] <TB0> INFO: test: pretest no parameter change
[12:51:55.602] <TB0> INFO: running: pretest
[12:51:55.602] <TB0> INFO: write dac parameters into /usr/local/coldboxDATA/M2324_FullQualification_2016-09-16_14h37m_1474029479//000_FulltestPxar_m20//dacParameters_C0.dat
[12:51:55.602] <TB0> INFO: write dac parameters into /usr/local/coldboxDATA/M2324_FullQualification_2016-09-16_14h37m_1474029479//000_FulltestPxar_m20//dacParameters_C1.dat
[12:51:55.602] <TB0> INFO: write dac parameters into /usr/local/coldboxDATA/M2324_FullQualification_2016-09-16_14h37m_1474029479//000_FulltestPxar_m20//dacParameters_C2.dat
[12:51:55.602] <TB0> INFO: write dac parameters into /usr/local/coldboxDATA/M2324_FullQualification_2016-09-16_14h37m_1474029479//000_FulltestPxar_m20//dacParameters_C3.dat
[12:51:55.602] <TB0> INFO: write dac parameters into /usr/local/coldboxDATA/M2324_FullQualification_2016-09-16_14h37m_1474029479//000_FulltestPxar_m20//dacParameters_C4.dat
[12:51:55.602] <TB0> INFO: write dac parameters into /usr/local/coldboxDATA/M2324_FullQualification_2016-09-16_14h37m_1474029479//000_FulltestPxar_m20//dacParameters_C5.dat
[12:51:55.602] <TB0> INFO: write dac parameters into /usr/local/coldboxDATA/M2324_FullQualification_2016-09-16_14h37m_1474029479//000_FulltestPxar_m20//dacParameters_C6.dat
[12:51:55.603] <TB0> INFO: write dac parameters into /usr/local/coldboxDATA/M2324_FullQualification_2016-09-16_14h37m_1474029479//000_FulltestPxar_m20//dacParameters_C7.dat
[12:51:55.603] <TB0> INFO: write dac parameters into /usr/local/coldboxDATA/M2324_FullQualification_2016-09-16_14h37m_1474029479//000_FulltestPxar_m20//dacParameters_C8.dat
[12:51:55.603] <TB0> INFO: write dac parameters into /usr/local/coldboxDATA/M2324_FullQualification_2016-09-16_14h37m_1474029479//000_FulltestPxar_m20//dacParameters_C9.dat
[12:51:55.603] <TB0> INFO: write dac parameters into /usr/local/coldboxDATA/M2324_FullQualification_2016-09-16_14h37m_1474029479//000_FulltestPxar_m20//dacParameters_C10.dat
[12:51:55.603] <TB0> INFO: write dac parameters into /usr/local/coldboxDATA/M2324_FullQualification_2016-09-16_14h37m_1474029479//000_FulltestPxar_m20//dacParameters_C11.dat
[12:51:55.603] <TB0> INFO: write dac parameters into /usr/local/coldboxDATA/M2324_FullQualification_2016-09-16_14h37m_1474029479//000_FulltestPxar_m20//dacParameters_C12.dat
[12:51:55.603] <TB0> INFO: write dac parameters into /usr/local/coldboxDATA/M2324_FullQualification_2016-09-16_14h37m_1474029479//000_FulltestPxar_m20//dacParameters_C13.dat
[12:51:55.603] <TB0> INFO: write dac parameters into /usr/local/coldboxDATA/M2324_FullQualification_2016-09-16_14h37m_1474029479//000_FulltestPxar_m20//dacParameters_C14.dat
[12:51:55.603] <TB0> INFO: write dac parameters into /usr/local/coldboxDATA/M2324_FullQualification_2016-09-16_14h37m_1474029479//000_FulltestPxar_m20//dacParameters_C15.dat
[12:51:55.603] <TB0> INFO: enter test to run
[12:51:55.603] <TB0> INFO: test: fulltest no parameter change
[12:51:55.604] <TB0> INFO: running: fulltest
[12:51:55.604] <TB0> INFO: ######################################################################
[12:51:55.604] <TB0> INFO: PixTestFullTest::doTest()
[12:51:55.604] <TB0> INFO: ######################################################################
[12:51:55.605] <TB0> INFO: ######################################################################
[12:51:55.605] <TB0> INFO: PixTestAlive::doTest()
[12:51:55.605] <TB0> INFO: ######################################################################
[12:51:55.606] <TB0> INFO: ----------------------------------------------------------------------
[12:51:55.606] <TB0> INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[12:51:55.606] <TB0> INFO: ----------------------------------------------------------------------
[12:51:55.877] <TB0> INFO: Expecting 41600 events.
[12:52:03.725] <TB0> INFO: 41600 events read in total (7292ms).
[12:52:03.726] <TB0> INFO: Test took 8119ms.
[12:52:03.949] <TB0> INFO: PixTestAlive::aliveTest() done
[12:52:03.949] <TB0> INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 1 0 0 0 0
[12:52:03.951] <TB0> INFO: ----------------------------------------------------------------------
[12:52:03.951] <TB0> INFO: PixTestAlive::maskTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[12:52:03.951] <TB0> INFO: ----------------------------------------------------------------------
[12:52:04.229] <TB0> INFO: Expecting 41600 events.
[12:52:09.217] <TB0> INFO: 41600 events read in total (4432ms).
[12:52:09.218] <TB0> INFO: Test took 5266ms.
[12:52:09.218] <TB0> INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[12:52:09.457] <TB0> INFO: PixTestAlive::maskTest() done
[12:52:09.457] <TB0> INFO: number of mask-defect pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[12:52:09.458] <TB0> INFO: ----------------------------------------------------------------------
[12:52:09.459] <TB0> INFO: PixTestAlive::addressDecodingTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[12:52:09.459] <TB0> INFO: ----------------------------------------------------------------------
[12:52:09.745] <TB0> INFO: Expecting 41600 events.
[12:52:17.661] <TB0> INFO: 41600 events read in total (7359ms).
[12:52:17.661] <TB0> INFO: Test took 8201ms.
[12:52:17.883] <TB0> INFO: PixTestAlive::addressDecodingTest() done
[12:52:17.883] <TB0> INFO: number of address-decoding pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[12:52:17.883] <TB0> INFO: PixTestAlive::doTest() done, duration: 22 seconds
[12:52:17.883] <TB0> INFO: Decoding statistics:
[12:52:17.883] <TB0> INFO: General information:
[12:52:17.883] <TB0> INFO: 16bit words read: 0
[12:52:17.883] <TB0> INFO: valid events total: 0
[12:52:17.883] <TB0> INFO: empty events: 0
[12:52:17.883] <TB0> INFO: valid events with pixels: 0
[12:52:17.883] <TB0> INFO: valid pixel hits: 0
[12:52:17.883] <TB0> INFO: Event errors: 0
[12:52:17.883] <TB0> INFO: start marker: 0
[12:52:17.883] <TB0> INFO: stop marker: 0
[12:52:17.883] <TB0> INFO: overflow: 0
[12:52:17.883] <TB0> INFO: invalid 5bit words: 0
[12:52:17.883] <TB0> INFO: invalid XOR eye diagram: 0
[12:52:17.883] <TB0> INFO: frame (failed synchr.): 0
[12:52:17.883] <TB0> INFO: idle data (no TBM trl): 0
[12:52:17.883] <TB0> INFO: no data (only TBM hdr): 0
[12:52:17.883] <TB0> INFO: TBM errors: 0
[12:52:17.883] <TB0> INFO: flawed TBM headers: 0
[12:52:17.883] <TB0> INFO: flawed TBM trailers: 0
[12:52:17.883] <TB0> INFO: event ID mismatches: 0
[12:52:17.883] <TB0> INFO: ROC errors: 0
[12:52:17.883] <TB0> INFO: missing ROC header(s): 0
[12:52:17.883] <TB0> INFO: misplaced readback start: 0
[12:52:17.883] <TB0> INFO: Pixel decoding errors: 0
[12:52:17.883] <TB0> INFO: pixel data incomplete: 0
[12:52:17.883] <TB0> INFO: pixel address: 0
[12:52:17.883] <TB0> INFO: pulse height fill bit: 0
[12:52:17.883] <TB0> INFO: buffer corruption: 0
[12:52:17.889] <TB0> INFO: ######################################################################
[12:52:17.889] <TB0> INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[12:52:17.889] <TB0> INFO: ######################################################################
[12:52:17.892] <TB0> INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (-1/-1) hits flags = 514 (plus default)
[12:52:17.902] <TB0> INFO: dacScan split into 1 runs with ntrig = 5
[12:52:17.902] <TB0> INFO: run 1 of 1
[12:52:18.164] <TB0> INFO: Expecting 3120000 events.
[12:54:06.900] <TB0> INFO: 863925 events read in total (108180ms).
[12:55:53.732] <TB0> INFO: 1712680 events read in total (215012ms).
[12:57:40.109] <TB0> INFO: 2574555 events read in total (321389ms).
[12:58:47.756] <TB0> INFO: 3120000 events read in total (389036ms).
[12:58:47.830] <TB0> INFO: Test took 389929ms.
[12:59:11.461] <TB0> INFO: PixTestBBMap::doTest() done, duration: 413 seconds
[12:59:11.461] <TB0> INFO: number of dead bumps (per ROC): 2 0 0 0 0 0 1 0 1 0 0 0 1 0 0 0
[12:59:11.461] <TB0> INFO: separation cut (per ROC): 76 70 74 83 87 86 85 68 75 68 105 96 103 86 93 93
[12:59:11.461] <TB0> INFO: Decoding statistics:
[12:59:11.461] <TB0> INFO: General information:
[12:59:11.461] <TB0> INFO: 16bit words read: 0
[12:59:11.461] <TB0> INFO: valid events total: 0
[12:59:11.461] <TB0> INFO: empty events: 0
[12:59:11.461] <TB0> INFO: valid events with pixels: 0
[12:59:11.461] <TB0> INFO: valid pixel hits: 0
[12:59:11.461] <TB0> INFO: Event errors: 0
[12:59:11.461] <TB0> INFO: start marker: 0
[12:59:11.461] <TB0> INFO: stop marker: 0
[12:59:11.461] <TB0> INFO: overflow: 0
[12:59:11.461] <TB0> INFO: invalid 5bit words: 0
[12:59:11.461] <TB0> INFO: invalid XOR eye diagram: 0
[12:59:11.461] <TB0> INFO: frame (failed synchr.): 0
[12:59:11.461] <TB0> INFO: idle data (no TBM trl): 0
[12:59:11.461] <TB0> INFO: no data (only TBM hdr): 0
[12:59:11.461] <TB0> INFO: TBM errors: 0
[12:59:11.461] <TB0> INFO: flawed TBM headers: 0
[12:59:11.461] <TB0> INFO: flawed TBM trailers: 0
[12:59:11.461] <TB0> INFO: event ID mismatches: 0
[12:59:11.461] <TB0> INFO: ROC errors: 0
[12:59:11.461] <TB0> INFO: missing ROC header(s): 0
[12:59:11.461] <TB0> INFO: misplaced readback start: 0
[12:59:11.461] <TB0> INFO: Pixel decoding errors: 0
[12:59:11.461] <TB0> INFO: pixel data incomplete: 0
[12:59:11.461] <TB0> INFO: pixel address: 0
[12:59:11.461] <TB0> INFO: pulse height fill bit: 0
[12:59:11.461] <TB0> INFO: buffer corruption: 0
[12:59:11.539] <TB0> INFO: ######################################################################
[12:59:11.539] <TB0> INFO: PixTestScurves::fullTest() ntrig = 50, dacs/step = -1, ntrig/step = -1
[12:59:11.539] <TB0> INFO: ######################################################################
[12:59:11.539] <TB0> INFO: ----------------------------------------------------------------------
[12:59:11.539] <TB0> INFO: PixTestScurves::scurves(Vcal), ntrig = 50, dacs/step = -1, ntrig/step = -1
[12:59:11.539] <TB0> INFO: ----------------------------------------------------------------------
[12:59:11.540] <TB0> INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 25 .. 200 (-1/-1) hits flags = 528 (plus default)
[12:59:11.548] <TB0> INFO: dacScan split into 1 runs with ntrig = 50
[12:59:11.548] <TB0> INFO: run 1 of 1
[12:59:11.818] <TB0> INFO: Expecting 36608000 events.
[13:00:51.827] <TB0> INFO: 816100 events read in total (99453ms).
[13:02:31.366] <TB0> INFO: 1618250 events read in total (198992ms).
[13:04:10.495] <TB0> INFO: 2419000 events read in total (298121ms).
[13:05:49.381] <TB0> INFO: 3218600 events read in total (397007ms).
[13:07:28.599] <TB0> INFO: 4019350 events read in total (496225ms).
[13:09:07.994] <TB0> INFO: 4821050 events read in total (595620ms).
[13:10:45.974] <TB0> INFO: 5620600 events read in total (693600ms).
[13:12:25.268] <TB0> INFO: 6423300 events read in total (792894ms).
[13:14:04.553] <TB0> INFO: 7222150 events read in total (892179ms).
[13:15:43.763] <TB0> INFO: 8022800 events read in total (991389ms).
[13:17:23.166] <TB0> INFO: 8823000 events read in total (1090792ms).
[13:19:02.123] <TB0> INFO: 9622700 events read in total (1189749ms).
[13:20:41.802] <TB0> INFO: 10423200 events read in total (1289428ms).
[13:22:20.901] <TB0> INFO: 11222950 events read in total (1388527ms).
[13:24:00.911] <TB0> INFO: 12024250 events read in total (1488537ms).
[13:25:40.051] <TB0> INFO: 12824550 events read in total (1587677ms).
[13:27:19.044] <TB0> INFO: 13623950 events read in total (1686670ms).
[13:28:58.315] <TB0> INFO: 14422450 events read in total (1785941ms).
[13:30:37.794] <TB0> INFO: 15221950 events read in total (1885420ms).
[13:32:17.038] <TB0> INFO: 16021350 events read in total (1984664ms).
[13:33:56.698] <TB0> INFO: 16821050 events read in total (2084324ms).
[13:35:35.890] <TB0> INFO: 17621350 events read in total (2183516ms).
[13:37:15.118] <TB0> INFO: 18417000 events read in total (2282744ms).
[13:38:54.373] <TB0> INFO: 19209350 events read in total (2381999ms).
[13:40:32.897] <TB0> INFO: 20000050 events read in total (2480523ms).
[13:42:12.082] <TB0> INFO: 20792750 events read in total (2579708ms).
[13:43:51.325] <TB0> INFO: 21586250 events read in total (2678951ms).
[13:45:30.630] <TB0> INFO: 22377250 events read in total (2778256ms).
[13:47:10.062] <TB0> INFO: 23169300 events read in total (2877688ms).
[13:48:49.411] <TB0> INFO: 23960400 events read in total (2977037ms).
[13:50:28.392] <TB0> INFO: 24752650 events read in total (3076018ms).
[13:52:07.489] <TB0> INFO: 25543450 events read in total (3175115ms).
[13:53:47.080] <TB0> INFO: 26335000 events read in total (3274706ms).
[13:55:26.638] <TB0> INFO: 27125400 events read in total (3374264ms).
[13:57:05.748] <TB0> INFO: 27916300 events read in total (3473374ms).
[13:58:44.876] <TB0> INFO: 28706450 events read in total (3572502ms).
[14:00:24.111] <TB0> INFO: 29496200 events read in total (3671737ms).
[14:02:03.443] <TB0> INFO: 30289000 events read in total (3771069ms).
[14:03:42.270] <TB0> INFO: 31080050 events read in total (3869896ms).
[14:05:21.166] <TB0> INFO: 31871400 events read in total (3968792ms).
[14:06:59.779] <TB0> INFO: 32662500 events read in total (4067405ms).
[14:08:39.144] <TB0> INFO: 33454700 events read in total (4166770ms).
[14:10:17.624] <TB0> INFO: 34246600 events read in total (4265250ms).
[14:11:56.316] <TB0> INFO: 35038700 events read in total (4363942ms).
[14:13:35.840] <TB0> INFO: 35832600 events read in total (4463466ms).
[14:15:11.034] <TB0> INFO: 36608000 events read in total (4558660ms).
[14:15:11.094] <TB0> INFO: Test took 4559545ms.
[14:15:11.491] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[14:15:13.252] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[14:15:14.966] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[14:15:16.722] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[14:15:18.487] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[14:15:20.242] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[14:15:21.967] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[14:15:23.725] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[14:15:25.459] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[14:15:27.224] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[14:15:28.977] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[14:15:30.695] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[14:15:32.426] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[14:15:34.108] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[14:15:35.734] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[14:15:37.428] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[14:15:39.194] <TB0> INFO: PixTestScurves::scurves() done
[14:15:39.194] <TB0> INFO: Vcal mean: 84.82 74.94 83.39 87.14 86.42 85.39 87.98 73.99 74.55 73.31 94.33 92.55 93.86 84.43 90.35 100.18
[14:15:39.194] <TB0> INFO: Vcal RMS: 4.45 3.80 4.85 5.53 4.88 4.53 4.81 4.48 3.98 4.50 5.49 5.91 5.46 4.38 5.38 5.55
[14:15:39.194] <TB0> INFO: PixTestScurves::fullTest() done, duration: 4587 seconds
[14:15:39.194] <TB0> INFO: Decoding statistics:
[14:15:39.194] <TB0> INFO: General information:
[14:15:39.194] <TB0> INFO: 16bit words read: 0
[14:15:39.194] <TB0> INFO: valid events total: 0
[14:15:39.194] <TB0> INFO: empty events: 0
[14:15:39.194] <TB0> INFO: valid events with pixels: 0
[14:15:39.194] <TB0> INFO: valid pixel hits: 0
[14:15:39.194] <TB0> INFO: Event errors: 0
[14:15:39.194] <TB0> INFO: start marker: 0
[14:15:39.194] <TB0> INFO: stop marker: 0
[14:15:39.194] <TB0> INFO: overflow: 0
[14:15:39.194] <TB0> INFO: invalid 5bit words: 0
[14:15:39.195] <TB0> INFO: invalid XOR eye diagram: 0
[14:15:39.195] <TB0> INFO: frame (failed synchr.): 0
[14:15:39.195] <TB0> INFO: idle data (no TBM trl): 0
[14:15:39.195] <TB0> INFO: no data (only TBM hdr): 0
[14:15:39.195] <TB0> INFO: TBM errors: 0
[14:15:39.195] <TB0> INFO: flawed TBM headers: 0
[14:15:39.195] <TB0> INFO: flawed TBM trailers: 0
[14:15:39.195] <TB0> INFO: event ID mismatches: 0
[14:15:39.195] <TB0> INFO: ROC errors: 0
[14:15:39.195] <TB0> INFO: missing ROC header(s): 0
[14:15:39.195] <TB0> INFO: misplaced readback start: 0
[14:15:39.195] <TB0> INFO: Pixel decoding errors: 0
[14:15:39.195] <TB0> INFO: pixel data incomplete: 0
[14:15:39.195] <TB0> INFO: pixel address: 0
[14:15:39.195] <TB0> INFO: pulse height fill bit: 0
[14:15:39.195] <TB0> INFO: buffer corruption: 0
[14:15:39.265] <TB0> INFO: ######################################################################
[14:15:39.265] <TB0> INFO: PixTestTrim::doTest()
[14:15:39.265] <TB0> INFO: ######################################################################
[14:15:39.266] <TB0> INFO: ----------------------------------------------------------------------
[14:15:39.266] <TB0> INFO: PixTestTrim::trimTest() ntrig = 10, vcal = 35
[14:15:39.266] <TB0> INFO: ----------------------------------------------------------------------
[14:15:39.344] <TB0> INFO: ---> VthrComp thr map (minimal VthrComp)
[14:15:39.344] <TB0> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 10 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[14:15:39.352] <TB0> INFO: dacScan split into 1 runs with ntrig = 10
[14:15:39.352] <TB0> INFO: run 1 of 1
[14:15:39.612] <TB0> INFO: Expecting 6281600 events.
[14:17:27.670] <TB0> INFO: 1096040 events read in total (107501ms).
[14:19:15.462] <TB0> INFO: 2186770 events read in total (215293ms).
[14:21:04.768] <TB0> INFO: 3271600 events read in total (324600ms).
[14:22:54.024] <TB0> INFO: 4362800 events read in total (433855ms).
[14:24:43.575] <TB0> INFO: 5458010 events read in total (543406ms).
[14:26:05.564] <TB0> INFO: 6281600 events read in total (625395ms).
[14:26:05.617] <TB0> INFO: Test took 626266ms.
[14:26:24.632] <TB0> INFO: ROC 0 VthrComp = 92
[14:26:24.632] <TB0> INFO: ROC 1 VthrComp = 84
[14:26:24.632] <TB0> INFO: ROC 2 VthrComp = 89
[14:26:24.632] <TB0> INFO: ROC 3 VthrComp = 93
[14:26:24.632] <TB0> INFO: ROC 4 VthrComp = 93
[14:26:24.632] <TB0> INFO: ROC 5 VthrComp = 96
[14:26:24.632] <TB0> INFO: ROC 6 VthrComp = 95
[14:26:24.632] <TB0> INFO: ROC 7 VthrComp = 78
[14:26:24.632] <TB0> INFO: ROC 8 VthrComp = 83
[14:26:24.632] <TB0> INFO: ROC 9 VthrComp = 79
[14:26:24.633] <TB0> INFO: ROC 10 VthrComp = 100
[14:26:24.633] <TB0> INFO: ROC 11 VthrComp = 95
[14:26:24.633] <TB0> INFO: ROC 12 VthrComp = 97
[14:26:24.633] <TB0> INFO: ROC 13 VthrComp = 96
[14:26:24.633] <TB0> INFO: ROC 14 VthrComp = 95
[14:26:24.633] <TB0> INFO: ROC 15 VthrComp = 103
[14:26:24.633] <TB0> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[14:26:24.645] <TB0> INFO: ---> dac: vcal name: TrimThr1 ntrig: 10 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[14:26:24.653] <TB0> INFO: dacScan split into 1 runs with ntrig = 10
[14:26:24.654] <TB0> INFO: run 1 of 1
[14:26:24.913] <TB0> INFO: Expecting 6281600 events.
[14:28:08.895] <TB0> INFO: 758810 events read in total (103426ms).
[14:29:51.548] <TB0> INFO: 1515170 events read in total (206079ms).
[14:31:33.940] <TB0> INFO: 2271980 events read in total (308471ms).
[14:32:12.013] <TB0> CRITICAL: <USBInterface.libftd2xx.cc/FillBuffer:L266> Requested to read 3599b, but read 0b - 3599b missing!
[14:32:12.013] <TB0> CRITICAL: <USBInterface.libftd2xx.cc/FillBuffer:L273> FTD2XX error occured: io error