Test Date: 2016-10-20 09:44
Analysis date: 2016-10-20 16:46
Logfile
LogfileView
[10:37:23.107] <TB3> INFO: *** Welcome to pxar ***
[10:37:23.107] <TB3> INFO: *** Today: 2016/10/20
[10:37:23.114] <TB3> INFO: *** Version: c8ba-dirty
[10:37:23.114] <TB3> INFO: readRocDacs: /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters_C15.dat
[10:37:23.114] <TB3> INFO: readTbmDacs: /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//tbmParameters_C0a.dat .. /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//tbmParameters_C1b.dat
[10:37:23.114] <TB3> INFO: readMaskFile: /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//defaultMaskFile.dat
[10:37:23.114] <TB3> INFO: readTrimFile: /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//trimParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//trimParameters_C15.dat
[10:37:23.175] <TB3> INFO: clk: 4
[10:37:23.175] <TB3> INFO: ctr: 4
[10:37:23.175] <TB3> INFO: sda: 19
[10:37:23.175] <TB3> INFO: tin: 9
[10:37:23.175] <TB3> INFO: level: 15
[10:37:23.175] <TB3> INFO: triggerdelay: 0
[10:37:23.175] <TB3> QUIET: Instanciating API for pxar v2.7.6+55~gafdbfd9
[10:37:23.175] <TB3> INFO: Log level: INFO
[10:37:23.184] <TB3> INFO: Found DTB DTB_WWVASW
[10:37:23.192] <TB3> QUIET: Connection to board DTB_WWVASW opened.
[10:37:23.194] <TB3> INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 126
HW version: DTB1.2
FW version: 4.6
SW version: 4.7
Options:
USB id: DTB_WWVASW
MAC address: 40D85511807E
Hostname: pixelDTB126
Comment:
------------------------------------------------------
[10:37:23.196] <TB3> INFO: RPC call hashes of host and DTB match: 486171790
[10:37:24.689] <TB3> INFO: DUT info:
[10:37:24.689] <TB3> INFO: The DUT currently contains the following objects:
[10:37:24.689] <TB3> INFO: 4 TBM Cores tbm10c (4 ON)
[10:37:24.689] <TB3> INFO: TBM Core alpha (0): 7 registers set
[10:37:24.690] <TB3> INFO: TBM Core beta (1): 7 registers set
[10:37:24.690] <TB3> INFO: TBM Core alpha (2): 7 registers set
[10:37:24.690] <TB3> INFO: TBM Core beta (3): 7 registers set
[10:37:24.690] <TB3> INFO: 16 ROCs proc600 (16 ON) with 4160 pixelConfigs
[10:37:24.690] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[10:37:24.690] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[10:37:24.690] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[10:37:24.690] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[10:37:24.690] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[10:37:24.690] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[10:37:24.690] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[10:37:24.690] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[10:37:24.690] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[10:37:24.690] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[10:37:24.690] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[10:37:24.690] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[10:37:24.690] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[10:37:24.690] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[10:37:24.690] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[10:37:24.690] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[10:37:25.092] <TB3> INFO: enter 'restricted' command line mode
[10:37:25.092] <TB3> INFO: enter test to run
[10:37:25.092] <TB3> INFO: test: pretest no parameter change
[10:37:25.092] <TB3> INFO: running: pretest
[10:37:25.099] <TB3> INFO: ######################################################################
[10:37:25.099] <TB3> INFO: PixTestPretest::doTest()
[10:37:25.099] <TB3> INFO: ######################################################################
[10:37:25.100] <TB3> INFO: ----------------------------------------------------------------------
[10:37:25.100] <TB3> INFO: PixTestPretest::programROC()
[10:37:25.100] <TB3> INFO: ----------------------------------------------------------------------
[10:37:43.115] <TB3> INFO: PixTestPretest::programROC() done: ROCs are all programmable
[10:37:43.115] <TB3> INFO: IA differences per ROC: 20.1 17.7 16.9 18.5 16.9 21.7 19.3 19.3 18.5 20.9 20.9 16.9 21.7 19.3 16.9 18.5
[10:37:43.181] <TB3> INFO: ----------------------------------------------------------------------
[10:37:43.181] <TB3> INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[10:37:43.181] <TB3> INFO: ----------------------------------------------------------------------
[10:38:04.480] <TB3> INFO: PixTestPretest::setVana() done, Module Ia 387.5 mA = 24.2188 mA/ROC
[10:38:04.480] <TB3> INFO: i(loss) [mA/ROC]: 19.3 20.1 19.3 20.1 19.3 20.1 19.3 20.9 20.9 20.1 20.1 20.1 20.9 19.3 18.5 19.3
[10:38:04.514] <TB3> INFO: ----------------------------------------------------------------------
[10:38:04.514] <TB3> INFO: PixTestPretest::findTiming()
[10:38:04.514] <TB3> INFO: ----------------------------------------------------------------------
[10:38:04.514] <TB3> INFO: PixTestCmd::init()
[10:38:05.093] <TB3> WARNING: Not unmasking DUT, not setting Calibrate bits!

[10:38:36.660] <TB3> INFO: TBM phases: 160MHz: 0, 400MHz: 6, TBM delays: ROC(0/1):5, header/trailer: 1, token: 1
[10:38:36.660] <TB3> INFO: (success/tries = 100/100), width = 3
[10:38:38.159] <TB3> INFO: ----------------------------------------------------------------------
[10:38:38.159] <TB3> INFO: PixTestPretest::findWorkingPixel()
[10:38:38.159] <TB3> INFO: ----------------------------------------------------------------------
[10:38:38.252] <TB3> INFO: Expecting 231680 events.
[10:38:48.156] <TB3> INFO: 231680 events read in total (9313ms).
[10:38:48.165] <TB3> INFO: Test took 10003ms.
[10:38:48.411] <TB3> INFO: Found working pixel in all ROCs: col/row = 12/22
[10:38:48.443] <TB3> INFO: ----------------------------------------------------------------------
[10:38:48.443] <TB3> INFO: PixTestPretest::setVthrCompCalDel()
[10:38:48.443] <TB3> INFO: ----------------------------------------------------------------------
[10:38:48.537] <TB3> INFO: Expecting 231680 events.
[10:38:58.556] <TB3> INFO: 231680 events read in total (9428ms).
[10:38:58.566] <TB3> INFO: Test took 10118ms.
[10:38:58.818] <TB3> INFO: PixTestPretest::setVthrCompCalDel() done
[10:38:58.818] <TB3> INFO: CalDel: 105 111 113 94 100 103 89 96 109 103 119 106 85 106 98 91
[10:38:58.818] <TB3> INFO: VthrComp: 51 52 51 51 52 51 51 52 53 52 51 51 51 51 51 51
[10:38:58.820] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters_C0.dat
[10:38:58.820] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters_C1.dat
[10:38:58.821] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters_C2.dat
[10:38:58.821] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters_C3.dat
[10:38:58.821] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters_C4.dat
[10:38:58.821] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters_C5.dat
[10:38:58.821] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters_C6.dat
[10:38:58.821] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters_C7.dat
[10:38:58.821] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters_C8.dat
[10:38:58.821] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters_C9.dat
[10:38:58.821] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters_C10.dat
[10:38:58.821] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters_C11.dat
[10:38:58.822] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters_C12.dat
[10:38:58.822] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters_C13.dat
[10:38:58.822] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters_C14.dat
[10:38:58.822] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters_C15.dat
[10:38:58.822] <TB3> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//tbmParameters_C0a.dat
[10:38:58.822] <TB3> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//tbmParameters_C0b.dat
[10:38:58.822] <TB3> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//tbmParameters_C1a.dat
[10:38:58.822] <TB3> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//tbmParameters_C1b.dat
[10:38:58.822] <TB3> INFO: PixTestPretest::doTest() done, duration: 93 seconds
[10:38:58.873] <TB3> INFO: enter test to run
[10:38:58.873] <TB3> INFO: test: FullTest no parameter change
[10:38:58.873] <TB3> INFO: running: fulltest
[10:38:58.873] <TB3> INFO: ######################################################################
[10:38:58.873] <TB3> INFO: PixTestFullTest::doTest()
[10:38:58.873] <TB3> INFO: ######################################################################
[10:38:58.875] <TB3> INFO: ######################################################################
[10:38:58.875] <TB3> INFO: PixTestAlive::doTest()
[10:38:58.875] <TB3> INFO: ######################################################################
[10:38:58.876] <TB3> INFO: ----------------------------------------------------------------------
[10:38:58.876] <TB3> INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[10:38:58.876] <TB3> INFO: ----------------------------------------------------------------------
[10:38:59.116] <TB3> INFO: Expecting 41600 events.
[10:39:02.743] <TB3> INFO: 41600 events read in total (3035ms).
[10:39:02.744] <TB3> INFO: Test took 3866ms.
[10:39:02.978] <TB3> INFO: PixTestAlive::aliveTest() done
[10:39:02.978] <TB3> INFO: number of dead pixels (per ROC): 0 0 2 0 1 0 0 0 0 0 0 0 0 2 0 0
[10:39:02.979] <TB3> INFO: ----------------------------------------------------------------------
[10:39:02.980] <TB3> INFO: PixTestAlive::maskTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[10:39:02.980] <TB3> INFO: ----------------------------------------------------------------------
[10:39:03.226] <TB3> INFO: Expecting 41600 events.
[10:39:06.215] <TB3> INFO: 41600 events read in total (2397ms).
[10:39:06.216] <TB3> INFO: Test took 3235ms.
[10:39:06.216] <TB3> INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[10:39:06.459] <TB3> INFO: PixTestAlive::maskTest() done
[10:39:06.459] <TB3> INFO: number of mask-defect pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[10:39:06.460] <TB3> INFO: ----------------------------------------------------------------------
[10:39:06.460] <TB3> INFO: PixTestAlive::addressDecodingTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[10:39:06.460] <TB3> INFO: ----------------------------------------------------------------------
[10:39:06.706] <TB3> INFO: Expecting 41600 events.
[10:39:10.350] <TB3> INFO: 41600 events read in total (3052ms).
[10:39:10.351] <TB3> INFO: Test took 3889ms.
[10:39:10.591] <TB3> INFO: PixTestAlive::addressDecodingTest() done
[10:39:10.591] <TB3> INFO: number of address-decoding pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[10:39:10.591] <TB3> INFO: PixTestAlive::doTest() done, duration: 11 seconds
[10:39:10.592] <TB3> INFO: Decoding statistics:
[10:39:10.592] <TB3> INFO: General information:
[10:39:10.592] <TB3> INFO: 16bit words read: 0
[10:39:10.592] <TB3> INFO: valid events total: 0
[10:39:10.592] <TB3> INFO: empty events: 0
[10:39:10.592] <TB3> INFO: valid events with pixels: 0
[10:39:10.592] <TB3> INFO: valid pixel hits: 0
[10:39:10.592] <TB3> INFO: Event errors: 0
[10:39:10.592] <TB3> INFO: start marker: 0
[10:39:10.592] <TB3> INFO: stop marker: 0
[10:39:10.592] <TB3> INFO: overflow: 0
[10:39:10.592] <TB3> INFO: invalid 5bit words: 0
[10:39:10.592] <TB3> INFO: invalid XOR eye diagram: 0
[10:39:10.592] <TB3> INFO: frame (failed synchr.): 0
[10:39:10.592] <TB3> INFO: idle data (no TBM trl): 0
[10:39:10.592] <TB3> INFO: no data (only TBM hdr): 0
[10:39:10.592] <TB3> INFO: TBM errors: 0
[10:39:10.592] <TB3> INFO: flawed TBM headers: 0
[10:39:10.592] <TB3> INFO: flawed TBM trailers: 0
[10:39:10.592] <TB3> INFO: event ID mismatches: 0
[10:39:10.592] <TB3> INFO: ROC errors: 0
[10:39:10.592] <TB3> INFO: missing ROC header(s): 0
[10:39:10.592] <TB3> INFO: misplaced readback start: 0
[10:39:10.592] <TB3> INFO: Pixel decoding errors: 0
[10:39:10.592] <TB3> INFO: pixel data incomplete: 0
[10:39:10.592] <TB3> INFO: pixel address: 0
[10:39:10.592] <TB3> INFO: pulse height fill bit: 0
[10:39:10.592] <TB3> INFO: buffer corruption: 0
[10:39:10.598] <TB3> INFO: readReadbackCal: /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C0.dat .. /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C15.dat
[10:39:10.598] <TB3> INFO: readGainPedestalParameters /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//phCalibrationFitErr_C0.dat .. /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//phCalibrationFitErr_C15.dat
[10:39:10.598] <TB3> ERROR: <ConfigParameters.cc/readGainPedestalParameters:L1005> cannot open /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//phCalibrationFitErr_C0.dat for reading PH calibration constants

[10:39:10.598] <TB3> INFO: ######################################################################
[10:39:10.598] <TB3> INFO: PixTestReadback::doTest()
[10:39:10.598] <TB3> INFO: ######################################################################
[10:39:10.598] <TB3> INFO: ----------------------------------------------------------------------
[10:39:10.598] <TB3> INFO: PixTestReadback::CalibrateVd()
[10:39:10.598] <TB3> INFO: ----------------------------------------------------------------------
[10:39:20.586] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C0.dat
[10:39:20.586] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C1.dat
[10:39:20.586] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C2.dat
[10:39:20.586] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C3.dat
[10:39:20.586] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C4.dat
[10:39:20.586] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C5.dat
[10:39:20.586] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C6.dat
[10:39:20.586] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C7.dat
[10:39:20.586] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C8.dat
[10:39:20.586] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C9.dat
[10:39:20.587] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C10.dat
[10:39:20.587] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C11.dat
[10:39:20.587] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C12.dat
[10:39:20.587] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C13.dat
[10:39:20.587] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C14.dat
[10:39:20.587] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C15.dat
[10:39:20.615] <TB3> INFO: PixTestPattern:: pg_setup set to default.
[10:39:20.615] <TB3> INFO: ----------------------------------------------------------------------
[10:39:20.615] <TB3> INFO: PixTestReadback::CalibrateVa()
[10:39:20.615] <TB3> INFO: ----------------------------------------------------------------------
[10:39:30.555] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C0.dat
[10:39:30.555] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C1.dat
[10:39:30.555] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C2.dat
[10:39:30.555] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C3.dat
[10:39:30.555] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C4.dat
[10:39:30.555] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C5.dat
[10:39:30.555] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C6.dat
[10:39:30.555] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C7.dat
[10:39:30.556] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C8.dat
[10:39:30.556] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C9.dat
[10:39:30.556] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C10.dat
[10:39:30.556] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C11.dat
[10:39:30.556] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C12.dat
[10:39:30.556] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C13.dat
[10:39:30.556] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C14.dat
[10:39:30.556] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C15.dat
[10:39:30.587] <TB3> INFO: PixTestPattern:: pg_setup set to default.
[10:39:30.588] <TB3> INFO: ----------------------------------------------------------------------
[10:39:30.588] <TB3> INFO: PixTestReadback::readbackVbg()
[10:39:30.588] <TB3> INFO: ----------------------------------------------------------------------
[10:39:38.266] <TB3> INFO: PixTestPattern:: pg_setup set to default.
[10:39:38.267] <TB3> INFO: ----------------------------------------------------------------------
[10:39:38.267] <TB3> INFO: PixTestReadback::getCalibratedVbg()
[10:39:38.267] <TB3> INFO: ----------------------------------------------------------------------
[10:39:38.267] <TB3> INFO: Vbg will be calibrated using Vd calibration
[10:39:38.267] <TB3> INFO: /*/*/*/*::: ROC 0: uncalibrated Vbg = 150.2calibrated Vbg = 1.19524 :::*/*/*/*/
[10:39:38.267] <TB3> INFO: /*/*/*/*::: ROC 1: uncalibrated Vbg = 157calibrated Vbg = 1.1905 :::*/*/*/*/
[10:39:38.267] <TB3> INFO: /*/*/*/*::: ROC 2: uncalibrated Vbg = 158.3calibrated Vbg = 1.18574 :::*/*/*/*/
[10:39:38.267] <TB3> INFO: /*/*/*/*::: ROC 3: uncalibrated Vbg = 157.2calibrated Vbg = 1.18943 :::*/*/*/*/
[10:39:38.267] <TB3> INFO: /*/*/*/*::: ROC 4: uncalibrated Vbg = 161.6calibrated Vbg = 1.1902 :::*/*/*/*/
[10:39:38.267] <TB3> INFO: /*/*/*/*::: ROC 5: uncalibrated Vbg = 165.7calibrated Vbg = 1.19751 :::*/*/*/*/
[10:39:38.267] <TB3> INFO: /*/*/*/*::: ROC 6: uncalibrated Vbg = 153.6calibrated Vbg = 1.19255 :::*/*/*/*/
[10:39:38.267] <TB3> INFO: /*/*/*/*::: ROC 7: uncalibrated Vbg = 161calibrated Vbg = 1.19794 :::*/*/*/*/
[10:39:38.267] <TB3> INFO: /*/*/*/*::: ROC 8: uncalibrated Vbg = 158.7calibrated Vbg = 1.19024 :::*/*/*/*/
[10:39:38.267] <TB3> INFO: /*/*/*/*::: ROC 9: uncalibrated Vbg = 159calibrated Vbg = 1.18865 :::*/*/*/*/
[10:39:38.267] <TB3> INFO: /*/*/*/*::: ROC 10: uncalibrated Vbg = 157calibrated Vbg = 1.18677 :::*/*/*/*/
[10:39:38.267] <TB3> INFO: /*/*/*/*::: ROC 11: uncalibrated Vbg = 153.2calibrated Vbg = 1.17913 :::*/*/*/*/
[10:39:38.267] <TB3> INFO: /*/*/*/*::: ROC 12: uncalibrated Vbg = 159calibrated Vbg = 1.18752 :::*/*/*/*/
[10:39:38.267] <TB3> INFO: /*/*/*/*::: ROC 13: uncalibrated Vbg = 157.8calibrated Vbg = 1.18595 :::*/*/*/*/
[10:39:38.267] <TB3> INFO: /*/*/*/*::: ROC 14: uncalibrated Vbg = 144.1calibrated Vbg = 1.19075 :::*/*/*/*/
[10:39:38.267] <TB3> INFO: /*/*/*/*::: ROC 15: uncalibrated Vbg = 152.9calibrated Vbg = 1.18654 :::*/*/*/*/
[10:39:38.270] <TB3> INFO: ----------------------------------------------------------------------
[10:39:38.271] <TB3> INFO: PixTestReadback::CalibrateIa()
[10:39:38.271] <TB3> INFO: ----------------------------------------------------------------------
[10:42:19.058] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C0.dat
[10:42:19.058] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C1.dat
[10:42:19.058] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C2.dat
[10:42:19.058] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C3.dat
[10:42:19.058] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C4.dat
[10:42:19.058] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C5.dat
[10:42:19.058] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C6.dat
[10:42:19.058] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C7.dat
[10:42:19.058] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C8.dat
[10:42:19.058] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C9.dat
[10:42:19.058] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C10.dat
[10:42:19.059] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C11.dat
[10:42:19.059] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C12.dat
[10:42:19.059] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C13.dat
[10:42:19.059] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C14.dat
[10:42:19.059] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C15.dat
[10:42:19.085] <TB3> INFO: PixTestPattern:: pg_setup set to default.
[10:42:19.087] <TB3> INFO: PixTestReadback::doTest() done
[10:42:19.087] <TB3> INFO: Decoding statistics:
[10:42:19.087] <TB3> INFO: General information:
[10:42:19.088] <TB3> INFO: 16bit words read: 1536
[10:42:19.088] <TB3> INFO: valid events total: 256
[10:42:19.088] <TB3> INFO: empty events: 256
[10:42:19.088] <TB3> INFO: valid events with pixels: 0
[10:42:19.088] <TB3> INFO: valid pixel hits: 0
[10:42:19.088] <TB3> INFO: Event errors: 0
[10:42:19.088] <TB3> INFO: start marker: 0
[10:42:19.088] <TB3> INFO: stop marker: 0
[10:42:19.088] <TB3> INFO: overflow: 0
[10:42:19.088] <TB3> INFO: invalid 5bit words: 0
[10:42:19.088] <TB3> INFO: invalid XOR eye diagram: 0
[10:42:19.088] <TB3> INFO: frame (failed synchr.): 0
[10:42:19.088] <TB3> INFO: idle data (no TBM trl): 0
[10:42:19.088] <TB3> INFO: no data (only TBM hdr): 0
[10:42:19.088] <TB3> INFO: TBM errors: 0
[10:42:19.088] <TB3> INFO: flawed TBM headers: 0
[10:42:19.088] <TB3> INFO: flawed TBM trailers: 0
[10:42:19.088] <TB3> INFO: event ID mismatches: 0
[10:42:19.088] <TB3> INFO: ROC errors: 0
[10:42:19.088] <TB3> INFO: missing ROC header(s): 0
[10:42:19.088] <TB3> INFO: misplaced readback start: 0
[10:42:19.088] <TB3> INFO: Pixel decoding errors: 0
[10:42:19.088] <TB3> INFO: pixel data incomplete: 0
[10:42:19.088] <TB3> INFO: pixel address: 0
[10:42:19.088] <TB3> INFO: pulse height fill bit: 0
[10:42:19.088] <TB3> INFO: buffer corruption: 0
[10:42:19.146] <TB3> INFO: ######################################################################
[10:42:19.146] <TB3> INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[10:42:19.146] <TB3> INFO: ######################################################################
[10:42:19.149] <TB3> INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (-1/-1) hits flags = 514 (plus default)
[10:42:19.162] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[10:42:19.162] <TB3> INFO: run 1 of 1
[10:42:19.399] <TB3> INFO: Expecting 3120000 events.
[10:42:50.972] <TB3> INFO: 668660 events read in total (30981ms).
[10:43:03.258] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (117) != TBM ID (129)

[10:43:03.397] <TB3> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 117 117 129 117 117 117 117 117

[10:43:03.397] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (118)

[10:43:03.397] <TB3> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[10:43:03.397] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a079 80c0 40c1 40c1 e022 c000

[10:43:03.397] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a073 8040 40c0 40c1 e022 c000

[10:43:03.397] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a074 80b1 40c0 40c0 e022 c000

[10:43:03.397] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 40c1 40c1 27ef 40c0 e022 c000

[10:43:03.397] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a076 8000 40c0 40c0 e022 c000

[10:43:03.397] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a077 8040 40c0 40c0 e022 c000

[10:43:03.397] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a078 80b1 40c0 40c0 e022 c000

[10:43:21.287] <TB3> INFO: 1337635 events read in total (61296ms).
[10:43:33.536] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (164) != TBM ID (129)

[10:43:33.669] <TB3> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 164 164 129 164 164 164 164 164

[10:43:33.669] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (165)

[10:43:33.670] <TB3> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[10:43:33.670] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0a8 80b1 40c0 40c0 e022 c000

[10:43:33.670] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0a2 8000 40c0 40c0 e022 c000

[10:43:33.670] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0a3 8040 40c0 40c1 e022 c000

[10:43:33.670] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 40c1 40c1 2fef 40c0 e022 c000

[10:43:33.670] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0a5 80c0 40c0 40c0 e022 c000

[10:43:33.670] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0a6 8000 40c0 40c0 e022 c000

[10:43:33.670] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0a7 8040 40c0 40c0 e022 c000

[10:43:51.939] <TB3> INFO: 2003885 events read in total (91948ms).
[10:44:04.239] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (46) != TBM ID (129)

[10:44:04.379] <TB3> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 46 46 129 46 46 46 46 46

[10:44:04.379] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (47)

[10:44:04.379] <TB3> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[10:44:04.379] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a032 8000 40c0 826 2fef 40c0 826 2fef e022 c000

[10:44:04.379] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a02c 80b1 40c1 826 2fef 40c1 826 2fef e022 c000

[10:44:04.379] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a02d 80c0 40c1 826 2fef 40c1 826 2fef e022 c000

[10:44:04.379] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 40c1 40c1 2fef 40c0 826 2fef e022 c000

[10:44:04.379] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a02f 8040 40c2 826 2fef 40c2 826 2fef e022 c000

[10:44:04.379] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a030 80b1 40c0 826 2fef 40c0 826 2fef e022 c000

[10:44:04.379] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a031 80c0 40c1 826 2fef 40c1 826 2fef e022 c000

[10:44:22.207] <TB3> INFO: 2672120 events read in total (122216ms).
[10:44:30.541] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (121) != TBM ID (129)

[10:44:30.680] <TB3> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 121 121 129 121 121 121 121 121

[10:44:30.680] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (122)

[10:44:30.680] <TB3> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[10:44:30.680] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a07d 80c0 40c0 a8a 25ef 40c0 a8a 25cd e022 c000

[10:44:30.680] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a077 8040 40c0 a8a 25ef 40c0 a8a 25cd e022 c000

[10:44:30.680] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a078 80b1 40c0 a8a 25ef 40c0 a8a 25cb e022 c000

[10:44:30.680] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 40c1 40c1 25ef 40c1 a8a 25cd e022 c000

[10:44:30.680] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a07a 8000 40c1 a8a 25ef 40c1 a8a 25cd e022 c000

[10:44:30.680] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a07b 8040 40c1 a8a 25ef 40c1 a8a 25cc e022 c000

[10:44:30.680] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a07c 80b1 40c1 a8a 25ef 40c1 a8a 25cc e022 c000

[10:44:43.073] <TB3> INFO: 3120000 events read in total (143082ms).
[10:44:43.157] <TB3> INFO: Test took 143995ms.
[10:45:05.431] <TB3> INFO: PixTestBBMap::doTest() done with 4 decoding errors: , duration: 166 seconds
[10:45:05.431] <TB3> INFO: number of dead bumps (per ROC): 5 1 1 0 4 0 3 0 0 1 0 0 0 3 0 0
[10:45:05.431] <TB3> INFO: separation cut (per ROC): 111 106 108 105 106 124 107 120 106 107 107 102 111 102 101 105
[10:45:05.431] <TB3> INFO: Decoding statistics:
[10:45:05.431] <TB3> INFO: General information:
[10:45:05.431] <TB3> INFO: 16bit words read: 0
[10:45:05.431] <TB3> INFO: valid events total: 0
[10:45:05.431] <TB3> INFO: empty events: 0
[10:45:05.431] <TB3> INFO: valid events with pixels: 0
[10:45:05.431] <TB3> INFO: valid pixel hits: 0
[10:45:05.431] <TB3> INFO: Event errors: 0
[10:45:05.431] <TB3> INFO: start marker: 0
[10:45:05.431] <TB3> INFO: stop marker: 0
[10:45:05.431] <TB3> INFO: overflow: 0
[10:45:05.431] <TB3> INFO: invalid 5bit words: 0
[10:45:05.431] <TB3> INFO: invalid XOR eye diagram: 0
[10:45:05.431] <TB3> INFO: frame (failed synchr.): 0
[10:45:05.431] <TB3> INFO: idle data (no TBM trl): 0
[10:45:05.431] <TB3> INFO: no data (only TBM hdr): 0
[10:45:05.431] <TB3> INFO: TBM errors: 0
[10:45:05.431] <TB3> INFO: flawed TBM headers: 0
[10:45:05.431] <TB3> INFO: flawed TBM trailers: 0
[10:45:05.431] <TB3> INFO: event ID mismatches: 0
[10:45:05.431] <TB3> INFO: ROC errors: 0
[10:45:05.431] <TB3> INFO: missing ROC header(s): 0
[10:45:05.431] <TB3> INFO: misplaced readback start: 0
[10:45:05.432] <TB3> INFO: Pixel decoding errors: 0
[10:45:05.432] <TB3> INFO: pixel data incomplete: 0
[10:45:05.432] <TB3> INFO: pixel address: 0
[10:45:05.432] <TB3> INFO: pulse height fill bit: 0
[10:45:05.432] <TB3> INFO: buffer corruption: 0
[10:45:05.469] <TB3> INFO: ######################################################################
[10:45:05.469] <TB3> INFO: PixTestScurves::fullTest() ntrig = 50, dacs/step = -1, ntrig/step = -1
[10:45:05.469] <TB3> INFO: ######################################################################
[10:45:05.469] <TB3> INFO: ----------------------------------------------------------------------
[10:45:05.469] <TB3> INFO: PixTestScurves::scurves(Vcal), ntrig = 50, dacs/step = -1, ntrig/step = -1
[10:45:05.469] <TB3> INFO: ----------------------------------------------------------------------
[10:45:05.469] <TB3> INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 25 .. 200 (-1/-1) hits flags = 528 (plus default)
[10:45:05.483] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[10:45:05.483] <TB3> INFO: run 1 of 1
[10:45:05.762] <TB3> INFO: Expecting 36608000 events.
[10:45:29.467] <TB3> INFO: 681450 events read in total (23113ms).
[10:45:52.343] <TB3> INFO: 1348050 events read in total (45989ms).
[10:46:15.242] <TB3> INFO: 2013300 events read in total (68888ms).
[10:46:38.131] <TB3> INFO: 2677900 events read in total (91777ms).
[10:47:00.966] <TB3> INFO: 3341950 events read in total (114612ms).
[10:47:23.715] <TB3> INFO: 4005800 events read in total (137361ms).
[10:47:46.705] <TB3> INFO: 4671150 events read in total (160351ms).
[10:48:09.880] <TB3> INFO: 5335050 events read in total (183526ms).
[10:48:32.868] <TB3> INFO: 5999500 events read in total (206514ms).
[10:48:55.598] <TB3> INFO: 6663750 events read in total (229244ms).
[10:49:18.640] <TB3> INFO: 7327150 events read in total (252286ms).
[10:49:41.425] <TB3> INFO: 7989950 events read in total (275071ms).
[10:50:04.154] <TB3> INFO: 8654050 events read in total (297800ms).
[10:50:27.026] <TB3> INFO: 9317850 events read in total (320672ms).
[10:50:50.099] <TB3> INFO: 9981100 events read in total (343745ms).
[10:51:13.008] <TB3> INFO: 10644850 events read in total (366654ms).
[10:51:36.136] <TB3> INFO: 11306850 events read in total (389782ms).
[10:51:58.878] <TB3> INFO: 11968500 events read in total (412524ms).
[10:52:21.692] <TB3> INFO: 12629050 events read in total (435338ms).
[10:52:44.692] <TB3> INFO: 13292900 events read in total (458338ms).
[10:53:07.537] <TB3> INFO: 13954950 events read in total (481183ms).
[10:53:30.728] <TB3> INFO: 14615400 events read in total (504374ms).
[10:53:53.804] <TB3> INFO: 15276150 events read in total (527450ms).
[10:54:16.538] <TB3> INFO: 15936500 events read in total (550184ms).
[10:54:39.555] <TB3> INFO: 16596700 events read in total (573201ms).
[10:55:02.295] <TB3> INFO: 17257650 events read in total (595941ms).
[10:55:25.047] <TB3> INFO: 17916800 events read in total (618693ms).
[10:55:48.106] <TB3> INFO: 18575800 events read in total (641752ms).
[10:56:11.025] <TB3> INFO: 19232450 events read in total (664671ms).
[10:56:33.601] <TB3> INFO: 19887400 events read in total (687247ms).
[10:56:56.461] <TB3> INFO: 20544900 events read in total (710107ms).
[10:57:19.412] <TB3> INFO: 21199250 events read in total (733058ms).
[10:57:42.430] <TB3> INFO: 21856600 events read in total (756076ms).
[10:58:05.331] <TB3> INFO: 22511950 events read in total (778977ms).
[10:58:28.377] <TB3> INFO: 23167500 events read in total (802023ms).
[10:58:51.174] <TB3> INFO: 23821450 events read in total (824820ms).
[10:59:13.935] <TB3> INFO: 24477950 events read in total (847581ms).
[10:59:36.673] <TB3> INFO: 25132450 events read in total (870319ms).
[10:59:59.507] <TB3> INFO: 25789450 events read in total (893153ms).
[11:00:22.111] <TB3> INFO: 26444650 events read in total (915757ms).
[11:00:44.761] <TB3> INFO: 27100350 events read in total (938407ms).
[11:01:07.411] <TB3> INFO: 27755000 events read in total (961057ms).
[11:01:30.028] <TB3> INFO: 28409350 events read in total (983674ms).
[11:01:52.595] <TB3> INFO: 29063850 events read in total (1006241ms).
[11:02:15.414] <TB3> INFO: 29717000 events read in total (1029060ms).
[11:02:38.215] <TB3> INFO: 30369600 events read in total (1051861ms).
[11:03:00.633] <TB3> INFO: 31021850 events read in total (1074279ms).
[11:03:23.440] <TB3> INFO: 31676200 events read in total (1097086ms).
[11:03:46.341] <TB3> INFO: 32327950 events read in total (1119987ms).
[11:04:09.052] <TB3> INFO: 32981700 events read in total (1142698ms).
[11:04:31.829] <TB3> INFO: 33637150 events read in total (1165475ms).
[11:04:54.602] <TB3> INFO: 34291850 events read in total (1188248ms).
[11:05:17.477] <TB3> INFO: 34947350 events read in total (1211123ms).
[11:05:40.713] <TB3> INFO: 35603500 events read in total (1234359ms).
[11:06:04.234] <TB3> INFO: 36265650 events read in total (1257880ms).
[11:06:16.613] <TB3> INFO: 36608000 events read in total (1270259ms).
[11:06:16.677] <TB3> INFO: Test took 1271194ms.
[11:06:17.118] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:06:19.101] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:06:20.954] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:06:22.000] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:06:24.836] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:06:26.478] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:06:28.674] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:06:30.720] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:06:32.391] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:06:33.927] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:06:35.465] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:06:36.984] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:06:38.462] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:06:39.988] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:06:41.513] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:06:43.028] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:06:44.667] <TB3> INFO: PixTestScurves::scurves() done
[11:06:44.667] <TB3> INFO: Vcal mean: 110.84 113.71 115.01 112.03 116.49 120.05 115.64 125.85 122.03 124.14 116.96 102.96 119.51 103.38 111.17 108.88
[11:06:44.667] <TB3> INFO: Vcal RMS: 5.59 5.48 6.54 4.88 6.00 5.52 5.74 5.64 6.99 6.52 6.27 5.28 5.95 5.61 5.20 4.84
[11:06:44.667] <TB3> INFO: PixTestScurves::fullTest() done, duration: 1299 seconds
[11:06:44.667] <TB3> INFO: Decoding statistics:
[11:06:44.667] <TB3> INFO: General information:
[11:06:44.667] <TB3> INFO: 16bit words read: 0
[11:06:44.667] <TB3> INFO: valid events total: 0
[11:06:44.667] <TB3> INFO: empty events: 0
[11:06:44.667] <TB3> INFO: valid events with pixels: 0
[11:06:44.667] <TB3> INFO: valid pixel hits: 0
[11:06:44.667] <TB3> INFO: Event errors: 0
[11:06:44.667] <TB3> INFO: start marker: 0
[11:06:44.667] <TB3> INFO: stop marker: 0
[11:06:44.667] <TB3> INFO: overflow: 0
[11:06:44.667] <TB3> INFO: invalid 5bit words: 0
[11:06:44.667] <TB3> INFO: invalid XOR eye diagram: 0
[11:06:44.667] <TB3> INFO: frame (failed synchr.): 0
[11:06:44.667] <TB3> INFO: idle data (no TBM trl): 0
[11:06:44.667] <TB3> INFO: no data (only TBM hdr): 0
[11:06:44.667] <TB3> INFO: TBM errors: 0
[11:06:44.667] <TB3> INFO: flawed TBM headers: 0
[11:06:44.667] <TB3> INFO: flawed TBM trailers: 0
[11:06:44.667] <TB3> INFO: event ID mismatches: 0
[11:06:44.667] <TB3> INFO: ROC errors: 0
[11:06:44.667] <TB3> INFO: missing ROC header(s): 0
[11:06:44.667] <TB3> INFO: misplaced readback start: 0
[11:06:44.667] <TB3> INFO: Pixel decoding errors: 0
[11:06:44.667] <TB3> INFO: pixel data incomplete: 0
[11:06:44.668] <TB3> INFO: pixel address: 0
[11:06:44.668] <TB3> INFO: pulse height fill bit: 0
[11:06:44.668] <TB3> INFO: buffer corruption: 0
[11:06:44.737] <TB3> INFO: ######################################################################
[11:06:44.737] <TB3> INFO: PixTestTrim::doTest()
[11:06:44.737] <TB3> INFO: ######################################################################
[11:06:44.738] <TB3> INFO: ----------------------------------------------------------------------
[11:06:44.738] <TB3> INFO: PixTestTrim::trimTest() ntrig = 8, vcal = 35
[11:06:44.739] <TB3> INFO: ----------------------------------------------------------------------
[11:06:44.786] <TB3> INFO: ---> VthrComp thr map (minimal VthrComp)
[11:06:44.786] <TB3> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[11:06:44.797] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[11:06:44.797] <TB3> INFO: run 1 of 1
[11:06:45.039] <TB3> INFO: Expecting 5025280 events.
[11:07:16.102] <TB3> INFO: 822320 events read in total (30464ms).
[11:07:46.528] <TB3> INFO: 1643376 events read in total (60891ms).
[11:08:16.868] <TB3> INFO: 2462296 events read in total (91230ms).
[11:08:46.955] <TB3> INFO: 3277440 events read in total (121317ms).
[11:09:16.980] <TB3> INFO: 4089296 events read in total (151343ms).
[11:09:47.412] <TB3> INFO: 4899272 events read in total (181774ms).
[11:09:52.518] <TB3> INFO: 5025280 events read in total (186880ms).
[11:09:52.578] <TB3> INFO: Test took 187782ms.
[11:10:10.156] <TB3> INFO: ROC 0 VthrComp = 117
[11:10:10.157] <TB3> INFO: ROC 1 VthrComp = 110
[11:10:10.157] <TB3> INFO: ROC 2 VthrComp = 113
[11:10:10.157] <TB3> INFO: ROC 3 VthrComp = 115
[11:10:10.157] <TB3> INFO: ROC 4 VthrComp = 111
[11:10:10.157] <TB3> INFO: ROC 5 VthrComp = 125
[11:10:10.157] <TB3> INFO: ROC 6 VthrComp = 119
[11:10:10.157] <TB3> INFO: ROC 7 VthrComp = 132
[11:10:10.157] <TB3> INFO: ROC 8 VthrComp = 128
[11:10:10.157] <TB3> INFO: ROC 9 VthrComp = 125
[11:10:10.158] <TB3> INFO: ROC 10 VthrComp = 117
[11:10:10.158] <TB3> INFO: ROC 11 VthrComp = 105
[11:10:10.158] <TB3> INFO: ROC 12 VthrComp = 127
[11:10:10.158] <TB3> INFO: ROC 13 VthrComp = 106
[11:10:10.158] <TB3> INFO: ROC 14 VthrComp = 112
[11:10:10.158] <TB3> INFO: ROC 15 VthrComp = 114
[11:10:10.397] <TB3> INFO: Expecting 41600 events.
[11:10:13.880] <TB3> INFO: 41600 events read in total (2892ms).
[11:10:13.881] <TB3> INFO: Test took 3721ms.
[11:10:13.892] <TB3> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[11:10:13.892] <TB3> INFO: ---> dac: vcal name: TrimThr1 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[11:10:13.906] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[11:10:13.906] <TB3> INFO: run 1 of 1
[11:10:14.184] <TB3> INFO: Expecting 5025280 events.
[11:10:40.601] <TB3> INFO: 590880 events read in total (25825ms).
[11:11:06.120] <TB3> INFO: 1181408 events read in total (51344ms).
[11:11:31.663] <TB3> INFO: 1772648 events read in total (76887ms).
[11:11:57.663] <TB3> INFO: 2363264 events read in total (102887ms).
[11:12:23.316] <TB3> INFO: 2951152 events read in total (128540ms).
[11:12:48.983] <TB3> INFO: 3538408 events read in total (154207ms).
[11:13:15.243] <TB3> INFO: 4124408 events read in total (180467ms).
[11:13:40.593] <TB3> INFO: 4710000 events read in total (205817ms).
[11:13:54.628] <TB3> INFO: 5025280 events read in total (219852ms).
[11:13:54.709] <TB3> INFO: Test took 220803ms.
[11:14:18.766] <TB3> INFO: roc 0 with ID = 0 has maximal Vcal 59.5627 for pixel 10/7 mean/min/max = 45.3016/31.021/59.5821
[11:14:18.766] <TB3> INFO: roc 1 with ID = 1 has maximal Vcal 64.608 for pixel 19/12 mean/min/max = 49.162/33.6815/64.6425
[11:14:18.767] <TB3> INFO: roc 2 with ID = 2 has maximal Vcal 63.1761 for pixel 11/10 mean/min/max = 47.4376/31.6152/63.26
[11:14:18.767] <TB3> INFO: roc 3 with ID = 3 has maximal Vcal 58.7707 for pixel 35/10 mean/min/max = 45.3282/31.7253/58.931
[11:14:18.768] <TB3> INFO: roc 4 with ID = 4 has maximal Vcal 64.2091 for pixel 51/1 mean/min/max = 49.4178/33.6902/65.1454
[11:14:18.768] <TB3> INFO: roc 5 with ID = 5 has maximal Vcal 59.1151 for pixel 20/78 mean/min/max = 45.0305/30.9211/59.1398
[11:14:18.768] <TB3> INFO: roc 6 with ID = 6 has maximal Vcal 60.3002 for pixel 3/59 mean/min/max = 45.8854/31.378/60.3928
[11:14:18.769] <TB3> INFO: roc 7 with ID = 7 has maximal Vcal 61.3225 for pixel 7/10 mean/min/max = 46.9542/32.3887/61.5196
[11:14:18.769] <TB3> INFO: roc 8 with ID = 8 has maximal Vcal 63.4204 for pixel 2/6 mean/min/max = 46.72/29.7945/63.6456
[11:14:18.770] <TB3> INFO: roc 9 with ID = 9 has maximal Vcal 63.7904 for pixel 5/14 mean/min/max = 47.2159/30.3881/64.0438
[11:14:18.770] <TB3> INFO: roc 10 with ID = 10 has maximal Vcal 64.5096 for pixel 16/0 mean/min/max = 47.4904/30.4312/64.5497
[11:14:18.771] <TB3> INFO: roc 11 with ID = 11 has maximal Vcal 60.7108 for pixel 0/8 mean/min/max = 47.4663/34.1155/60.8172
[11:14:18.771] <TB3> INFO: roc 12 with ID = 12 has maximal Vcal 59.5962 for pixel 0/40 mean/min/max = 45.31/30.7998/59.8203
[11:14:18.771] <TB3> INFO: roc 13 with ID = 13 has maximal Vcal 64.8438 for pixel 18/4 mean/min/max = 48.2569/31.4995/65.0143
[11:14:18.772] <TB3> INFO: roc 14 with ID = 14 has maximal Vcal 60.7108 for pixel 2/15 mean/min/max = 46.8097/32.8309/60.7886
[11:14:18.772] <TB3> INFO: roc 15 with ID = 15 has maximal Vcal 58.8754 for pixel 20/11 mean/min/max = 45.8101/32.6995/58.9207
[11:14:18.773] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:14:18.861] <TB3> INFO: Expecting 411648 events.
[11:14:28.391] <TB3> INFO: 411648 events read in total (8938ms).
[11:14:28.402] <TB3> INFO: Expecting 411648 events.
[11:14:37.850] <TB3> INFO: 411648 events read in total (9045ms).
[11:14:37.862] <TB3> INFO: Expecting 411648 events.
[11:14:47.175] <TB3> INFO: 411648 events read in total (8910ms).
[11:14:47.188] <TB3> INFO: Expecting 411648 events.
[11:14:56.592] <TB3> INFO: 411648 events read in total (9001ms).
[11:14:56.613] <TB3> INFO: Expecting 411648 events.
[11:15:05.926] <TB3> INFO: 411648 events read in total (8911ms).
[11:15:05.955] <TB3> INFO: Expecting 411648 events.
[11:15:15.350] <TB3> INFO: 411648 events read in total (8992ms).
[11:15:15.376] <TB3> INFO: Expecting 411648 events.
[11:15:24.764] <TB3> INFO: 411648 events read in total (8985ms).
[11:15:24.787] <TB3> INFO: Expecting 411648 events.
[11:15:34.162] <TB3> INFO: 411648 events read in total (8971ms).
[11:15:34.196] <TB3> INFO: Expecting 411648 events.
[11:15:43.519] <TB3> INFO: 411648 events read in total (8919ms).
[11:15:43.559] <TB3> INFO: Expecting 411648 events.
[11:15:53.047] <TB3> INFO: 411648 events read in total (9084ms).
[11:15:53.094] <TB3> INFO: Expecting 411648 events.
[11:16:02.436] <TB3> INFO: 411648 events read in total (8939ms).
[11:16:02.484] <TB3> INFO: Expecting 411648 events.
[11:16:11.839] <TB3> INFO: 411648 events read in total (8953ms).
[11:16:11.891] <TB3> INFO: Expecting 411648 events.
[11:16:21.198] <TB3> INFO: 411648 events read in total (8904ms).
[11:16:21.262] <TB3> INFO: Expecting 411648 events.
[11:16:30.700] <TB3> INFO: 411648 events read in total (9035ms).
[11:16:30.773] <TB3> INFO: Expecting 411648 events.
[11:16:39.000] <TB3> INFO: 411648 events read in total (8824ms).
[11:16:40.073] <TB3> INFO: Expecting 411648 events.
[11:16:49.390] <TB3> INFO: 411648 events read in total (8914ms).
[11:16:49.625] <TB3> INFO: Test took 150852ms.
[11:16:50.396] <TB3> INFO: ---> dac: vcal name: TrimThr2 ntrig: 8 dacrange: 0 .. 150 (-1/-1) hits flags = 528 (plus default)
[11:16:50.409] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[11:16:50.409] <TB3> INFO: run 1 of 1
[11:16:50.685] <TB3> INFO: Expecting 5025280 events.
[11:17:17.313] <TB3> INFO: 587096 events read in total (26037ms).
[11:17:43.385] <TB3> INFO: 1173592 events read in total (52108ms).
[11:18:09.497] <TB3> INFO: 1760896 events read in total (78221ms).
[11:18:35.484] <TB3> INFO: 2345928 events read in total (104207ms).
[11:19:01.509] <TB3> INFO: 2932448 events read in total (130232ms).
[11:19:27.852] <TB3> INFO: 3517368 events read in total (156575ms).
[11:19:54.104] <TB3> INFO: 4103600 events read in total (182827ms).
[11:20:19.913] <TB3> INFO: 4690008 events read in total (208636ms).
[11:20:35.493] <TB3> INFO: 5025280 events read in total (224216ms).
[11:20:35.789] <TB3> INFO: Test took 225382ms.
[11:20:59.853] <TB3> INFO: ---> TrimStepCorr4 extremal thresholds: 3.845564 .. 144.055031
[11:21:00.095] <TB3> INFO: Expecting 208000 events.
[11:21:09.433] <TB3> INFO: 208000 events read in total (8746ms).
[11:21:09.434] <TB3> INFO: Test took 9580ms.
[11:21:09.481] <TB3> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 8 dacrange: 3 .. 154 (-1/-1) hits flags = 528 (plus default)
[11:21:09.495] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[11:21:09.495] <TB3> INFO: run 1 of 1
[11:21:09.773] <TB3> INFO: Expecting 5058560 events.
[11:21:35.739] <TB3> INFO: 582552 events read in total (25375ms).
[11:22:01.137] <TB3> INFO: 1164568 events read in total (50774ms).
[11:22:26.532] <TB3> INFO: 1746896 events read in total (76168ms).
[11:22:52.088] <TB3> INFO: 2328432 events read in total (101724ms).
[11:23:17.778] <TB3> INFO: 2910328 events read in total (127414ms).
[11:23:42.989] <TB3> INFO: 3492056 events read in total (152625ms).
[11:24:08.666] <TB3> INFO: 4073368 events read in total (178302ms).
[11:24:34.484] <TB3> INFO: 4655016 events read in total (204120ms).
[11:24:53.167] <TB3> INFO: 5058560 events read in total (222803ms).
[11:24:53.285] <TB3> INFO: Test took 223791ms.
[11:25:20.209] <TB3> INFO: ---> TrimStepCorr2 extremal thresholds: 27.446321 .. 49.277941
[11:25:20.447] <TB3> INFO: Expecting 208000 events.
[11:25:30.102] <TB3> INFO: 208000 events read in total (9064ms).
[11:25:30.103] <TB3> INFO: Test took 9892ms.
[11:25:30.150] <TB3> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 8 dacrange: 17 .. 59 (-1/-1) hits flags = 528 (plus default)
[11:25:30.163] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[11:25:30.164] <TB3> INFO: run 1 of 1
[11:25:30.442] <TB3> INFO: Expecting 1431040 events.
[11:25:58.088] <TB3> INFO: 644728 events read in total (27054ms).
[11:26:25.393] <TB3> INFO: 1288920 events read in total (54359ms).
[11:26:31.947] <TB3> INFO: 1431040 events read in total (60914ms).
[11:26:31.981] <TB3> INFO: Test took 61818ms.
[11:26:45.608] <TB3> INFO: ---> TrimStepCorr1a extremal thresholds: 25.574190 .. 47.328700
[11:26:45.848] <TB3> INFO: Expecting 208000 events.
[11:26:55.578] <TB3> INFO: 208000 events read in total (9139ms).
[11:26:55.580] <TB3> INFO: Test took 9971ms.
[11:26:55.628] <TB3> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 8 dacrange: 15 .. 57 (-1/-1) hits flags = 528 (plus default)
[11:26:55.641] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[11:26:55.641] <TB3> INFO: run 1 of 1
[11:26:55.920] <TB3> INFO: Expecting 1431040 events.
[11:27:24.531] <TB3> INFO: 660080 events read in total (28020ms).
[11:27:52.893] <TB3> INFO: 1319216 events read in total (56382ms).
[11:27:58.044] <TB3> INFO: 1431040 events read in total (61533ms).
[11:27:58.084] <TB3> INFO: Test took 62443ms.
[11:28:11.586] <TB3> INFO: ---> TrimStepCorr1b extremal thresholds: 24.005862 .. 45.313756
[11:28:11.824] <TB3> INFO: Expecting 208000 events.
[11:28:21.684] <TB3> INFO: 208000 events read in total (9269ms).
[11:28:21.685] <TB3> INFO: Test took 10098ms.
[11:28:21.733] <TB3> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 8 dacrange: 14 .. 55 (-1/-1) hits flags = 528 (plus default)
[11:28:21.747] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[11:28:21.747] <TB3> INFO: run 1 of 1
[11:28:22.026] <TB3> INFO: Expecting 1397760 events.
[11:28:50.022] <TB3> INFO: 671528 events read in total (27405ms).
[11:29:17.930] <TB3> INFO: 1341984 events read in total (55313ms).
[11:29:20.696] <TB3> INFO: 1397760 events read in total (58079ms).
[11:29:20.727] <TB3> INFO: Test took 58980ms.
[11:29:33.150] <TB3> INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[11:29:33.150] <TB3> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 8 dacrange: 15 .. 55 (-1/-1) hits flags = 528 (plus default)
[11:29:33.163] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[11:29:33.163] <TB3> INFO: run 1 of 1
[11:29:33.400] <TB3> INFO: Expecting 1364480 events.
[11:30:01.428] <TB3> INFO: 667440 events read in total (27437ms).
[11:30:29.880] <TB3> INFO: 1334416 events read in total (55889ms).
[11:30:31.622] <TB3> INFO: 1364480 events read in total (57632ms).
[11:30:31.653] <TB3> INFO: Test took 58490ms.
[11:30:45.024] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C0.dat
[11:30:45.024] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C1.dat
[11:30:45.024] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C2.dat
[11:30:45.024] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C3.dat
[11:30:45.024] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C4.dat
[11:30:45.024] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C5.dat
[11:30:45.025] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C6.dat
[11:30:45.025] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C7.dat
[11:30:45.025] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C8.dat
[11:30:45.025] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C9.dat
[11:30:45.025] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C10.dat
[11:30:45.025] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C11.dat
[11:30:45.025] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C12.dat
[11:30:45.025] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C13.dat
[11:30:45.025] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C14.dat
[11:30:45.025] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C15.dat
[11:30:45.025] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//trimParameters35_C0.dat
[11:30:45.032] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//trimParameters35_C1.dat
[11:30:45.038] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//trimParameters35_C2.dat
[11:30:45.044] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//trimParameters35_C3.dat
[11:30:45.049] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//trimParameters35_C4.dat
[11:30:45.054] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//trimParameters35_C5.dat
[11:30:45.058] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//trimParameters35_C6.dat
[11:30:45.063] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//trimParameters35_C7.dat
[11:30:45.068] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//trimParameters35_C8.dat
[11:30:45.072] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//trimParameters35_C9.dat
[11:30:45.077] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//trimParameters35_C10.dat
[11:30:45.081] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//trimParameters35_C11.dat
[11:30:45.086] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//trimParameters35_C12.dat
[11:30:45.091] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//trimParameters35_C13.dat
[11:30:45.095] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//trimParameters35_C14.dat
[11:30:45.100] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//trimParameters35_C15.dat
[11:30:45.104] <TB3> INFO: PixTestTrim::trimTest() done
[11:30:45.104] <TB3> INFO: vtrim: 109 132 127 135 109 113 132 134 145 148 143 121 121 146 139 119
[11:30:45.104] <TB3> INFO: vthrcomp: 117 110 113 115 111 125 119 132 128 125 117 105 127 106 112 114
[11:30:45.104] <TB3> INFO: vcal mean: 34.98 35.07 34.99 34.90 35.04 34.91 34.93 34.93 35.01 35.02 35.03 34.99 34.94 34.99 35.00 34.99
[11:30:45.104] <TB3> INFO: vcal RMS: 1.00 1.07 1.40 1.02 1.18 1.03 1.06 1.03 1.26 1.35 1.30 0.96 1.00 1.15 1.11 1.02
[11:30:45.104] <TB3> INFO: bits mean: 9.53 8.82 9.63 9.64 8.14 9.56 9.62 9.39 9.98 9.68 9.94 8.77 9.50 9.42 9.34 9.51
[11:30:45.104] <TB3> INFO: bits RMS: 2.84 2.55 2.59 2.71 2.85 2.85 2.71 2.58 2.65 2.74 2.61 2.65 2.86 2.29 2.61 2.63
[11:30:45.111] <TB3> INFO: ----------------------------------------------------------------------
[11:30:45.111] <TB3> INFO: PixTestTrim::trimBitTest() ntrig = 5, vtrims = 254 126 63 32
[11:30:45.111] <TB3> INFO: ----------------------------------------------------------------------
[11:30:45.114] <TB3> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 5 dacrange: 0 .. 199 (-1/-1) hits flags = 528 (plus default)
[11:30:45.126] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[11:30:45.126] <TB3> INFO: run 1 of 1
[11:30:45.363] <TB3> INFO: Expecting 4160000 events.
[11:31:17.904] <TB3> INFO: 748320 events read in total (31949ms).
[11:31:49.915] <TB3> INFO: 1492500 events read in total (63960ms).
[11:32:21.773] <TB3> INFO: 2232665 events read in total (95818ms).
[11:32:53.637] <TB3> INFO: 2967350 events read in total (127682ms).
[11:33:24.987] <TB3> INFO: 3699400 events read in total (159032ms).
[11:33:45.186] <TB3> INFO: 4160000 events read in total (179231ms).
[11:33:45.333] <TB3> INFO: Test took 180207ms.
[11:34:12.586] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 5 dacrange: 0 .. 206 (-1/-1) hits flags = 528 (plus default)
[11:34:12.599] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[11:34:12.599] <TB3> INFO: run 1 of 1
[11:34:12.835] <TB3> INFO: Expecting 4305600 events.
[11:34:44.394] <TB3> INFO: 715555 events read in total (30967ms).
[11:35:15.650] <TB3> INFO: 1427380 events read in total (62223ms).
[11:35:46.773] <TB3> INFO: 2137035 events read in total (93346ms).
[11:36:17.540] <TB3> INFO: 2840115 events read in total (124113ms).
[11:36:48.343] <TB3> INFO: 3542215 events read in total (154917ms).
[11:37:19.289] <TB3> INFO: 4244150 events read in total (185862ms).
[11:37:22.536] <TB3> INFO: 4305600 events read in total (189109ms).
[11:37:22.709] <TB3> INFO: Test took 190110ms.
[11:37:48.214] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 5 dacrange: 0 .. 198 (-1/-1) hits flags = 528 (plus default)
[11:37:48.227] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[11:37:48.227] <TB3> INFO: run 1 of 1
[11:37:48.481] <TB3> INFO: Expecting 4139200 events.
[11:38:20.453] <TB3> INFO: 725785 events read in total (31381ms).
[11:38:51.544] <TB3> INFO: 1447385 events read in total (62472ms).
[11:39:22.832] <TB3> INFO: 2166090 events read in total (93760ms).
[11:39:53.853] <TB3> INFO: 2878770 events read in total (124782ms).
[11:40:25.186] <TB3> INFO: 3589485 events read in total (156114ms).
[11:40:49.533] <TB3> INFO: 4139200 events read in total (180461ms).
[11:40:49.631] <TB3> INFO: Test took 181403ms.
[11:41:13.927] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 5 dacrange: 0 .. 198 (-1/-1) hits flags = 528 (plus default)
[11:41:13.944] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[11:41:13.944] <TB3> INFO: run 1 of 1
[11:41:14.222] <TB3> INFO: Expecting 4139200 events.
[11:41:46.473] <TB3> INFO: 726000 events read in total (31659ms).
[11:42:17.788] <TB3> INFO: 1447520 events read in total (62974ms).
[11:42:49.456] <TB3> INFO: 2166465 events read in total (94642ms).
[11:43:20.541] <TB3> INFO: 2879350 events read in total (125727ms).
[11:43:51.623] <TB3> INFO: 3590165 events read in total (156809ms).
[11:44:16.083] <TB3> INFO: 4139200 events read in total (181269ms).
[11:44:16.165] <TB3> INFO: Test took 182221ms.
[11:44:42.403] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 5 dacrange: 0 .. 185 (-1/-1) hits flags = 528 (plus default)
[11:44:42.416] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[11:44:42.416] <TB3> INFO: run 1 of 1
[11:44:42.652] <TB3> INFO: Expecting 3868800 events.
[11:45:15.136] <TB3> INFO: 744830 events read in total (31893ms).
[11:45:46.938] <TB3> INFO: 1484825 events read in total (63695ms).
[11:46:18.702] <TB3> INFO: 2219835 events read in total (95459ms).
[11:46:50.325] <TB3> INFO: 2950130 events read in total (127082ms).
[11:47:22.157] <TB3> INFO: 3678270 events read in total (158914ms).
[11:47:30.698] <TB3> INFO: 3868800 events read in total (167455ms).
[11:47:30.789] <TB3> INFO: Test took 168373ms.
[11:47:53.992] <TB3> INFO: PixTestTrim::trimBitTest() done
[11:47:53.993] <TB3> INFO: PixTestTrim::doTest() done, duration: 2469 seconds
[11:47:53.993] <TB3> INFO: Decoding statistics:
[11:47:53.993] <TB3> INFO: General information:
[11:47:53.993] <TB3> INFO: 16bit words read: 0
[11:47:53.993] <TB3> INFO: valid events total: 0
[11:47:53.994] <TB3> INFO: empty events: 0
[11:47:53.994] <TB3> INFO: valid events with pixels: 0
[11:47:53.994] <TB3> INFO: valid pixel hits: 0
[11:47:53.994] <TB3> INFO: Event errors: 0
[11:47:53.994] <TB3> INFO: start marker: 0
[11:47:53.994] <TB3> INFO: stop marker: 0
[11:47:53.994] <TB3> INFO: overflow: 0
[11:47:53.994] <TB3> INFO: invalid 5bit words: 0
[11:47:53.994] <TB3> INFO: invalid XOR eye diagram: 0
[11:47:53.994] <TB3> INFO: frame (failed synchr.): 0
[11:47:53.994] <TB3> INFO: idle data (no TBM trl): 0
[11:47:53.994] <TB3> INFO: no data (only TBM hdr): 0
[11:47:53.994] <TB3> INFO: TBM errors: 0
[11:47:53.994] <TB3> INFO: flawed TBM headers: 0
[11:47:53.994] <TB3> INFO: flawed TBM trailers: 0
[11:47:53.994] <TB3> INFO: event ID mismatches: 0
[11:47:53.994] <TB3> INFO: ROC errors: 0
[11:47:53.994] <TB3> INFO: missing ROC header(s): 0
[11:47:53.994] <TB3> INFO: misplaced readback start: 0
[11:47:53.994] <TB3> INFO: Pixel decoding errors: 0
[11:47:53.994] <TB3> INFO: pixel data incomplete: 0
[11:47:53.994] <TB3> INFO: pixel address: 0
[11:47:53.994] <TB3> INFO: pulse height fill bit: 0
[11:47:53.994] <TB3> INFO: buffer corruption: 0
[11:47:54.612] <TB3> INFO: ######################################################################
[11:47:54.612] <TB3> INFO: PixTestPhOptimization::doTest() Ntrig = 10
[11:47:54.612] <TB3> INFO: ######################################################################
[11:47:54.851] <TB3> INFO: Expecting 41600 events.
[11:47:58.486] <TB3> INFO: 41600 events read in total (3043ms).
[11:47:58.487] <TB3> INFO: Test took 3874ms.
[11:47:58.974] <TB3> INFO: Expecting 41600 events.
[11:48:02.557] <TB3> INFO: 41600 events read in total (2991ms).
[11:48:02.558] <TB3> INFO: Test took 3868ms.
[11:48:02.847] <TB3> INFO: Expecting 41600 events.
[11:48:06.423] <TB3> INFO: 41600 events read in total (2984ms).
[11:48:06.424] <TB3> INFO: Test took 3842ms.
[11:48:06.713] <TB3> INFO: Expecting 41600 events.
[11:48:10.347] <TB3> INFO: 41600 events read in total (3042ms).
[11:48:10.348] <TB3> INFO: Test took 3899ms.
[11:48:10.641] <TB3> INFO: Expecting 41600 events.
[11:48:14.200] <TB3> INFO: 41600 events read in total (2967ms).
[11:48:14.201] <TB3> INFO: Test took 3825ms.
[11:48:14.490] <TB3> INFO: Expecting 41600 events.
[11:48:18.125] <TB3> INFO: 41600 events read in total (3043ms).
[11:48:18.125] <TB3> INFO: Test took 3900ms.
[11:48:18.415] <TB3> INFO: Expecting 41600 events.
[11:48:21.993] <TB3> INFO: 41600 events read in total (2987ms).
[11:48:21.993] <TB3> INFO: Test took 3844ms.
[11:48:22.282] <TB3> INFO: Expecting 41600 events.
[11:48:25.850] <TB3> INFO: 41600 events read in total (2976ms).
[11:48:25.851] <TB3> INFO: Test took 3834ms.
[11:48:26.153] <TB3> INFO: Expecting 41600 events.
[11:48:29.779] <TB3> INFO: 41600 events read in total (3035ms).
[11:48:29.780] <TB3> INFO: Test took 3905ms.
[11:48:30.071] <TB3> INFO: Expecting 41600 events.
[11:48:33.701] <TB3> INFO: 41600 events read in total (3039ms).
[11:48:33.702] <TB3> INFO: Test took 3896ms.
[11:48:33.992] <TB3> INFO: Expecting 41600 events.
[11:48:37.558] <TB3> INFO: 41600 events read in total (2974ms).
[11:48:37.559] <TB3> INFO: Test took 3833ms.
[11:48:37.850] <TB3> INFO: Expecting 41600 events.
[11:48:41.477] <TB3> INFO: 41600 events read in total (3035ms).
[11:48:41.477] <TB3> INFO: Test took 3892ms.
[11:48:41.769] <TB3> INFO: Expecting 41600 events.
[11:48:45.297] <TB3> INFO: 41600 events read in total (2937ms).
[11:48:45.298] <TB3> INFO: Test took 3794ms.
[11:48:45.588] <TB3> INFO: Expecting 41600 events.
[11:48:49.138] <TB3> INFO: 41600 events read in total (2958ms).
[11:48:49.139] <TB3> INFO: Test took 3817ms.
[11:48:49.431] <TB3> INFO: Expecting 41600 events.
[11:48:52.967] <TB3> INFO: 41600 events read in total (2944ms).
[11:48:52.968] <TB3> INFO: Test took 3802ms.
[11:48:53.261] <TB3> INFO: Expecting 41600 events.
[11:48:56.842] <TB3> INFO: 41600 events read in total (2989ms).
[11:48:56.843] <TB3> INFO: Test took 3849ms.
[11:48:57.134] <TB3> INFO: Expecting 41600 events.
[11:49:00.784] <TB3> INFO: 41600 events read in total (3058ms).
[11:49:00.785] <TB3> INFO: Test took 3916ms.
[11:49:01.074] <TB3> INFO: Expecting 41600 events.
[11:49:04.595] <TB3> INFO: 41600 events read in total (2930ms).
[11:49:04.596] <TB3> INFO: Test took 3787ms.
[11:49:04.886] <TB3> INFO: Expecting 41600 events.
[11:49:08.415] <TB3> INFO: 41600 events read in total (2937ms).
[11:49:08.415] <TB3> INFO: Test took 3794ms.
[11:49:08.705] <TB3> INFO: Expecting 41600 events.
[11:49:12.316] <TB3> INFO: 41600 events read in total (3019ms).
[11:49:12.317] <TB3> INFO: Test took 3877ms.
[11:49:12.608] <TB3> INFO: Expecting 41600 events.
[11:49:16.120] <TB3> INFO: 41600 events read in total (2921ms).
[11:49:16.120] <TB3> INFO: Test took 3778ms.
[11:49:16.409] <TB3> INFO: Expecting 41600 events.
[11:49:19.970] <TB3> INFO: 41600 events read in total (2969ms).
[11:49:19.971] <TB3> INFO: Test took 3827ms.
[11:49:20.260] <TB3> INFO: Expecting 41600 events.
[11:49:23.856] <TB3> INFO: 41600 events read in total (3004ms).
[11:49:23.857] <TB3> INFO: Test took 3862ms.
[11:49:24.149] <TB3> INFO: Expecting 41600 events.
[11:49:27.700] <TB3> INFO: 41600 events read in total (2959ms).
[11:49:27.701] <TB3> INFO: Test took 3818ms.
[11:49:27.992] <TB3> INFO: Expecting 41600 events.
[11:49:31.486] <TB3> INFO: 41600 events read in total (2903ms).
[11:49:31.486] <TB3> INFO: Test took 3760ms.
[11:49:31.777] <TB3> INFO: Expecting 41600 events.
[11:49:35.332] <TB3> INFO: 41600 events read in total (2963ms).
[11:49:35.333] <TB3> INFO: Test took 3821ms.
[11:49:35.622] <TB3> INFO: Expecting 41600 events.
[11:49:39.129] <TB3> INFO: 41600 events read in total (2915ms).
[11:49:39.130] <TB3> INFO: Test took 3773ms.
[11:49:39.420] <TB3> INFO: Expecting 41600 events.
[11:49:43.013] <TB3> INFO: 41600 events read in total (3001ms).
[11:49:43.013] <TB3> INFO: Test took 3858ms.
[11:49:43.309] <TB3> INFO: Expecting 41600 events.
[11:49:46.837] <TB3> INFO: 41600 events read in total (2937ms).
[11:49:46.838] <TB3> INFO: Test took 3795ms.
[11:49:47.129] <TB3> INFO: Expecting 2560 events.
[11:49:48.018] <TB3> INFO: 2560 events read in total (297ms).
[11:49:48.019] <TB3> INFO: Test took 1167ms.
[11:49:48.327] <TB3> INFO: Expecting 2560 events.
[11:49:49.216] <TB3> INFO: 2560 events read in total (297ms).
[11:49:49.216] <TB3> INFO: Test took 1197ms.
[11:49:49.524] <TB3> INFO: Expecting 2560 events.
[11:49:50.413] <TB3> INFO: 2560 events read in total (297ms).
[11:49:50.414] <TB3> INFO: Test took 1198ms.
[11:49:50.722] <TB3> INFO: Expecting 2560 events.
[11:49:51.609] <TB3> INFO: 2560 events read in total (295ms).
[11:49:51.609] <TB3> INFO: Test took 1195ms.
[11:49:51.918] <TB3> INFO: Expecting 2560 events.
[11:49:52.797] <TB3> INFO: 2560 events read in total (288ms).
[11:49:52.797] <TB3> INFO: Test took 1187ms.
[11:49:53.106] <TB3> INFO: Expecting 2560 events.
[11:49:53.990] <TB3> INFO: 2560 events read in total (292ms).
[11:49:53.990] <TB3> INFO: Test took 1192ms.
[11:49:54.298] <TB3> INFO: Expecting 2560 events.
[11:49:55.179] <TB3> INFO: 2560 events read in total (289ms).
[11:49:55.179] <TB3> INFO: Test took 1189ms.
[11:49:55.487] <TB3> INFO: Expecting 2560 events.
[11:49:56.372] <TB3> INFO: 2560 events read in total (293ms).
[11:49:56.373] <TB3> INFO: Test took 1193ms.
[11:49:56.682] <TB3> INFO: Expecting 2560 events.
[11:49:57.565] <TB3> INFO: 2560 events read in total (291ms).
[11:49:57.565] <TB3> INFO: Test took 1192ms.
[11:49:57.872] <TB3> INFO: Expecting 2560 events.
[11:49:58.753] <TB3> INFO: 2560 events read in total (289ms).
[11:49:58.753] <TB3> INFO: Test took 1187ms.
[11:49:59.062] <TB3> INFO: Expecting 2560 events.
[11:49:59.950] <TB3> INFO: 2560 events read in total (296ms).
[11:49:59.950] <TB3> INFO: Test took 1196ms.
[11:50:00.258] <TB3> INFO: Expecting 2560 events.
[11:50:01.145] <TB3> INFO: 2560 events read in total (295ms).
[11:50:01.146] <TB3> INFO: Test took 1196ms.
[11:50:01.454] <TB3> INFO: Expecting 2560 events.
[11:50:02.345] <TB3> INFO: 2560 events read in total (299ms).
[11:50:02.345] <TB3> INFO: Test took 1199ms.
[11:50:02.653] <TB3> INFO: Expecting 2560 events.
[11:50:03.541] <TB3> INFO: 2560 events read in total (296ms).
[11:50:03.542] <TB3> INFO: Test took 1197ms.
[11:50:03.850] <TB3> INFO: Expecting 2560 events.
[11:50:04.738] <TB3> INFO: 2560 events read in total (296ms).
[11:50:04.738] <TB3> INFO: Test took 1196ms.
[11:50:05.047] <TB3> INFO: Expecting 2560 events.
[11:50:05.935] <TB3> INFO: 2560 events read in total (296ms).
[11:50:05.935] <TB3> INFO: Test took 1196ms.
[11:50:05.939] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:50:06.244] <TB3> INFO: Expecting 655360 events.
[11:50:21.078] <TB3> INFO: 655360 events read in total (14243ms).
[11:50:21.090] <TB3> INFO: Expecting 655360 events.
[11:50:35.558] <TB3> INFO: 655360 events read in total (14065ms).
[11:50:35.578] <TB3> INFO: Expecting 655360 events.
[11:50:50.168] <TB3> INFO: 655360 events read in total (14186ms).
[11:50:50.188] <TB3> INFO: Expecting 655360 events.
[11:51:04.699] <TB3> INFO: 655360 events read in total (14108ms).
[11:51:04.724] <TB3> INFO: Expecting 655360 events.
[11:51:19.330] <TB3> INFO: 655360 events read in total (14203ms).
[11:51:19.362] <TB3> INFO: Expecting 655360 events.
[11:51:33.915] <TB3> INFO: 655360 events read in total (14150ms).
[11:51:33.949] <TB3> INFO: Expecting 655360 events.
[11:51:48.561] <TB3> INFO: 655360 events read in total (14208ms).
[11:51:48.612] <TB3> INFO: Expecting 655360 events.
[11:52:03.187] <TB3> INFO: 655360 events read in total (14172ms).
[11:52:03.243] <TB3> INFO: Expecting 655360 events.
[11:52:17.838] <TB3> INFO: 655360 events read in total (14192ms).
[11:52:17.894] <TB3> INFO: Expecting 655360 events.
[11:52:32.395] <TB3> INFO: 655360 events read in total (14098ms).
[11:52:32.449] <TB3> INFO: Expecting 655360 events.
[11:52:47.102] <TB3> INFO: 655360 events read in total (14250ms).
[11:52:47.172] <TB3> INFO: Expecting 655360 events.
[11:53:01.726] <TB3> INFO: 655360 events read in total (14151ms).
[11:53:01.789] <TB3> INFO: Expecting 655360 events.
[11:53:16.530] <TB3> INFO: 655360 events read in total (14338ms).
[11:53:16.611] <TB3> INFO: Expecting 655360 events.
[11:53:31.237] <TB3> INFO: 655360 events read in total (14223ms).
[11:53:31.325] <TB3> INFO: Expecting 655360 events.
[11:53:45.875] <TB3> INFO: 655360 events read in total (14147ms).
[11:53:46.039] <TB3> INFO: Expecting 655360 events.
[11:54:00.591] <TB3> INFO: 655360 events read in total (14149ms).
[11:54:00.753] <TB3> INFO: Test took 234814ms.
[11:54:00.858] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:54:01.106] <TB3> INFO: Expecting 655360 events.
[11:54:15.866] <TB3> INFO: 655360 events read in total (14168ms).
[11:54:15.877] <TB3> INFO: Expecting 655360 events.
[11:54:30.435] <TB3> INFO: 655360 events read in total (14154ms).
[11:54:30.452] <TB3> INFO: Expecting 655360 events.
[11:54:44.895] <TB3> INFO: 655360 events read in total (14040ms).
[11:54:44.915] <TB3> INFO: Expecting 655360 events.
[11:54:59.490] <TB3> INFO: 655360 events read in total (14172ms).
[11:54:59.515] <TB3> INFO: Expecting 655360 events.
[11:55:13.985] <TB3> INFO: 655360 events read in total (14067ms).
[11:55:14.015] <TB3> INFO: Expecting 655360 events.
[11:55:28.543] <TB3> INFO: 655360 events read in total (14125ms).
[11:55:28.577] <TB3> INFO: Expecting 655360 events.
[11:55:43.135] <TB3> INFO: 655360 events read in total (14155ms).
[11:55:43.175] <TB3> INFO: Expecting 655360 events.
[11:55:57.712] <TB3> INFO: 655360 events read in total (14134ms).
[11:55:57.765] <TB3> INFO: Expecting 655360 events.
[11:56:12.216] <TB3> INFO: 655360 events read in total (14049ms).
[11:56:12.329] <TB3> INFO: Expecting 655360 events.
[11:56:26.685] <TB3> INFO: 655360 events read in total (13953ms).
[11:56:26.754] <TB3> INFO: Expecting 655360 events.
[11:56:41.126] <TB3> INFO: 655360 events read in total (13969ms).
[11:56:41.196] <TB3> INFO: Expecting 655360 events.
[11:56:55.528] <TB3> INFO: 655360 events read in total (13929ms).
[11:56:55.590] <TB3> INFO: Expecting 655360 events.
[11:57:10.178] <TB3> INFO: 655360 events read in total (14185ms).
[11:57:10.318] <TB3> INFO: Expecting 655360 events.
[11:57:24.001] <TB3> INFO: 655360 events read in total (14280ms).
[11:57:25.090] <TB3> INFO: Expecting 655360 events.
[11:57:40.281] <TB3> INFO: 655360 events read in total (14788ms).
[11:57:40.374] <TB3> INFO: Expecting 655360 events.
[11:57:55.465] <TB3> INFO: 655360 events read in total (14688ms).
[11:57:55.571] <TB3> INFO: Test took 234713ms.
[11:57:55.739] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[11:57:55.745] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[11:57:55.751] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[11:57:55.756] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[11:57:55.763] <TB3> INFO: safety margin for low PH: adding 2, margin is now 22
[11:57:55.768] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[11:57:55.774] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[11:57:55.780] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[11:57:55.785] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[11:57:55.791] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[11:57:55.797] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[11:57:55.802] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[11:57:55.808] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[11:57:55.814] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[11:57:55.819] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[11:57:55.825] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[11:57:55.831] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[11:57:55.836] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[11:57:55.842] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[11:57:55.848] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[11:57:55.886] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C0.dat
[11:57:55.886] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C1.dat
[11:57:55.886] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C2.dat
[11:57:55.886] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C3.dat
[11:57:55.887] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C4.dat
[11:57:55.887] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C5.dat
[11:57:55.887] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C6.dat
[11:57:55.887] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C7.dat
[11:57:55.888] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C8.dat
[11:57:55.888] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C9.dat
[11:57:55.888] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C10.dat
[11:57:55.888] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C11.dat
[11:57:55.888] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C12.dat
[11:57:55.888] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C13.dat
[11:57:55.889] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C14.dat
[11:57:55.889] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C15.dat
[11:57:56.178] <TB3> INFO: Expecting 41600 events.
[11:57:59.371] <TB3> INFO: 41600 events read in total (2601ms).
[11:57:59.372] <TB3> INFO: Test took 3480ms.
[11:57:59.873] <TB3> INFO: Expecting 41600 events.
[11:58:02.996] <TB3> INFO: 41600 events read in total (2530ms).
[11:58:02.996] <TB3> INFO: Test took 3411ms.
[11:58:03.446] <TB3> INFO: Expecting 41600 events.
[11:58:06.640] <TB3> INFO: 41600 events read in total (2602ms).
[11:58:06.641] <TB3> INFO: Test took 3433ms.
[11:58:06.857] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:58:06.946] <TB3> INFO: Expecting 2560 events.
[11:58:07.840] <TB3> INFO: 2560 events read in total (303ms).
[11:58:07.840] <TB3> INFO: Test took 983ms.
[11:58:07.844] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:58:08.148] <TB3> INFO: Expecting 2560 events.
[11:58:09.042] <TB3> INFO: 2560 events read in total (302ms).
[11:58:09.042] <TB3> INFO: Test took 1198ms.
[11:58:09.046] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:58:09.351] <TB3> INFO: Expecting 2560 events.
[11:58:10.239] <TB3> INFO: 2560 events read in total (297ms).
[11:58:10.240] <TB3> INFO: Test took 1194ms.
[11:58:10.241] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:58:10.548] <TB3> INFO: Expecting 2560 events.
[11:58:11.441] <TB3> INFO: 2560 events read in total (302ms).
[11:58:11.441] <TB3> INFO: Test took 1200ms.
[11:58:11.444] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:58:11.749] <TB3> INFO: Expecting 2560 events.
[11:58:12.641] <TB3> INFO: 2560 events read in total (300ms).
[11:58:12.641] <TB3> INFO: Test took 1197ms.
[11:58:12.644] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:58:12.950] <TB3> INFO: Expecting 2560 events.
[11:58:13.841] <TB3> INFO: 2560 events read in total (299ms).
[11:58:13.842] <TB3> INFO: Test took 1198ms.
[11:58:13.844] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:58:14.150] <TB3> INFO: Expecting 2560 events.
[11:58:15.036] <TB3> INFO: 2560 events read in total (295ms).
[11:58:15.037] <TB3> INFO: Test took 1193ms.
[11:58:15.040] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:58:15.345] <TB3> INFO: Expecting 2560 events.
[11:58:16.240] <TB3> INFO: 2560 events read in total (303ms).
[11:58:16.240] <TB3> INFO: Test took 1200ms.
[11:58:16.244] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:58:16.548] <TB3> INFO: Expecting 2560 events.
[11:58:17.439] <TB3> INFO: 2560 events read in total (299ms).
[11:58:17.439] <TB3> INFO: Test took 1195ms.
[11:58:17.442] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:58:17.748] <TB3> INFO: Expecting 2560 events.
[11:58:18.638] <TB3> INFO: 2560 events read in total (299ms).
[11:58:18.638] <TB3> INFO: Test took 1196ms.
[11:58:18.641] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:58:18.947] <TB3> INFO: Expecting 2560 events.
[11:58:19.838] <TB3> INFO: 2560 events read in total (300ms).
[11:58:19.838] <TB3> INFO: Test took 1197ms.
[11:58:19.842] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:58:20.146] <TB3> INFO: Expecting 2560 events.
[11:58:21.037] <TB3> INFO: 2560 events read in total (299ms).
[11:58:21.037] <TB3> INFO: Test took 1195ms.
[11:58:21.041] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:58:21.345] <TB3> INFO: Expecting 2560 events.
[11:58:22.226] <TB3> INFO: 2560 events read in total (289ms).
[11:58:22.227] <TB3> INFO: Test took 1187ms.
[11:58:22.230] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:58:22.535] <TB3> INFO: Expecting 2560 events.
[11:58:23.415] <TB3> INFO: 2560 events read in total (289ms).
[11:58:23.415] <TB3> INFO: Test took 1185ms.
[11:58:23.417] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:58:23.725] <TB3> INFO: Expecting 2560 events.
[11:58:24.615] <TB3> INFO: 2560 events read in total (298ms).
[11:58:24.615] <TB3> INFO: Test took 1198ms.
[11:58:24.619] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:58:24.924] <TB3> INFO: Expecting 2560 events.
[11:58:25.814] <TB3> INFO: 2560 events read in total (298ms).
[11:58:25.815] <TB3> INFO: Test took 1197ms.
[11:58:25.818] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:58:26.123] <TB3> INFO: Expecting 2560 events.
[11:58:27.011] <TB3> INFO: 2560 events read in total (296ms).
[11:58:27.011] <TB3> INFO: Test took 1193ms.
[11:58:27.015] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:58:27.319] <TB3> INFO: Expecting 2560 events.
[11:58:28.207] <TB3> INFO: 2560 events read in total (297ms).
[11:58:28.207] <TB3> INFO: Test took 1192ms.
[11:58:28.209] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:58:28.515] <TB3> INFO: Expecting 2560 events.
[11:58:29.410] <TB3> INFO: 2560 events read in total (303ms).
[11:58:29.410] <TB3> INFO: Test took 1201ms.
[11:58:29.413] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:58:29.718] <TB3> INFO: Expecting 2560 events.
[11:58:30.605] <TB3> INFO: 2560 events read in total (296ms).
[11:58:30.605] <TB3> INFO: Test took 1192ms.
[11:58:30.607] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:58:30.914] <TB3> INFO: Expecting 2560 events.
[11:58:31.793] <TB3> INFO: 2560 events read in total (288ms).
[11:58:31.794] <TB3> INFO: Test took 1188ms.
[11:58:31.796] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:58:32.103] <TB3> INFO: Expecting 2560 events.
[11:58:32.993] <TB3> INFO: 2560 events read in total (298ms).
[11:58:32.994] <TB3> INFO: Test took 1198ms.
[11:58:32.997] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:58:33.302] <TB3> INFO: Expecting 2560 events.
[11:58:34.190] <TB3> INFO: 2560 events read in total (296ms).
[11:58:34.191] <TB3> INFO: Test took 1194ms.
[11:58:34.195] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:58:34.500] <TB3> INFO: Expecting 2560 events.
[11:58:35.381] <TB3> INFO: 2560 events read in total (290ms).
[11:58:35.382] <TB3> INFO: Test took 1187ms.
[11:58:35.384] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:58:35.690] <TB3> INFO: Expecting 2560 events.
[11:58:36.582] <TB3> INFO: 2560 events read in total (301ms).
[11:58:36.582] <TB3> INFO: Test took 1198ms.
[11:58:36.585] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:58:36.890] <TB3> INFO: Expecting 2560 events.
[11:58:37.783] <TB3> INFO: 2560 events read in total (301ms).
[11:58:37.784] <TB3> INFO: Test took 1199ms.
[11:58:37.788] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:58:38.092] <TB3> INFO: Expecting 2560 events.
[11:58:38.987] <TB3> INFO: 2560 events read in total (303ms).
[11:58:38.987] <TB3> INFO: Test took 1199ms.
[11:58:38.991] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:58:39.295] <TB3> INFO: Expecting 2560 events.
[11:58:40.186] <TB3> INFO: 2560 events read in total (299ms).
[11:58:40.186] <TB3> INFO: Test took 1195ms.
[11:58:40.189] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:58:40.495] <TB3> INFO: Expecting 2560 events.
[11:58:41.391] <TB3> INFO: 2560 events read in total (304ms).
[11:58:41.391] <TB3> INFO: Test took 1202ms.
[11:58:41.395] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:58:41.700] <TB3> INFO: Expecting 2560 events.
[11:58:42.595] <TB3> INFO: 2560 events read in total (303ms).
[11:58:42.596] <TB3> INFO: Test took 1202ms.
[11:58:42.599] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:58:42.904] <TB3> INFO: Expecting 2560 events.
[11:58:43.794] <TB3> INFO: 2560 events read in total (298ms).
[11:58:43.794] <TB3> INFO: Test took 1196ms.
[11:58:43.797] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:58:44.103] <TB3> INFO: Expecting 2560 events.
[11:58:44.992] <TB3> INFO: 2560 events read in total (297ms).
[11:58:44.993] <TB3> INFO: Test took 1196ms.
[11:58:45.477] <TB3> INFO: PixTestPhOptimization::doTest() done, duration: 650 seconds
[11:58:45.477] <TB3> INFO: PH scale (per ROC): 63 62 58 45 44 39 55 48 42 64 42 53 44 68 53 62
[11:58:45.477] <TB3> INFO: PH offset (per ROC): 121 113 123 91 95 107 122 89 101 116 98 123 103 119 110 121
[11:58:45.487] <TB3> INFO: Decoding statistics:
[11:58:45.487] <TB3> INFO: General information:
[11:58:45.487] <TB3> INFO: 16bit words read: 127888
[11:58:45.487] <TB3> INFO: valid events total: 20480
[11:58:45.487] <TB3> INFO: empty events: 17976
[11:58:45.487] <TB3> INFO: valid events with pixels: 2504
[11:58:45.487] <TB3> INFO: valid pixel hits: 2504
[11:58:45.487] <TB3> INFO: Event errors: 0
[11:58:45.488] <TB3> INFO: start marker: 0
[11:58:45.488] <TB3> INFO: stop marker: 0
[11:58:45.488] <TB3> INFO: overflow: 0
[11:58:45.488] <TB3> INFO: invalid 5bit words: 0
[11:58:45.488] <TB3> INFO: invalid XOR eye diagram: 0
[11:58:45.488] <TB3> INFO: frame (failed synchr.): 0
[11:58:45.488] <TB3> INFO: idle data (no TBM trl): 0
[11:58:45.488] <TB3> INFO: no data (only TBM hdr): 0
[11:58:45.488] <TB3> INFO: TBM errors: 0
[11:58:45.488] <TB3> INFO: flawed TBM headers: 0
[11:58:45.488] <TB3> INFO: flawed TBM trailers: 0
[11:58:45.488] <TB3> INFO: event ID mismatches: 0
[11:58:45.488] <TB3> INFO: ROC errors: 0
[11:58:45.488] <TB3> INFO: missing ROC header(s): 0
[11:58:45.488] <TB3> INFO: misplaced readback start: 0
[11:58:45.488] <TB3> INFO: Pixel decoding errors: 0
[11:58:45.488] <TB3> INFO: pixel data incomplete: 0
[11:58:45.488] <TB3> INFO: pixel address: 0
[11:58:45.488] <TB3> INFO: pulse height fill bit: 0
[11:58:45.488] <TB3> INFO: buffer corruption: 0
[11:58:45.648] <TB3> INFO: ######################################################################
[11:58:45.648] <TB3> INFO: PixTestGainPedestal::fullTest() ntrig = 10
[11:58:45.648] <TB3> INFO: ######################################################################
[11:58:45.662] <TB3> INFO: scanning low vcal = 10
[11:58:45.900] <TB3> INFO: Expecting 41600 events.
[11:58:49.488] <TB3> INFO: 41600 events read in total (2996ms).
[11:58:49.488] <TB3> INFO: Test took 3825ms.
[11:58:49.490] <TB3> INFO: scanning low vcal = 20
[11:58:49.786] <TB3> INFO: Expecting 41600 events.
[11:58:53.353] <TB3> INFO: 41600 events read in total (2975ms).
[11:58:53.354] <TB3> INFO: Test took 3864ms.
[11:58:53.356] <TB3> INFO: scanning low vcal = 30
[11:58:53.653] <TB3> INFO: Expecting 41600 events.
[11:58:57.299] <TB3> INFO: 41600 events read in total (3055ms).
[11:58:57.300] <TB3> INFO: Test took 3944ms.
[11:58:57.302] <TB3> INFO: scanning low vcal = 40
[11:58:57.581] <TB3> INFO: Expecting 41600 events.
[11:59:01.571] <TB3> INFO: 41600 events read in total (3398ms).
[11:59:01.572] <TB3> INFO: Test took 4270ms.
[11:59:01.575] <TB3> INFO: scanning low vcal = 50
[11:59:01.856] <TB3> INFO: Expecting 41600 events.
[11:59:05.826] <TB3> INFO: 41600 events read in total (3378ms).
[11:59:05.827] <TB3> INFO: Test took 4252ms.
[11:59:05.830] <TB3> INFO: scanning low vcal = 60
[11:59:06.107] <TB3> INFO: Expecting 41600 events.
[11:59:10.077] <TB3> INFO: 41600 events read in total (3379ms).
[11:59:10.078] <TB3> INFO: Test took 4248ms.
[11:59:10.081] <TB3> INFO: scanning low vcal = 70
[11:59:10.358] <TB3> INFO: Expecting 41600 events.
[11:59:14.344] <TB3> INFO: 41600 events read in total (3395ms).
[11:59:14.344] <TB3> INFO: Test took 4263ms.
[11:59:14.347] <TB3> INFO: scanning low vcal = 80
[11:59:14.624] <TB3> INFO: Expecting 41600 events.
[11:59:18.604] <TB3> INFO: 41600 events read in total (3388ms).
[11:59:18.605] <TB3> INFO: Test took 4258ms.
[11:59:18.608] <TB3> INFO: scanning low vcal = 90
[11:59:18.884] <TB3> INFO: Expecting 41600 events.
[11:59:22.880] <TB3> INFO: 41600 events read in total (3404ms).
[11:59:22.881] <TB3> INFO: Test took 4273ms.
[11:59:22.885] <TB3> INFO: scanning low vcal = 100
[11:59:23.160] <TB3> INFO: Expecting 41600 events.
[11:59:27.139] <TB3> INFO: 41600 events read in total (3387ms).
[11:59:27.140] <TB3> INFO: Test took 4255ms.
[11:59:27.143] <TB3> INFO: scanning low vcal = 110
[11:59:27.420] <TB3> INFO: Expecting 41600 events.
[11:59:31.403] <TB3> INFO: 41600 events read in total (3391ms).
[11:59:31.404] <TB3> INFO: Test took 4261ms.
[11:59:31.408] <TB3> INFO: scanning low vcal = 120
[11:59:31.684] <TB3> INFO: Expecting 41600 events.
[11:59:35.648] <TB3> INFO: 41600 events read in total (3373ms).
[11:59:35.649] <TB3> INFO: Test took 4241ms.
[11:59:35.652] <TB3> INFO: scanning low vcal = 130
[11:59:35.929] <TB3> INFO: Expecting 41600 events.
[11:59:39.902] <TB3> INFO: 41600 events read in total (3381ms).
[11:59:39.903] <TB3> INFO: Test took 4251ms.
[11:59:39.906] <TB3> INFO: scanning low vcal = 140
[11:59:40.183] <TB3> INFO: Expecting 41600 events.
[11:59:44.207] <TB3> INFO: 41600 events read in total (3432ms).
[11:59:44.208] <TB3> INFO: Test took 4302ms.
[11:59:44.211] <TB3> INFO: scanning low vcal = 150
[11:59:44.487] <TB3> INFO: Expecting 41600 events.
[11:59:48.453] <TB3> INFO: 41600 events read in total (3374ms).
[11:59:48.454] <TB3> INFO: Test took 4243ms.
[11:59:48.457] <TB3> INFO: scanning low vcal = 160
[11:59:48.735] <TB3> INFO: Expecting 41600 events.
[11:59:52.676] <TB3> INFO: 41600 events read in total (3350ms).
[11:59:52.677] <TB3> INFO: Test took 4219ms.
[11:59:52.680] <TB3> INFO: scanning low vcal = 170
[11:59:52.957] <TB3> INFO: Expecting 41600 events.
[11:59:56.904] <TB3> INFO: 41600 events read in total (3355ms).
[11:59:56.905] <TB3> INFO: Test took 4225ms.
[11:59:56.911] <TB3> INFO: scanning low vcal = 180
[11:59:57.185] <TB3> INFO: Expecting 41600 events.
[12:00:01.119] <TB3> INFO: 41600 events read in total (3342ms).
[12:00:01.120] <TB3> INFO: Test took 4209ms.
[12:00:01.123] <TB3> INFO: scanning low vcal = 190
[12:00:01.400] <TB3> INFO: Expecting 41600 events.
[12:00:05.354] <TB3> INFO: 41600 events read in total (3362ms).
[12:00:05.355] <TB3> INFO: Test took 4232ms.
[12:00:05.358] <TB3> INFO: scanning low vcal = 200
[12:00:05.635] <TB3> INFO: Expecting 41600 events.
[12:00:09.559] <TB3> INFO: 41600 events read in total (3333ms).
[12:00:09.560] <TB3> INFO: Test took 4201ms.
[12:00:09.564] <TB3> INFO: scanning low vcal = 210
[12:00:09.839] <TB3> INFO: Expecting 41600 events.
[12:00:13.803] <TB3> INFO: 41600 events read in total (3372ms).
[12:00:13.804] <TB3> INFO: Test took 4239ms.
[12:00:13.808] <TB3> INFO: scanning low vcal = 220
[12:00:14.124] <TB3> INFO: Expecting 41600 events.
[12:00:18.112] <TB3> INFO: 41600 events read in total (3397ms).
[12:00:18.113] <TB3> INFO: Test took 4304ms.
[12:00:18.116] <TB3> INFO: scanning low vcal = 230
[12:00:18.393] <TB3> INFO: Expecting 41600 events.
[12:00:22.430] <TB3> INFO: 41600 events read in total (3446ms).
[12:00:22.431] <TB3> INFO: Test took 4314ms.
[12:00:22.435] <TB3> INFO: scanning low vcal = 240
[12:00:22.711] <TB3> INFO: Expecting 41600 events.
[12:00:26.807] <TB3> INFO: 41600 events read in total (3503ms).
[12:00:26.808] <TB3> INFO: Test took 4373ms.
[12:00:26.812] <TB3> INFO: scanning low vcal = 250
[12:00:27.136] <TB3> INFO: Expecting 41600 events.
[12:00:31.217] <TB3> INFO: 41600 events read in total (3489ms).
[12:00:31.219] <TB3> INFO: Test took 4407ms.
[12:00:31.224] <TB3> INFO: scanning high vcal = 30 (= 210 in low range)
[12:00:31.499] <TB3> INFO: Expecting 41600 events.
[12:00:35.580] <TB3> INFO: 41600 events read in total (3489ms).
[12:00:35.581] <TB3> INFO: Test took 4356ms.
[12:00:35.585] <TB3> INFO: scanning high vcal = 50 (= 350 in low range)
[12:00:35.876] <TB3> INFO: Expecting 41600 events.
[12:00:39.933] <TB3> INFO: 41600 events read in total (3465ms).
[12:00:39.933] <TB3> INFO: Test took 4348ms.
[12:00:39.937] <TB3> INFO: scanning high vcal = 70 (= 490 in low range)
[12:00:40.213] <TB3> INFO: Expecting 41600 events.
[12:00:44.260] <TB3> INFO: 41600 events read in total (3455ms).
[12:00:44.260] <TB3> INFO: Test took 4323ms.
[12:00:44.264] <TB3> INFO: scanning high vcal = 90 (= 630 in low range)
[12:00:44.556] <TB3> INFO: Expecting 41600 events.
[12:00:48.623] <TB3> INFO: 41600 events read in total (3475ms).
[12:00:48.624] <TB3> INFO: Test took 4359ms.
[12:00:48.627] <TB3> INFO: scanning high vcal = 200 (= 1400 in low range)
[12:00:48.904] <TB3> INFO: Expecting 41600 events.
[12:00:52.873] <TB3> INFO: 41600 events read in total (3377ms).
[12:00:52.874] <TB3> INFO: Test took 4247ms.
[12:00:53.295] <TB3> INFO: PixTestGainPedestal::measure() done
[12:01:27.119] <TB3> INFO: PixTestGainPedestal::fit() done
[12:01:27.119] <TB3> INFO: non-linearity mean: 0.984 0.973 0.986 0.950 0.937 0.971 0.978 0.940 0.928 0.987 0.925 0.978 0.948 0.983 0.955 0.983
[12:01:27.119] <TB3> INFO: non-linearity RMS: 0.003 0.012 0.002 0.128 0.138 0.171 0.004 0.112 0.077 0.003 0.126 0.004 0.147 0.004 0.037 0.003
[12:01:27.119] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//phCalibrationFitErr35_C0.dat
[12:01:27.133] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//phCalibrationFitErr35_C1.dat
[12:01:27.146] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//phCalibrationFitErr35_C2.dat
[12:01:27.160] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//phCalibrationFitErr35_C3.dat
[12:01:27.173] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//phCalibrationFitErr35_C4.dat
[12:01:27.187] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//phCalibrationFitErr35_C5.dat
[12:01:27.200] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//phCalibrationFitErr35_C6.dat
[12:01:27.213] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//phCalibrationFitErr35_C7.dat
[12:01:27.227] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//phCalibrationFitErr35_C8.dat
[12:01:27.240] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//phCalibrationFitErr35_C9.dat
[12:01:27.253] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//phCalibrationFitErr35_C10.dat
[12:01:27.267] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//phCalibrationFitErr35_C11.dat
[12:01:27.280] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//phCalibrationFitErr35_C12.dat
[12:01:27.293] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//phCalibrationFitErr35_C13.dat
[12:01:27.307] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//phCalibrationFitErr35_C14.dat
[12:01:27.320] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//phCalibrationFitErr35_C15.dat
[12:01:27.333] <TB3> INFO: PixTestGainPedestal::fullTest() done, duration: 161 seconds
[12:01:27.333] <TB3> INFO: Decoding statistics:
[12:01:27.333] <TB3> INFO: General information:
[12:01:27.333] <TB3> INFO: 16bit words read: 3327776
[12:01:27.333] <TB3> INFO: valid events total: 332800
[12:01:27.333] <TB3> INFO: empty events: 0
[12:01:27.333] <TB3> INFO: valid events with pixels: 332800
[12:01:27.333] <TB3> INFO: valid pixel hits: 665488
[12:01:27.333] <TB3> INFO: Event errors: 0
[12:01:27.333] <TB3> INFO: start marker: 0
[12:01:27.333] <TB3> INFO: stop marker: 0
[12:01:27.333] <TB3> INFO: overflow: 0
[12:01:27.334] <TB3> INFO: invalid 5bit words: 0
[12:01:27.334] <TB3> INFO: invalid XOR eye diagram: 0
[12:01:27.334] <TB3> INFO: frame (failed synchr.): 0
[12:01:27.334] <TB3> INFO: idle data (no TBM trl): 0
[12:01:27.334] <TB3> INFO: no data (only TBM hdr): 0
[12:01:27.334] <TB3> INFO: TBM errors: 0
[12:01:27.334] <TB3> INFO: flawed TBM headers: 0
[12:01:27.334] <TB3> INFO: flawed TBM trailers: 0
[12:01:27.334] <TB3> INFO: event ID mismatches: 0
[12:01:27.334] <TB3> INFO: ROC errors: 0
[12:01:27.334] <TB3> INFO: missing ROC header(s): 0
[12:01:27.334] <TB3> INFO: misplaced readback start: 0
[12:01:27.334] <TB3> INFO: Pixel decoding errors: 0
[12:01:27.334] <TB3> INFO: pixel data incomplete: 0
[12:01:27.334] <TB3> INFO: pixel address: 0
[12:01:27.334] <TB3> INFO: pulse height fill bit: 0
[12:01:27.334] <TB3> INFO: buffer corruption: 0
[12:01:27.351] <TB3> INFO: Decoding statistics:
[12:01:27.351] <TB3> INFO: General information:
[12:01:27.351] <TB3> INFO: 16bit words read: 3457200
[12:01:27.351] <TB3> INFO: valid events total: 353536
[12:01:27.351] <TB3> INFO: empty events: 18232
[12:01:27.351] <TB3> INFO: valid events with pixels: 335304
[12:01:27.351] <TB3> INFO: valid pixel hits: 667992
[12:01:27.351] <TB3> INFO: Event errors: 0
[12:01:27.351] <TB3> INFO: start marker: 0
[12:01:27.351] <TB3> INFO: stop marker: 0
[12:01:27.351] <TB3> INFO: overflow: 0
[12:01:27.351] <TB3> INFO: invalid 5bit words: 0
[12:01:27.351] <TB3> INFO: invalid XOR eye diagram: 0
[12:01:27.351] <TB3> INFO: frame (failed synchr.): 0
[12:01:27.351] <TB3> INFO: idle data (no TBM trl): 0
[12:01:27.351] <TB3> INFO: no data (only TBM hdr): 0
[12:01:27.351] <TB3> INFO: TBM errors: 0
[12:01:27.351] <TB3> INFO: flawed TBM headers: 0
[12:01:27.351] <TB3> INFO: flawed TBM trailers: 0
[12:01:27.351] <TB3> INFO: event ID mismatches: 0
[12:01:27.351] <TB3> INFO: ROC errors: 0
[12:01:27.351] <TB3> INFO: missing ROC header(s): 0
[12:01:27.351] <TB3> INFO: misplaced readback start: 0
[12:01:27.351] <TB3> INFO: Pixel decoding errors: 0
[12:01:27.351] <TB3> INFO: pixel data incomplete: 0
[12:01:27.351] <TB3> INFO: pixel address: 0
[12:01:27.351] <TB3> INFO: pulse height fill bit: 0
[12:01:27.351] <TB3> INFO: buffer corruption: 0
[12:01:27.351] <TB3> INFO: enter test to run
[12:01:27.351] <TB3> INFO: test: exit no parameter change
[12:01:27.471] <TB3> QUIET: Connection to board 126 closed.
[12:01:27.472] <TB3> INFO: pXar: this is the end, my friend
MoReWeb-v1.0.5-10-g7383767 on branch 20161012_zhud