Test Date: 2015-06-26 09:57
Analysis date: 2015-10-28 15:43
Logfile
LogfileView
[09:59:32.073] INFO: *** Welcome to pxar ***
[09:59:32.073] INFO: *** Today: 2015/06/26
[09:59:32.073] INFO: readRocDacs: /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//dacParameters_C0.dat .. /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//dacParameters_C15.dat
[09:59:32.073] INFO: readTbmDacs: /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//tbmParameters_C0a.dat .. /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//tbmParameters_C0b.dat
[09:59:32.073] INFO: readMaskFile: /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//defaultMaskFile.dat
[09:59:32.073] INFO: readTrimFile: /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//trimParameters_C0.dat .. /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//trimParameters_C15.dat
[09:59:32.135] INFO: clk: 4
[09:59:32.135] INFO: ctr: 4
[09:59:32.135] INFO: sda: 19
[09:59:32.135] INFO: tin: 9
[09:59:32.135] INFO: level: 15
[09:59:32.135] INFO: triggerdelay: 0
[09:59:32.135] QUIET: Instanciating API for pxar v2.2.4+51~gdb2a247
[09:59:32.135] INFO: Log level: DEBUG
[09:59:32.149] QUIET: Connection to board DTB_WV7UX2 opened.
[09:59:32.152] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 105
HW version: DTB1.2
FW version: 4.2
SW version: 4.2
USB id: DTB_WV7UX2
MAC address: 40D855118069
Hostname: pixelDTB105
Comment: with CMOS buffer
------------------------------------------------------
[09:59:32.155] INFO: RPC call hashes of host and DTB match: 447413373
[09:59:33.703] INFO: DUT info:
[09:59:33.703] INFO: The DUT currently contains the following objects:
[09:59:33.703] INFO: 2 TBM Cores tbm08c (2 ON)
[09:59:33.703] INFO: TBM Core alpha (0): 7 registers set
[09:59:33.703] INFO: TBM Core beta (1): 7 registers set
[09:59:33.703] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[09:59:33.703] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[09:59:33.703] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[09:59:33.703] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[09:59:33.703] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[09:59:33.703] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[09:59:33.703] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[09:59:33.703] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[09:59:33.703] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[09:59:33.703] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[09:59:33.703] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[09:59:33.703] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[09:59:33.703] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[09:59:33.703] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[09:59:33.703] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[09:59:33.703] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[09:59:33.703] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[09:59:33.703] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->BB<-
[09:59:33.703] DEBUG: <PixTestParameters.cc/dump:L107> dumpall: checkbox(0)
[09:59:33.703] DEBUG: <PixTestParameters.cc/dump:L107> dumpproblematic: checkbox(0)
[09:59:33.703] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 5
[09:59:33.703] DEBUG: <PixTestParameters.cc/dump:L107> vcals: 250
[09:59:33.703] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->BB2<-
[09:59:33.703] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[09:59:33.703] DEBUG: <PixTestParameters.cc/dump:L107> vcals: 222
[09:59:33.703] DEBUG: <PixTestParameters.cc/dump:L107> plwidth: 35
[09:59:33.703] DEBUG: <PixTestParameters.cc/dump:L107> pix: 11,20
[09:59:33.703] DEBUG: <PixTestParameters.cc/dump:L107> targetia: 24
[09:59:33.703] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->BB3<-
[09:59:33.703] DEBUG: <PixTestParameters.cc/dump:L107> dumpall: checkbox(0)
[09:59:33.703] DEBUG: <PixTestParameters.cc/dump:L107> dumpproblematic: checkbox(0)
[09:59:33.703] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 5
[09:59:33.703] DEBUG: <PixTestParameters.cc/dump:L107> vcals: 250
[09:59:33.703] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->DacDacScan<-
[09:59:33.703] DEBUG: <PixTestParameters.cc/dump:L107> phmap: checkbox
[09:59:33.703] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[09:59:33.703] DEBUG: <PixTestParameters.cc/dump:L107> dac1: caldel
[09:59:33.703] DEBUG: <PixTestParameters.cc/dump:L107> dac1lo: 0
[09:59:33.703] DEBUG: <PixTestParameters.cc/dump:L107> dac1hi: 255
[09:59:33.703] DEBUG: <PixTestParameters.cc/dump:L107> dac2: vthrcomp
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> dac2lo: 0
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> dac2hi: 255
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> pix: 11,20
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->DacScan<-
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> phmap: checkbox(1)
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> allpixels: checkbox(0)
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> unmasked: checkbox(0)
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> dac: vcal
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> daclo: 0
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> dachi: 255
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> pix: 11,20
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->GainPedestal<-
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> showfits: checkbox(0)
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> extended: checkbox(0)
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> dumphists: checkbox(0)
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> measure: button
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> fit: button
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> save: button
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->HighRate<-
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> pix: 11,20
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> maskhotpixels: button
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> savemaskfile: checkbox(0)
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> maskfilename: default
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> caldelscan: button
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> xpixelalive: button
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 50
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> vcal: 200
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> xnoisemaps: button
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> daclo: 0
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> dachi: 100
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> dacs/step: 20
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> rundaq: button
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> trgfrequency(khz): 20
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> runseconds: 2
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> triggerdelay: 20
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> delaytbm: checkbox
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> filltree: checkbox
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->IV<-
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> port: /dev/FIXME
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> voltagestart: 0
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> voltagestop: 600
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> voltagestep: 5
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> delay: 1
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> compliance(ua): 100
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->PhOptimization<-
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> safetymarginlow: 20
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> saturationvcal: 100
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> quantilesaturation: 0.98
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->PixelAlive<-
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> vcal: 200
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> alivetest: button
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> masktest: button
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> addressdecodingtest: button
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Pretest<-
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> programroc: button
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> targetia: 24
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> setvana: button
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> iterations: 100
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> settimings: button
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> findworkingpixel: button
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> setvthrcompcaldel: button
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> pix: 11,20
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> vcal: 250
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> deltavthrcomp: 50
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> fraccaldel: 0.5
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 5
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> savedacs: button
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Readback<-
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> calibratevd: button
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> calibrateva: button
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> calibrateia: button
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> readbackvbg: button
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> getcalibratedvbg: button
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> usecalvd: checkbox(1)
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> usecalva: checkbox(0)
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> setvana: button
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Scurves<-
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> adjustvcal: checkbox(1)
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> dumpall: checkbox(0)
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> dumpproblematic: checkbox(0)
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> dumpoutputfile: checkbox(0)
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 50
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> dac: VthrComp
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> daclo: 0
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> dachi: 200
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> dacs/step: 10
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> scurves: button
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Timing<-
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> fastscan: checkbox(0)
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> targetclk: 4
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> clocksdascan: button
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> phasescan: button
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> levelscan: button
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> tbmphasescan: button
[09:59:33.704] DEBUG: <PixTestParameters.cc/dump:L107> rocdelayscan: button
[09:59:33.705] DEBUG: <PixTestParameters.cc/dump:L107> timingtest: button
[09:59:33.705] DEBUG: <PixTestParameters.cc/dump:L107> saveparameters: button
[09:59:33.705] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Trim<-
[09:59:33.705] DEBUG: <PixTestParameters.cc/dump:L107> trim: button
[09:59:33.705] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[09:59:33.705] DEBUG: <PixTestParameters.cc/dump:L107> vcal: 35
[09:59:33.705] DEBUG: <PixTestParameters.cc/dump:L107> trimbits: button
[09:59:33.705] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Xray<-
[09:59:33.705] DEBUG: <PixTestParameters.cc/dump:L107> maskhotpixels: button
[09:59:33.705] DEBUG: <PixTestParameters.cc/dump:L107> savemaskfile: checkbox(0)
[09:59:33.705] DEBUG: <PixTestParameters.cc/dump:L107> maskfilename: default
[09:59:33.705] DEBUG: <PixTestParameters.cc/dump:L107> source: Ag
[09:59:33.705] DEBUG: <PixTestParameters.cc/dump:L107> phrun: button
[09:59:33.705] DEBUG: <PixTestParameters.cc/dump:L107> runseconds: 100
[09:59:33.705] DEBUG: <PixTestParameters.cc/dump:L107> trgfrequency(khz): 100
[09:59:33.705] DEBUG: <PixTestParameters.cc/dump:L107> ratescan: button
[09:59:33.705] DEBUG: <PixTestParameters.cc/dump:L107> vthrcompmin: 10
[09:59:33.705] DEBUG: <PixTestParameters.cc/dump:L107> vthrcompmax: 80
[09:59:33.705] DEBUG: <PixTestParameters.cc/dump:L107> stepseconds: 5
[09:59:33.705] DEBUG: <PixTestParameters.cc/dump:L107> delaytbm: checkbox
[09:59:33.705] DEBUG: <PixTestParameters.cc/dump:L107> filltree: checkbox
[09:59:33.705] DEBUG: <PixSetup.cc/init:L81> PixSetup init start; getCurrentRSS() = 33759232
[09:59:33.705] DEBUG: <PixSetup.cc/init:L87> fPixTestParameters = 0x25ac7d0
[09:59:33.705] DEBUG: <PixSetup.cc/init:L88> fConfigParameters = 0x2305980
[09:59:33.705] DEBUG: <PixSetup.cc/init:L89> fPxarMemory = 0x7f03a1d94010
[09:59:33.705] DEBUG: <PixSetup.cc/init:L90> fPxarMemHi = 0x7f03a7fff510
[09:59:33.705] DEBUG: <PixSetup.cc/init:L106> PixSetup init done; getCurrentRSS() = 33816576 fPxarMemory = 0x7f03a1d94010
[09:59:33.705] DEBUG: <PixTestFactory.cc/PixTestFactory:L51> PixTestFactory::PixTestFactory()
[09:59:34.107] INFO: enter 'restricted' command line mode
[09:59:34.107] INFO: enter test to run
[09:59:34.107] INFO: test: Pretest no parameter change
[09:59:34.107] INFO: running: pretest
[09:59:34.112] INFO: ######################################################################
[09:59:34.112] INFO: PixTestPretest::doTest()
[09:59:34.112] INFO: ######################################################################
[09:59:34.114] INFO: ----------------------------------------------------------------------
[09:59:34.114] INFO: PixTestPretest::programROC()
[09:59:34.114] INFO: ----------------------------------------------------------------------
[09:59:52.135] INFO: PixTestPretest::programROC() done: ROCs are all programmable
[09:59:52.135] INFO: IA differences per ROC: 19.3 18.5 17.7 18.5 20.1 16.1 19.3 20.1 16.9 18.5 19.3 17.7 20.1 17.7 18.5 19.3
[09:59:52.205] INFO: ----------------------------------------------------------------------
[09:59:52.205] INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[09:59:52.205] INFO: ----------------------------------------------------------------------
[09:59:52.309] DEBUG: <PixTestPretest.cc/setVana:L254> offset current from other 15 ROCs is 69.2812 mA
[09:59:52.410] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 0 iter 0 Vana 78 Ia 23.1188 mA
[09:59:52.511] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 1 Vana 83 Ia 24.7188 mA
[09:59:52.611] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 2 Vana 80 Ia 23.9188 mA
[09:59:52.713] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 1 iter 0 Vana 78 Ia 22.3188 mA
[09:59:52.814] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 1 Vana 88 Ia 24.7188 mA
[09:59:52.914] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 2 Vana 85 Ia 24.7188 mA
[09:59:53.015] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 3 Vana 82 Ia 23.9188 mA
[09:59:53.117] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 2 iter 0 Vana 78 Ia 22.3188 mA
[09:59:53.218] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 2 iter 1 Vana 88 Ia 23.9188 mA
[09:59:53.319] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 3 iter 0 Vana 78 Ia 22.3188 mA
[09:59:53.420] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 1 Vana 88 Ia 24.7188 mA
[09:59:53.521] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 2 Vana 85 Ia 24.7188 mA
[09:59:53.621] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 3 Vana 82 Ia 23.9188 mA
[09:59:53.722] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 4 iter 0 Vana 78 Ia 23.9188 mA
[09:59:53.824] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 5 iter 0 Vana 78 Ia 19.9188 mA
[09:59:53.925] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 1 Vana 103 Ia 24.7188 mA
[09:59:54.026] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 2 Vana 100 Ia 24.7188 mA
[09:59:54.127] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 3 Vana 97 Ia 23.9188 mA
[09:59:54.228] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 6 iter 0 Vana 78 Ia 23.1188 mA
[09:59:54.329] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 1 Vana 83 Ia 24.7188 mA
[09:59:54.429] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 2 Vana 80 Ia 23.9188 mA
[09:59:54.531] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 7 iter 0 Vana 78 Ia 24.7188 mA
[09:59:54.631] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 7 iter 1 Vana 75 Ia 23.9188 mA
[09:59:54.733] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 8 iter 0 Vana 78 Ia 21.5188 mA
[09:59:54.833] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 8 iter 1 Vana 93 Ia 23.9188 mA
[09:59:54.935] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 9 iter 0 Vana 78 Ia 22.3188 mA
[09:59:55.036] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 9 iter 1 Vana 88 Ia 23.9188 mA
[09:59:55.137] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 10 iter 0 Vana 78 Ia 23.1188 mA
[09:59:55.238] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 1 Vana 83 Ia 24.7188 mA
[09:59:55.339] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 2 Vana 80 Ia 24.7188 mA
[09:59:55.439] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 3 Vana 77 Ia 23.1188 mA
[09:59:55.540] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 4 Vana 82 Ia 24.7188 mA
[09:59:55.641] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 5 Vana 79 Ia 23.1188 mA
[09:59:55.741] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 6 Vana 84 Ia 25.5188 mA
[09:59:55.842] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 7 Vana 76 Ia 23.1188 mA
[09:59:55.942] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 8 Vana 81 Ia 24.7188 mA
[09:59:56.043] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 9 Vana 78 Ia 23.1188 mA
[09:59:56.143] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 10 Vana 83 Ia 25.5188 mA
[09:59:56.244] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 11 Vana 75 Ia 23.1188 mA
[09:59:56.345] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 11 iter 0 Vana 78 Ia 22.3188 mA
[09:59:56.446] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter 1 Vana 88 Ia 23.9188 mA
[09:59:56.547] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 12 iter 0 Vana 78 Ia 24.7188 mA
[09:59:56.648] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter 1 Vana 75 Ia 23.9188 mA
[09:59:56.749] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 13 iter 0 Vana 78 Ia 21.5188 mA
[09:59:56.850] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 1 Vana 93 Ia 24.7188 mA
[09:59:56.950] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 2 Vana 90 Ia 23.9188 mA
[09:59:57.052] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 14 iter 0 Vana 78 Ia 22.3188 mA
[09:59:57.153] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 1 Vana 88 Ia 24.7188 mA
[09:59:57.254] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 2 Vana 85 Ia 23.9188 mA
[09:59:57.355] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 15 iter 0 Vana 78 Ia 23.1188 mA
[09:59:57.456] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 1 Vana 83 Ia 24.7188 mA
[09:59:57.556] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 2 Vana 80 Ia 23.9188 mA
[09:59:57.601] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 0 Vana 80
[09:59:57.601] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 1 Vana 82
[09:59:57.601] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 2 Vana 88
[09:59:57.601] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 3 Vana 82
[09:59:57.601] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 4 Vana 78
[09:59:57.601] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 5 Vana 97
[09:59:57.602] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 6 Vana 80
[09:59:57.602] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 7 Vana 75
[09:59:57.602] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 8 Vana 93
[09:59:57.602] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 9 Vana 88
[09:59:57.602] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 10 Vana 75
[09:59:57.602] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 11 Vana 88
[09:59:57.602] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 12 Vana 75
[09:59:57.603] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 13 Vana 90
[09:59:57.603] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 14 Vana 85
[09:59:57.603] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 15 Vana 80
[09:59:57.706] INFO: PixTestPretest::setVana() done, Module Ia 387.5 mA = 24.2188 mA/ROC
[09:59:57.707] INFO: ----------------------------------------------------------------------
[09:59:57.707] INFO: PixTestPreTest::setTimings()
[09:59:57.707] INFO: ----------------------------------------------------------------------
[09:59:57.707] DEBUG: <PixTestPretest.cc/setTimings:L392> Testing Timing: Attempt #1
[09:59:58.671] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:59:58.671] INFO: Decoding statistics:
[09:59:58.671] INFO: General information:
[09:59:58.671] INFO: 16bit words read: 120
[09:59:58.671] INFO: valid events total: 10
[09:59:58.671] INFO: empty events: 10
[09:59:58.671] INFO: valid events with pixels: 0
[09:59:58.671] INFO: valid pixel hits: 0
[09:59:58.671] INFO: Event errors: 0
[09:59:58.671] INFO: start marker: 0
[09:59:58.671] INFO: stop marker: 0
[09:59:58.671] INFO: overflow: 0
[09:59:58.671] INFO: invalid 5bit words: 0
[09:59:58.671] INFO: invalid XOR eye diagram: 0
[09:59:58.671] INFO: TBM errors: 0
[09:59:58.671] INFO: flawed TBM headers: 0
[09:59:58.671] INFO: flawed TBM trailers: 0
[09:59:58.671] INFO: event ID mismatches: 0
[09:59:58.671] INFO: ROC errors: 0
[09:59:58.671] INFO: missing ROC header(s): 0
[09:59:58.671] INFO: misplaced readback start: 0
[09:59:58.671] INFO: Pixel decoding errors: 0
[09:59:58.671] INFO: pixel data incomplete: 0
[09:59:58.671] INFO: pixel address: 0
[09:59:58.671] INFO: pulse height fill bit: 0
[09:59:58.671] INFO: buffer corruption: 0
[09:59:58.671] INFO: ----------------------------------------------------------------------
[09:59:58.671] INFO: Default timings are good. No timing scan needed.
[09:59:58.671] INFO: ----------------------------------------------------------------------
[09:59:58.671] INFO: Test took 964 ms.
[09:59:58.671] INFO: PixTestPretest::setTimings() done.
[09:59:58.863] INFO: ----------------------------------------------------------------------
[09:59:58.863] INFO: PixTestPretest::findWorkingPixel()
[09:59:58.863] INFO: ----------------------------------------------------------------------
[10:00:06.041] INFO: Test took 7175ms.
[10:00:06.273] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C0 OK, with vthrComp = 98 and Delta(CalDel) = 63
[10:00:06.276] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C1 OK, with vthrComp = 91 and Delta(CalDel) = 56
[10:00:06.278] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C2 OK, with vthrComp = 103 and Delta(CalDel) = 60
[10:00:06.280] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C3 OK, with vthrComp = 90 and Delta(CalDel) = 58
[10:00:06.282] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C4 OK, with vthrComp = 95 and Delta(CalDel) = 59
[10:00:06.284] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C5 OK, with vthrComp = 100 and Delta(CalDel) = 62
[10:00:06.287] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C6 OK, with vthrComp = 94 and Delta(CalDel) = 62
[10:00:06.289] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C7 OK, with vthrComp = 107 and Delta(CalDel) = 58
[10:00:06.291] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C8 OK, with vthrComp = 90 and Delta(CalDel) = 62
[10:00:06.294] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C9 OK, with vthrComp = 72 and Delta(CalDel) = 63
[10:00:06.296] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C10 OK, with vthrComp = 69 and Delta(CalDel) = 63
[10:00:06.298] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C11 OK, with vthrComp = 83 and Delta(CalDel) = 60
[10:00:06.300] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C12 OK, with vthrComp = 88 and Delta(CalDel) = 63
[10:00:06.302] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C13 OK, with vthrComp = 94 and Delta(CalDel) = 56
[10:00:06.305] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C14 OK, with vthrComp = 94 and Delta(CalDel) = 62
[10:00:06.307] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C15 OK, with vthrComp = 104 and Delta(CalDel) = 57
[10:00:06.331] INFO: Found working pixel in all ROCs: col/row = 12/22
[10:00:06.380] INFO: ----------------------------------------------------------------------
[10:00:06.380] INFO: PixTestPretest::setVthrCompCalDel()
[10:00:06.380] INFO: ----------------------------------------------------------------------
[10:00:13.568] INFO: Test took 7183ms.
[10:00:13.620] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 137 +/- 30.5
[10:00:13.796] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 102 +/- 26.5
[10:00:13.798] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 109 +/- 30
[10:00:13.800] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 118 +/- 28
[10:00:13.803] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 127 +/- 31
[10:00:13.805] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 133 +/- 31
[10:00:13.807] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 132 +/- 30.5
[10:00:13.809] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 124 +/- 29.5
[10:00:13.812] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 132 +/- 30.5
[10:00:13.814] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 149 +/- 31.5
[10:00:13.816] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 143 +/- 31.5
[10:00:13.818] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 131 +/- 30.5
[10:00:13.821] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 138 +/- 30.5
[10:00:13.823] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 127 +/- 29
[10:00:13.825] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 138 +/- 31.5
[10:00:13.827] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 109 +/- 29.5
[10:00:13.878] INFO: PixTestPretest::setVthrCompCalDel() done
[10:00:13.878] INFO: CalDel: 137 102 109 118 127 133 132 124 132 149 143 131 138 127 138 109
[10:00:13.878] INFO: VthrComp: 51 51 55 51 51 51 51 51 51 51 51 51 51 51 51 51
[10:00:13.881] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//dacParameters_C0.dat
[10:00:13.881] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//dacParameters_C1.dat
[10:00:13.881] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//dacParameters_C2.dat
[10:00:13.881] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//dacParameters_C3.dat
[10:00:13.882] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//dacParameters_C4.dat
[10:00:13.882] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//dacParameters_C5.dat
[10:00:13.882] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//dacParameters_C6.dat
[10:00:13.882] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//dacParameters_C7.dat
[10:00:13.882] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//dacParameters_C8.dat
[10:00:13.882] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//dacParameters_C9.dat
[10:00:13.882] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//dacParameters_C10.dat
[10:00:13.882] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//dacParameters_C11.dat
[10:00:13.882] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//dacParameters_C12.dat
[10:00:13.882] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//dacParameters_C13.dat
[10:00:13.882] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//dacParameters_C14.dat
[10:00:13.882] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//dacParameters_C15.dat
[10:00:13.883] INFO: PixTestPretest::doTest() done, duration: 39 seconds
[10:00:13.883] DEBUG: <PixTestPretest.cc/~PixTestPretest:L134> PixTestPretest dtor
[10:00:13.955] INFO: enter test to run
[10:00:13.956] INFO: test: Fulltest no parameter change
[10:00:13.956] INFO: running: fulltest
[10:00:13.956] DEBUG: <PixTestFullTest.cc/init:L49> PixTestFullTest::init()
[10:00:13.956] DEBUG: <PixTestFullTest.cc/PixTestFullTest:L20> PixTestFullTest ctor(PixSetup &a, string, TGTab *)
[10:00:13.956] INFO: ######################################################################
[10:00:13.956] INFO: PixTestFullTest::doTest()
[10:00:13.956] INFO: ######################################################################
[10:00:13.956] DEBUG: <PixTestAlive.cc/init:L77> PixTestAlive::init()
[10:00:13.956] DEBUG: <PixTestAlive.cc/PixTestAlive:L21> PixTestAlive ctor(PixSetup &a, string, TGTab *)
[10:00:13.959] INFO: ######################################################################
[10:00:13.959] INFO: PixTestAlive::doTest()
[10:00:13.959] INFO: ######################################################################
[10:00:13.961] INFO: ----------------------------------------------------------------------
[10:00:13.961] 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:00:13.961] INFO: ----------------------------------------------------------------------
[10:00:13.963] DEBUG: <PixTest.cc/efficiencyMaps:L328> attempt #0
[10:00:17.647] INFO: Test took 3684ms.
[10:00:17.664] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:00:17.664] DEBUG: <PixTest.cc/efficiencyMaps:L339> eff result size = 66541
[10:00:17.664] DEBUG: <PixTest.cc/efficiencyMaps:L344> Create hists PixelAlive_C0 .. PixelAlive_C15
[10:00:17.904] INFO: PixTestAlive::aliveTest() done
[10:00:17.904] INFO: number of dead pixels (per ROC): 4 4 1 0 0 0 0 0 1 0 0 0 2 4 1 2
[10:00:17.904] DEBUG: <PixTestAlive.cc/aliveTest:L188> number of red-efficiency pixels: 4 4 1 0 0 0 0 0 1 0 0 0 2 4 1 2
[10:00:17.906] INFO: ----------------------------------------------------------------------
[10:00:17.906] 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:00:17.906] INFO: ----------------------------------------------------------------------
[10:00:17.908] DEBUG: <PixTest.cc/efficiencyMaps:L328> attempt #0
[10:00:20.560] INFO: Test took 2652ms.
[10:00:20.561] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:00:20.561] DEBUG: <PixTest.cc/efficiencyMaps:L339> eff result size = 0
[10:00:20.561] DEBUG: <PixTest.cc/efficiencyMaps:L344> Create hists MaskTest_C0 .. MaskTest_C15
[10:00:20.562] INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[10:00:20.800] INFO: PixTestAlive::maskTest() done
[10:00:20.801] 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:00:20.802] INFO: ----------------------------------------------------------------------
[10:00:20.802] 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:00:20.802] INFO: ----------------------------------------------------------------------
[10:00:20.804] DEBUG: <PixTest.cc/efficiencyMaps:L328> attempt #0
[10:00:24.497] INFO: Test took 3693ms.
[10:00:24.516] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:00:24.516] DEBUG: <PixTest.cc/efficiencyMaps:L339> eff result size = 66541
[10:00:24.516] DEBUG: <PixTest.cc/efficiencyMaps:L344> Create hists AddressDecodingTest_C0 .. AddressDecodingTest_C15
[10:00:24.758] INFO: PixTestAlive::addressDecodingTest() done
[10:00:24.758] 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:00:24.758] INFO: PixTestAlive::doTest() done, duration: 10 seconds
[10:00:24.758] DEBUG: <PixTestAlive.cc/~PixTestAlive:L109> PixTestAlive dtor
[10:00:24.762] DEBUG: <PixTestBBMap.cc/init:L79> PixTestBBMap::init()
[10:00:24.762] DEBUG: <PixTestBBMap.cc/PixTestBBMap:L27> PixTestBBMap ctor(PixSetup &a, string, TGTab *)
[10:00:24.764] INFO: ######################################################################
[10:00:24.764] INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[10:00:24.764] INFO: ######################################################################
[10:00:24.768] INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (30) hits flags = 2 (plus default)
[10:00:24.779] INFO: dacScan step from 0 .. 29
[10:00:24.779] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:00:42.406] INFO: Test took 17627ms.
[10:00:42.439] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:00:42.439] INFO: dacScan step from 30 .. 59
[10:00:42.440] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:01:00.569] INFO: Test took 18129ms.
[10:01:00.642] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:01:00.650] INFO: dacScan step from 60 .. 89
[10:01:00.651] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:01:23.875] INFO: Test took 23224ms.
[10:01:24.142] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:01:24.190] INFO: dacScan step from 90 .. 119
[10:01:24.191] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:01:48.313] INFO: Test took 24122ms.
[10:01:48.570] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:01:48.612] INFO: dacScan step from 120 .. 149
[10:01:48.612] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:02:11.738] INFO: Test took 23125ms.
[10:02:11.945] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:02:11.976] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[10:02:13.246] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[10:02:14.505] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[10:02:15.781] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[10:02:17.029] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[10:02:18.276] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[10:02:19.507] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[10:02:20.733] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[10:02:21.987] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[10:02:23.212] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[10:02:24.379] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[10:02:25.545] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[10:02:26.776] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[10:02:27.978] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[10:02:29.209] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[10:02:30.464] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[10:02:31.740] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 262090752
[10:02:31.786] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C0_V0
[10:02:31.787] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 105 (obtained for minval = 0) start: 105 .. 127 last peak: 66.0968 last sigma: 6.13346 lcuts[0] = 84.4972 lcuts[1] = 127.431
[10:02:31.787] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C1_V0
[10:02:31.788] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 101 (obtained for minval = 0) start: 101 .. 124 last peak: 57.918 last sigma: 6.7053 lcuts[0] = 78.0339 lcuts[1] = 124.971
[10:02:31.788] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C2_V0
[10:02:31.788] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 109 (obtained for minval = 0) start: 109 .. 133 last peak: 64.9268 last sigma: 6.85827 lcuts[0] = 85.5016 lcuts[1] = 133.509
[10:02:31.789] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C3_V0
[10:02:31.789] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 106 (obtained for minval = 0) start: 106 .. 128 last peak: 65.3684 last sigma: 6.31445 lcuts[0] = 84.3117 lcuts[1] = 128.513
[10:02:31.789] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C4_V0
[10:02:31.790] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 100 (obtained for minval = 0) start: 100 .. 122 last peak: 60.214 last sigma: 6.24292 lcuts[0] = 78.9427 lcuts[1] = 122.643
[10:02:31.790] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C5_V0
[10:02:31.790] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 101 (obtained for minval = 0) start: 101 .. 121 last peak: 64.782 last sigma: 5.67304 lcuts[0] = 81.8011 lcuts[1] = 121.512
[10:02:31.790] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C6_V0
[10:02:31.791] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 100 (obtained for minval = 0) start: 100 .. 121 last peak: 61.8964 last sigma: 5.92902 lcuts[0] = 79.6835 lcuts[1] = 121.187
[10:02:31.791] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C7_V0
[10:02:31.791] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 109 (obtained for minval = 0) start: 109 .. 132 last peak: 65.4822 last sigma: 6.73091 lcuts[0] = 85.675 lcuts[1] = 132.791
[10:02:31.792] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C8_V0
[10:02:31.792] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 99 (obtained for minval = 0) start: 99 .. 118 last peak: 63.2423 last sigma: 5.57436 lcuts[0] = 79.9654 lcuts[1] = 118.986
[10:02:31.792] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C9_V0
[10:02:31.793] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 90 (obtained for minval = 0) start: 90 .. 108 last peak: 57.2798 last sigma: 5.10994 lcuts[0] = 72.6096 lcuts[1] = 108.379
[10:02:31.793] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C10_V0
[10:02:31.793] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 90 (obtained for minval = 0) start: 90 .. 107 last peak: 57.8365 last sigma: 5.01435 lcuts[0] = 72.8795 lcuts[1] = 107.98
[10:02:31.793] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C11_V0
[10:02:31.794] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 102 (obtained for minval = 0) start: 102 .. 122 last peak: 64.3633 last sigma: 5.82284 lcuts[0] = 81.8318 lcuts[1] = 122.592
[10:02:31.794] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C12_V0
[10:02:31.794] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 87 (obtained for minval = 0) start: 87 .. 105 last peak: 54.0572 last sigma: 5.16962 lcuts[0] = 69.566 lcuts[1] = 105.753
[10:02:31.795] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C13_V0
[10:02:31.795] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 91 (obtained for minval = 0) start: 91 .. 111 last peak: 56.539 last sigma: 5.44882 lcuts[0] = 72.8854 lcuts[1] = 111.027
[10:02:31.795] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C14_V0
[10:02:31.796] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 96 (obtained for minval = 0) start: 96 .. 118 last peak: 54.9865 last sigma: 6.31357 lcuts[0] = 73.9272 lcuts[1] = 118.122
[10:02:31.796] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C15_V0
[10:02:31.796] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 104 (obtained for minval = 0) start: 104 .. 127 last peak: 62.9596 last sigma: 6.42765 lcuts[0] = 82.2426 lcuts[1] = 127.236
[10:02:31.798] INFO: PixTestBBMap::doTest() done, duration: 127 seconds
[10:02:31.798] INFO: number of dead bumps (per ROC): 5 2 2 2 0 2 0 1 2 3 2 4 1 1 3 1
[10:02:31.798] INFO: separation cut (per ROC): 106 102 110 107 101 102 101 110 100 91 91 103 88 92 97 105
[10:02:31.798] DEBUG: <PixTestBBMap.cc/~PixTestBBMap:L97> PixTestBBMap dtor
[10:02:31.862] DEBUG: <PixTestScurves.cc/setParameter:L92> set fOutputFilename =
[10:02:31.864] INFO: ######################################################################
[10:02:31.864] INFO: PixTestScurves::fullTest() ntrig = 50
[10:02:31.864] INFO: ######################################################################
[10:02:31.864] INFO: ----------------------------------------------------------------------
[10:02:31.864] INFO: PixTestScurves::scurves(Vcal), ntrig = 50
[10:02:31.864] INFO: ----------------------------------------------------------------------
[10:02:31.864] INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 0 .. 149 (10) hits flags = 16 (plus default)
[10:02:31.873] INFO: dacScan step from 0 .. 9
[10:02:31.873] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:03:05.316] INFO: Test took 33443ms.
[10:03:05.384] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:03:05.384] INFO: dacScan step from 10 .. 19
[10:03:05.384] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:03:23.547] ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (7) != Token Chain Length (8)

[10:03:23.547] ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (7) != Token Chain Length (8)

[10:03:23.547] WARNING: ROC 7: Readback start marker after 15 readouts!

[10:03:23.547] WARNING: ROC 7: Readback start marker after 15 readouts!

[10:03:38.989] INFO: Test took 33604ms.
[10:03:39.055] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:03:39.055] INFO: dacScan step from 20 .. 29
[10:03:39.055] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:04:12.541] INFO: Test took 33486ms.
[10:04:12.607] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:04:12.607] INFO: dacScan step from 30 .. 39
[10:04:12.608] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:04:46.064] INFO: Test took 33456ms.
[10:04:46.130] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:04:46.130] INFO: dacScan step from 40 .. 49
[10:04:46.130] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:05:19.619] INFO: Test took 33489ms.
[10:05:19.685] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:05:19.685] INFO: dacScan step from 50 .. 59
[10:05:19.685] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:05:53.149] INFO: Test took 33464ms.
[10:05:53.215] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:05:53.215] INFO: dacScan step from 60 .. 69
[10:05:53.215] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:06:26.689] INFO: Test took 33474ms.
[10:06:26.754] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:06:26.754] INFO: dacScan step from 70 .. 79
[10:06:26.755] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:07:00.356] WARNING: ROC 7: Readback start marker after 7 readouts!

[10:07:00.356] ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (12) != Token Chain Length (8)

[10:07:00.356] ERROR: <datapipe.cc/CheckEventID:L420> Event ID mismatch: local ID (12) != TBM ID (13)

[10:07:00.356] WARNING: ROC 0: Readback start marker after 15 readouts!

[10:07:00.356] WARNING: ROC 1: Readback start marker after 15 readouts!

[10:07:00.356] WARNING: ROC 5: Readback start marker after 15 readouts!

[10:07:00.356] WARNING: ROC 6: Readback start marker after 15 readouts!

[10:07:00.356] WARNING: ROC 4: Readback start marker after 15 readouts!

[10:07:00.356] WARNING: ROC 7: Readback start marker after 8 readouts!

[10:07:00.356] WARNING: ROC 2: Readback start marker after 15 readouts!

[10:07:00.356] WARNING: ROC 3: Readback start marker after 31 readouts!

[10:07:00.370] INFO: Test took 33615ms.
[10:07:00.439] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:07:00.439] INFO: dacScan step from 80 .. 89
[10:07:00.440] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:07:33.371] ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (12) != Token Chain Length (8)

[10:07:33.371] ERROR: <datapipe.cc/CheckEventID:L420> Event ID mismatch: local ID (4) != TBM ID (5)

[10:07:33.371] WARNING: ROC 2: Readback start marker after 15 readouts!

[10:07:33.371] WARNING: ROC 3: Readback start marker after 15 readouts!

[10:07:33.371] WARNING: ROC 0: Readback start marker after 15 readouts!

[10:07:33.371] WARNING: ROC 1: Readback start marker after 15 readouts!

[10:07:33.371] WARNING: ROC 5: Readback start marker after 15 readouts!

[10:07:33.371] WARNING: ROC 6: Readback start marker after 15 readouts!

[10:07:33.371] WARNING: ROC 4: Readback start marker after 31 readouts!

[10:07:33.371] WARNING: ROC 7: Readback start marker after 31 readouts!

[10:07:34.779] INFO: Test took 34339ms.
[10:07:34.911] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:07:34.915] INFO: dacScan step from 90 .. 99
[10:07:34.915] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:08:06.651] ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (13) != Token Chain Length (8)

[10:08:06.651] ERROR: <datapipe.cc/CheckEventID:L420> Event ID mismatch: local ID (33) != TBM ID (34)

[10:08:06.651] WARNING: ROC 5: Readback start marker after 15 readouts!

[10:08:06.651] WARNING: ROC 6: Readback start marker after 15 readouts!

[10:08:06.651] WARNING: ROC 4: Readback start marker after 15 readouts!

[10:08:06.651] WARNING: ROC 7: Readback start marker after 15 readouts!

[10:08:06.651] WARNING: ROC 2: Readback start marker after 15 readouts!

[10:08:06.651] WARNING: ROC 3: Readback start marker after 15 readouts!

[10:08:06.651] WARNING: ROC 0: Readback start marker after 15 readouts!

[10:08:06.651] WARNING: ROC 1: Readback start marker after 15 readouts!

[10:08:13.251] INFO: Test took 38336ms.
[10:08:13.519] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:08:13.530] INFO: dacScan step from 100 .. 109
[10:08:13.530] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:08:42.713] ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (4) != Token Chain Length (8)

[10:08:42.713] WARNING: ROC 5: Readback start marker after 15 readouts!

[10:08:42.713] WARNING: ROC 6: Readback start marker after 15 readouts!

[10:08:42.713] WARNING: ROC 4: Readback start marker after 15 readouts!

[10:08:42.713] WARNING: ROC 7: Readback start marker after 15 readouts!

[10:08:59.702] INFO: Test took 46172ms.
[10:09:00.159] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:09:00.175] INFO: dacScan step from 110 .. 119
[10:09:00.175] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:09:28.602] ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (4) != Token Chain Length (8)

[10:09:28.602] WARNING: ROC 5: Readback start marker after 15 readouts!

[10:09:28.602] WARNING: ROC 6: Readback start marker after 15 readouts!

[10:09:28.602] WARNING: ROC 4: Readback start marker after 15 readouts!

[10:09:28.602] WARNING: ROC 7: Readback start marker after 15 readouts!

[10:09:48.509] ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (6) != Token Chain Length (8)

[10:09:48.509] WARNING: ROC 6: Readback start marker after 15 readouts!

[10:09:48.509] WARNING: ROC 7: Readback start marker after 15 readouts!

[10:09:48.509] WARNING: ROC 3: Readback start marker after 32 readouts!

[10:09:52.865] INFO: Test took 52690ms.
[10:09:53.445] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:09:53.461] INFO: dacScan step from 120 .. 129
[10:09:53.461] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:10:22.846] ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (5) != Token Chain Length (8)

[10:10:22.847] WARNING: ROC 5: Readback start marker after 15 readouts!

[10:10:22.847] WARNING: ROC 6: Readback start marker after 15 readouts!

[10:10:22.847] WARNING: ROC 7: Readback start marker after 15 readouts!

[10:10:44.187] ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (15) != Token Chain Length (8)

[10:10:44.187] ERROR: <datapipe.cc/CheckEventID:L420> Event ID mismatch: local ID (251) != TBM ID (252)

[10:10:44.187] WARNING: ROC 3: Readback start marker after 15 readouts!

[10:10:44.187] WARNING: ROC 0: Readback start marker after 15 readouts!

[10:10:44.187] WARNING: ROC 1: Readback start marker after 15 readouts!

[10:10:44.187] WARNING: ROC 5: Readback start marker after 15 readouts!

[10:10:44.187] WARNING: ROC 6: Readback start marker after 15 readouts!

[10:10:44.187] WARNING: ROC 4: Readback start marker after 15 readouts!

[10:10:44.187] WARNING: ROC 7: Readback start marker after 15 readouts!

[10:10:44.187] WARNING: ROC 2: Readback start marker after 15 readouts!

[10:10:49.400] INFO: Test took 55939ms.
[10:10:49.978] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:10:49.994] INFO: dacScan step from 130 .. 139
[10:10:49.994] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:11:20.109] ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (6) != Token Chain Length (8)

[10:11:20.109] WARNING: ROC 6: Readback start marker after 15 readouts!

[10:11:20.109] WARNING: ROC 7: Readback start marker after 15 readouts!

[10:11:41.659] ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (5) != Token Chain Length (8)

[10:11:41.659] WARNING: ROC 5: Readback start marker after 15 readouts!

[10:11:41.659] WARNING: ROC 6: Readback start marker after 15 readouts!

[10:11:41.659] WARNING: ROC 7: Readback start marker after 15 readouts!

[10:11:46.952] INFO: Test took 56958ms.
[10:11:47.514] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:11:47.530] INFO: dacScan step from 140 .. 149
[10:11:47.531] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:12:16.632] ERROR: <datapipe.cc/CheckEventID:L420> Event ID mismatch: local ID (118) != TBM ID (190)

[10:12:16.632] ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (6) != Token Chain Length (8)

[10:12:16.632] ERROR: <datapipe.cc/CheckEventID:L420> Event ID mismatch: local ID (191) != TBM ID (119)

[10:12:16.634] WARNING: ROC 6: Readback start marker after 15 readouts!

[10:12:16.635] WARNING: ROC 7: Readback start marker after 15 readouts!

[10:12:36.643] ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (5) != Token Chain Length (8)

[10:12:36.643] WARNING: ROC 5: Readback start marker after 15 readouts!

[10:12:36.643] WARNING: ROC 6: Readback start marker after 15 readouts!

[10:12:36.643] WARNING: ROC 7: Readback start marker after 15 readouts!

[10:12:41.938] INFO: Test took 54407ms.
[10:12:42.501] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:12:42.517] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[10:12:42.517] INFO: dumping ASCII scurve output file: SCurveData
[10:12:43.712] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[10:12:43.712] INFO: dumping ASCII scurve output file: SCurveData
[10:12:44.917] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[10:12:44.917] INFO: dumping ASCII scurve output file: SCurveData
[10:12:46.109] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[10:12:46.109] INFO: dumping ASCII scurve output file: SCurveData
[10:12:47.314] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[10:12:47.314] INFO: dumping ASCII scurve output file: SCurveData
[10:12:48.536] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[10:12:48.536] INFO: dumping ASCII scurve output file: SCurveData
[10:12:49.732] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[10:12:49.732] INFO: dumping ASCII scurve output file: SCurveData
[10:12:50.948] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[10:12:50.948] INFO: dumping ASCII scurve output file: SCurveData
[10:12:52.169] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[10:12:52.169] INFO: dumping ASCII scurve output file: SCurveData
[10:12:53.393] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[10:12:53.393] INFO: dumping ASCII scurve output file: SCurveData
[10:12:54.634] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[10:12:54.634] INFO: dumping ASCII scurve output file: SCurveData
[10:12:55.859] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[10:12:55.859] INFO: dumping ASCII scurve output file: SCurveData
[10:12:57.075] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[10:12:57.075] INFO: dumping ASCII scurve output file: SCurveData
[10:12:58.318] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[10:12:58.318] INFO: dumping ASCII scurve output file: SCurveData
[10:12:59.561] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[10:12:59.561] INFO: dumping ASCII scurve output file: SCurveData
[10:13:00.779] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[10:13:00.779] INFO: dumping ASCII scurve output file: SCurveData
[10:13:01.987] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 564293632
[10:13:02.033] INFO: PixTestScurves::scurves() done
[10:13:02.033] INFO: Vcal mean: 108.72 108.22 113.93 107.70 97.47 111.78 99.78 99.51 98.01 92.59 98.55 102.07 87.48 94.16 99.80 109.86
[10:13:02.033] INFO: Vcal RMS: 6.35 6.59 6.44 5.85 5.28 6.10 5.18 6.05 6.16 5.25 6.41 5.41 5.88 5.58 5.74 5.41
[10:13:02.033] INFO: PixTestScurves::fullTest() done, duration: 630 seconds
[10:13:02.033] DEBUG: <PixTestScurves.cc/~PixTestScurves:L141> PixTestScurves dtor
[10:13:02.095] INFO: ######################################################################
[10:13:02.095] INFO: PixTestTrim::doTest()
[10:13:02.095] INFO: ######################################################################
[10:13:02.096] INFO: ----------------------------------------------------------------------
[10:13:02.096] INFO: PixTestTrim::trimTest() ntrig = 10, vcal = 35
[10:13:02.096] INFO: ----------------------------------------------------------------------
[10:13:02.164] INFO: ---> VthrComp thr map (minimal VthrComp)
[10:13:02.164] INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 5 dacrange: 0 .. 159 (20) hits flags = 16 (plus default)
[10:13:02.172] INFO: dacScan step from 0 .. 19
[10:13:02.172] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:13:14.584] INFO: Test took 12412ms.
[10:13:14.606] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:13:14.606] INFO: dacScan step from 20 .. 39
[10:13:14.606] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:13:27.013] INFO: Test took 12407ms.
[10:13:27.035] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:13:27.035] INFO: dacScan step from 40 .. 59
[10:13:27.036] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:13:39.463] INFO: Test took 12427ms.
[10:13:39.485] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:13:39.485] INFO: dacScan step from 60 .. 79
[10:13:39.485] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:13:51.913] INFO: Test took 12429ms.
[10:13:51.935] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:13:51.935] INFO: dacScan step from 80 .. 99
[10:13:51.936] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:14:04.459] INFO: Test took 12523ms.
[10:14:04.494] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:14:04.497] INFO: dacScan step from 100 .. 119
[10:14:04.497] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:14:18.861] INFO: Test took 14364ms.
[10:14:18.993] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:14:19.014] INFO: dacScan step from 120 .. 139
[10:14:19.014] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:14:35.921] INFO: Test took 16907ms.
[10:14:36.078] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:14:36.104] INFO: dacScan step from 140 .. 159
[10:14:36.104] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:14:49.540] INFO: Test took 13436ms.
[10:14:49.614] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:14:49.624] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[10:14:50.817] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[10:14:52.015] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[10:14:53.216] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[10:14:54.396] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[10:14:55.575] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[10:14:56.739] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[10:14:57.899] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[10:14:59.084] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[10:15:00.238] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[10:15:01.345] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[10:15:02.446] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[10:15:03.602] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[10:15:04.731] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[10:15:05.908] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[10:15:07.107] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[10:15:08.299] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 564318208
[10:15:08.301] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 103.394 minThrLimit = 103.33 minThrNLimit = 126.501 -> result = 103.394 -> 103
[10:15:08.301] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 104.046 minThrLimit = 103.723 minThrNLimit = 126.861 -> result = 104.046 -> 104
[10:15:08.301] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 107.965 minThrLimit = 107.931 minThrNLimit = 131.783 -> result = 107.965 -> 107
[10:15:08.302] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 101.423 minThrLimit = 101.32 minThrNLimit = 123.607 -> result = 101.423 -> 101
[10:15:08.302] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 99.0216 minThrLimit = 98.9725 minThrNLimit = 122.217 -> result = 99.0216 -> 99
[10:15:08.302] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 100.204 minThrLimit = 100.149 minThrNLimit = 119.564 -> result = 100.204 -> 100
[10:15:08.303] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 97.665 minThrLimit = 97.6149 minThrNLimit = 117.95 -> result = 97.665 -> 97
[10:15:08.303] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 100.97 minThrLimit = 100.968 minThrNLimit = 123.469 -> result = 100.97 -> 100
[10:15:08.303] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 95.844 minThrLimit = 95.802 minThrNLimit = 116.812 -> result = 95.844 -> 95
[10:15:08.304] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 88.7635 minThrLimit = 88.7469 minThrNLimit = 105.639 -> result = 88.7635 -> 88
[10:15:08.304] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 88.9707 minThrLimit = 88.9588 minThrNLimit = 104.979 -> result = 88.9707 -> 88
[10:15:08.304] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 99.4311 minThrLimit = 99.4227 minThrNLimit = 119.899 -> result = 99.4311 -> 99
[10:15:08.305] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 87.817 minThrLimit = 87.7313 minThrNLimit = 108.403 -> result = 87.817 -> 87
[10:15:08.305] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 95.61 minThrLimit = 95.5767 minThrNLimit = 117.66 -> result = 95.61 -> 95
[10:15:08.305] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 100.931 minThrLimit = 100.815 minThrNLimit = 123.953 -> result = 100.931 -> 100
[10:15:08.306] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 104.11 minThrLimit = 104.081 minThrNLimit = 126.237 -> result = 104.11 -> 104
[10:15:08.306] INFO: ROC 0 VthrComp = 103
[10:15:08.306] INFO: ROC 1 VthrComp = 104
[10:15:08.306] INFO: ROC 2 VthrComp = 107
[10:15:08.306] INFO: ROC 3 VthrComp = 101
[10:15:08.306] INFO: ROC 4 VthrComp = 99
[10:15:08.306] INFO: ROC 5 VthrComp = 100
[10:15:08.306] INFO: ROC 6 VthrComp = 97
[10:15:08.307] INFO: ROC 7 VthrComp = 100
[10:15:08.307] INFO: ROC 8 VthrComp = 95
[10:15:08.307] INFO: ROC 9 VthrComp = 88
[10:15:08.307] INFO: ROC 10 VthrComp = 88
[10:15:08.307] INFO: ROC 11 VthrComp = 99
[10:15:08.307] INFO: ROC 12 VthrComp = 87
[10:15:08.307] INFO: ROC 13 VthrComp = 95
[10:15:08.308] INFO: ROC 14 VthrComp = 100
[10:15:08.308] INFO: ROC 15 VthrComp = 104
[10:15:08.308] INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[10:15:08.308] INFO: ---> dac: vcal name: TrimThr1 ntrig: 5 dacrange: 0 .. 159 (20) hits flags = 16 (plus default)
[10:15:08.317] INFO: dacScan step from 0 .. 19
[10:15:08.317] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:15:20.711] INFO: Test took 12394ms.
[10:15:20.733] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:15:20.733] INFO: dacScan step from 20 .. 39
[10:15:20.733] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:15:33.220] INFO: Test took 12487ms.
[10:15:33.250] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:15:33.253] INFO: dacScan step from 40 .. 59
[10:15:33.253] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:15:48.187] INFO: Test took 14934ms.
[10:15:48.333] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:15:48.358] INFO: dacScan step from 60 .. 79
[10:15:48.358] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:16:05.085] INFO: Test took 16727ms.
[10:16:05.249] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:16:05.276] INFO: dacScan step from 80 .. 99
[10:16:05.276] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:16:21.985] INFO: Test took 16709ms.
[10:16:22.148] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:16:22.177] INFO: dacScan step from 100 .. 119
[10:16:22.177] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:16:38.948] INFO: Test took 16771ms.
[10:16:39.112] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:16:39.140] INFO: dacScan step from 120 .. 139
[10:16:39.140] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:16:57.378] INFO: Test took 18238ms.
[10:16:57.542] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:16:57.570] INFO: dacScan step from 140 .. 159
[10:16:57.570] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:17:14.495] INFO: Test took 16925ms.
[10:17:14.658] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:17:14.686] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[10:17:16.062] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[10:17:17.447] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[10:17:18.856] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[10:17:20.228] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[10:17:21.593] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[10:17:22.994] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[10:17:24.370] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[10:17:25.731] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[10:17:27.089] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[10:17:28.455] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[10:17:29.841] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[10:17:31.202] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[10:17:32.555] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[10:17:33.909] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[10:17:35.280] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[10:17:36.660] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 564318208
[10:17:36.662] INFO: roc 0 with ID = 0 has maximal Vcal 62.9547 for pixel 6/3 mean/min/max = 47.8208/32.5786/63.0631
[10:17:36.662] INFO: roc 1 with ID = 1 has maximal Vcal 63.583 for pixel 27/2 mean/min/max = 48.5151/33.3347/63.6955
[10:17:36.662] INFO: roc 2 with ID = 2 has maximal Vcal 68.4907 for pixel 12/5 mean/min/max = 51.7778/34.7699/68.7857
[10:17:36.662] INFO: roc 3 with ID = 3 has maximal Vcal 64.4487 for pixel 1/1 mean/min/max = 48.312/32.1081/64.5159
[10:17:36.663] INFO: roc 4 with ID = 4 has maximal Vcal 57.1003 for pixel 2/64 mean/min/max = 44.4727/31.5128/57.4325
[10:17:36.663] INFO: roc 5 with ID = 5 has maximal Vcal 66.1046 for pixel 17/51 mean/min/max = 49.2589/32.3798/66.138
[10:17:36.663] INFO: roc 6 with ID = 6 has maximal Vcal 58.2065 for pixel 10/1 mean/min/max = 45.3661/32.4255/58.3067
[10:17:36.664] INFO: roc 7 with ID = 7 has maximal Vcal 61.4722 for pixel 18/4 mean/min/max = 47.1936/32.7015/61.6857
[10:17:36.664] INFO: roc 8 with ID = 8 has maximal Vcal 60.6429 for pixel 5/0 mean/min/max = 46.3984/32.147/60.6497
[10:17:36.664] INFO: roc 9 with ID = 9 has maximal Vcal 60.1659 for pixel 14/72 mean/min/max = 47.4078/34.6111/60.2045
[10:17:36.664] INFO: roc 10 with ID = 10 has maximal Vcal 65.4437 for pixel 16/39 mean/min/max = 49.8839/33.595/66.1728
[10:17:36.665] INFO: roc 11 with ID = 11 has maximal Vcal 57.7509 for pixel 11/54 mean/min/max = 44.9431/31.8274/58.0587
[10:17:36.665] INFO: roc 12 with ID = 12 has maximal Vcal 59.4616 for pixel 12/17 mean/min/max = 45.838/32.102/59.574
[10:17:36.665] INFO: roc 13 with ID = 13 has maximal Vcal 57.0796 for pixel 17/6 mean/min/max = 45.1327/33.1217/57.1437
[10:17:36.665] INFO: roc 14 with ID = 14 has maximal Vcal 59.5375 for pixel 51/76 mean/min/max = 45.9159/32.173/59.6588
[10:17:36.666] INFO: roc 15 with ID = 15 has maximal Vcal 64.158 for pixel 23/3 mean/min/max = 49.1585/34.1521/64.1649
[10:17:36.666] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:18:50.928] INFO: Test took 74262ms.
[10:18:51.704] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.2274 < 35 for itrim = 130; old thr = 34.031 ... break
[10:18:51.727] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.3283 < 35 for itrim = 118; old thr = 34.3086 ... break
[10:18:51.749] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.0249 < 35 for itrim = 122; old thr = 34.3872 ... break
[10:18:51.776] DEBUG: <PixTestTrim.cc/trimTest:L309> vtrim: vcal = 35.6576 < 35 for itrim+1 = 119; old thr = 34.7763 ... break
[10:18:51.805] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.2116 < 35 for itrim = 103; old thr = 33.5802 ... break
[10:18:51.825] DEBUG: <PixTestTrim.cc/trimTest:L309> vtrim: vcal = 35.2042 < 35 for itrim+1 = 130; old thr = 34.8068 ... break
[10:18:51.851] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.1452 < 35 for itrim = 110; old thr = 34.1135 ... break
[10:18:51.880] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.034 < 35 for itrim = 128; old thr = 33.6539 ... break
[10:18:51.907] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.1172 < 35 for itrim = 123; old thr = 34.4186 ... break
[10:18:51.930] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.637 < 35 for itrim = 111; old thr = 33.6872 ... break
[10:18:51.949] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.5055 < 35 for itrim = 121; old thr = 34.1128 ... break
[10:18:51.973] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.2249 < 35 for itrim = 100; old thr = 34.0393 ... break
[10:18:51.003] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.1674 < 35 for itrim = 107; old thr = 34.8262 ... break
[10:18:52.032] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.2231 < 35 for itrim = 112; old thr = 34.2608 ... break
[10:18:52.057] DEBUG: <PixTestTrim.cc/trimTest:L309> vtrim: vcal = 36.0878 < 35 for itrim+1 = 94; old thr = 34.9648 ... break
[10:18:52.082] DEBUG: <PixTestTrim.cc/trimTest:L309> vtrim: vcal = 36.5847 < 35 for itrim+1 = 142; old thr = 33.524 ... break
[10:18:52.145] INFO: ---> dac: vcal name: TrimThr2 ntrig: 10 dacrange: 0 .. 199 (20) hits flags = 16 (plus default)
[10:18:52.154] INFO: dacScan step from 0 .. 19
[10:18:52.154] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:19:10.363] INFO: Test took 18209ms.
[10:19:10.412] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:19:10.414] INFO: dacScan step from 20 .. 39
[10:19:10.414] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:19:32.515] INFO: Test took 22101ms.
[10:19:32.740] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:19:32.768] INFO: dacScan step from 40 .. 59
[10:19:32.768] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:19:48.571] ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (0) != Token Chain Length (8)

[10:19:48.571] ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (0) != Token Chain Length (8)

[10:19:48.571] ERROR: <datapipe.cc/CheckEventID:L420> Event ID mismatch: local ID (145) != TBM ID (146)

[10:19:48.571] ERROR: <datapipe.cc/CheckEventID:L420> Event ID mismatch: local ID (145) != TBM ID (146)

[10:19:48.571] WARNING: ROC 5: Readback start marker after 15 readouts!

[10:19:48.571] WARNING: ROC 6: Readback start marker after 15 readouts!

[10:19:48.571] WARNING: ROC 4: Readback start marker after 15 readouts!

[10:19:48.571] WARNING: ROC 7: Readback start marker after 15 readouts!

[10:19:48.571] WARNING: ROC 2: Readback start marker after 15 readouts!

[10:19:48.571] WARNING: ROC 7: Readback start marker after 15 readouts!

[10:19:48.571] WARNING: ROC 3: Readback start marker after 15 readouts!

[10:19:48.571] WARNING: ROC 2: Readback start marker after 15 readouts!

[10:19:48.571] WARNING: ROC 1: Readback start marker after 15 readouts!

[10:19:48.571] WARNING: ROC 5: Readback start marker after 15 readouts!

[10:19:48.571] WARNING: ROC 6: Readback start marker after 15 readouts!

[10:19:48.571] WARNING: ROC 0: Readback start marker after 15 readouts!

[10:19:48.571] WARNING: ROC 3: Readback start marker after 15 readouts!

[10:19:48.571] WARNING: ROC 4: Readback start marker after 15 readouts!

[10:19:48.571] WARNING: ROC 0: Readback start marker after 15 readouts!

[10:19:48.571] WARNING: ROC 1: Readback start marker after 15 readouts!

[10:19:59.570] INFO: Test took 26802ms.
[10:19:59.852] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:19:59.880] INFO: dacScan step from 60 .. 79
[10:19:59.880] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:20:26.824] INFO: Test took 26945ms.
[10:20:27.107] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:20:27.137] INFO: dacScan step from 80 .. 99
[10:20:27.137] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:20:54.068] INFO: Test took 26931ms.
[10:20:54.347] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:20:54.375] INFO: dacScan step from 100 .. 119
[10:20:54.375] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:21:21.387] INFO: Test took 27012ms.
[10:21:21.666] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:21:21.694] INFO: dacScan step from 120 .. 139
[10:21:21.694] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:21:50.150] INFO: Test took 28456ms.
[10:21:50.432] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:21:50.460] INFO: dacScan step from 140 .. 159
[10:21:50.460] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:22:17.608] INFO: Test took 27148ms.
[10:22:17.886] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:22:17.914] INFO: dacScan step from 160 .. 179
[10:22:17.914] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:22:44.964] INFO: Test took 27050ms.
[10:22:45.243] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:22:45.271] INFO: dacScan step from 180 .. 199
[10:22:45.271] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:23:13.097] INFO: Test took 27826ms.
[10:23:13.380] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:23:13.408] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[10:23:14.846] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[10:23:16.299] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[10:23:17.767] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[10:23:19.183] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[10:23:20.595] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[10:23:22.051] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[10:23:23.455] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[10:23:24.886] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[10:23:26.290] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[10:23:27.723] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[10:23:29.165] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[10:23:30.567] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[10:23:31.963] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[10:23:33.365] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[10:23:34.786] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[10:23:36.229] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 568811520
[10:23:36.230] INFO: ---> TrimStepCorr4 extremal thresholds: 0.063379 .. 255.000000
[10:23:36.293] INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 4 dacrange: 0 .. 255 (20) hits flags = 16 (plus default)
[10:23:36.301] INFO: dacScan step from 0 .. 19
[10:23:36.301] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:23:47.548] INFO: Test took 11247ms.
[10:23:47.569] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:23:47.569] INFO: dacScan step from 20 .. 39
[10:23:47.569] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:23:59.634] INFO: Test took 12065ms.
[10:23:59.714] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:23:59.730] INFO: dacScan step from 40 .. 59
[10:23:59.730] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:24:14.250] INFO: Test took 14520ms.
[10:24:14.400] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:24:14.429] INFO: dacScan step from 60 .. 79
[10:24:14.429] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:24:29.179] INFO: Test took 14750ms.
[10:24:29.323] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:24:29.351] INFO: dacScan step from 80 .. 99
[10:24:29.351] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:24:44.090] INFO: Test took 14740ms.
[10:24:44.234] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:24:44.262] INFO: dacScan step from 100 .. 119
[10:24:44.262] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:24:59.085] INFO: Test took 14823ms.
[10:24:59.228] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:24:59.257] INFO: dacScan step from 120 .. 139
[10:24:59.257] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:25:15.558] INFO: Test took 16301ms.
[10:25:15.700] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:25:15.727] INFO: dacScan step from 140 .. 159
[10:25:15.728] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:25:30.712] INFO: Test took 14984ms.
[10:25:30.855] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:25:30.882] INFO: dacScan step from 160 .. 179
[10:25:30.882] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:25:45.786] INFO: Test took 14904ms.
[10:25:45.928] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:25:45.956] INFO: dacScan step from 180 .. 199
[10:25:45.956] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:26:01.607] INFO: Test took 15651ms.
[10:26:01.750] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:26:01.778] INFO: dacScan step from 200 .. 219
[10:26:01.778] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:26:16.527] INFO: Test took 14749ms.
[10:26:16.670] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:26:16.698] INFO: dacScan step from 220 .. 239
[10:26:16.698] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:26:31.452] INFO: Test took 14754ms.
[10:26:31.595] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:26:31.623] INFO: dacScan step from 240 .. 255
[10:26:31.623] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:26:43.924] INFO: Test took 12301ms.
[10:26:44.039] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:26:44.062] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[10:26:45.784] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[10:26:47.518] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[10:26:49.261] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[10:26:50.976] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[10:26:52.692] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[10:26:54.426] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[10:26:56.143] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[10:26:57.864] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[10:26:59.585] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[10:27:01.296] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[10:27:03.035] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[10:27:04.758] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[10:27:06.469] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[10:27:08.186] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[10:27:09.913] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[10:27:11.642] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 568815616
[10:27:11.708] INFO: ---> TrimStepCorr2 extremal thresholds: 2.010413 .. 66.073253
[10:27:11.770] INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 4 dacrange: 2 .. 76 (20) hits flags = 16 (plus default)
[10:27:11.779] INFO: dacScan step from 2 .. 21
[10:27:11.779] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:27:23.036] INFO: Test took 11257ms.
[10:27:23.057] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:27:23.057] INFO: dacScan step from 22 .. 41
[10:27:23.058] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:27:35.392] INFO: Test took 12334ms.
[10:27:35.484] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:27:35.503] INFO: dacScan step from 42 .. 61
[10:27:35.503] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:27:50.187] INFO: Test took 14684ms.
[10:27:50.334] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:27:50.362] INFO: dacScan step from 62 .. 76
[10:27:50.362] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:28:02.024] INFO: Test took 11662ms.
[10:28:02.132] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:28:02.153] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[10:28:03.158] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[10:28:04.158] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[10:28:05.166] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[10:28:06.175] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[10:28:07.175] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[10:28:08.179] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[10:28:09.189] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[10:28:10.193] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[10:28:11.201] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[10:28:12.200] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[10:28:13.203] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[10:28:14.200] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[10:28:15.196] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[10:28:16.193] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[10:28:17.192] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[10:28:18.185] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 568938496
[10:28:18.251] INFO: ---> TrimStepCorr1a extremal thresholds: 12.205892 .. 55.976230
[10:28:18.313] INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 4 dacrange: 2 .. 65 (20) hits flags = 16 (plus default)
[10:28:18.322] INFO: dacScan step from 2 .. 21
[10:28:18.322] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:28:29.585] INFO: Test took 11263ms.
[10:28:29.606] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:28:29.606] INFO: dacScan step from 22 .. 41
[10:28:29.606] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:28:41.915] INFO: Test took 12309ms.
[10:28:41.005] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:28:42.024] INFO: dacScan step from 42 .. 61
[10:28:42.024] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:28:56.739] INFO: Test took 14715ms.
[10:28:56.884] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:28:56.912] INFO: dacScan step from 62 .. 65
[10:28:56.912] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:29:01.856] INFO: Test took 4944ms.
[10:29:01.886] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:29:01.897] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[10:29:02.822] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[10:29:03.752] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[10:29:04.679] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[10:29:05.600] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[10:29:06.520] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[10:29:07.438] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[10:29:08.364] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[10:29:09.283] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[10:29:10.200] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[10:29:11.123] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[10:29:12.040] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[10:29:12.962] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[10:29:13.888] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[10:29:14.818] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[10:29:15.743] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[10:29:16.670] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 568938496
[10:29:16.737] INFO: ---> TrimStepCorr1b extremal thresholds: 0.342902 .. 42.714422
[10:29:16.799] INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 4 dacrange: 0 .. 52 (20) hits flags = 16 (plus default)
[10:29:16.807] INFO: dacScan step from 0 .. 19
[10:29:16.808] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:29:28.055] INFO: Test took 11247ms.
[10:29:28.076] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:29:28.076] INFO: dacScan step from 20 .. 39
[10:29:28.076] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:29:40.085] INFO: Test took 12009ms.
[10:29:40.157] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:29:40.172] INFO: dacScan step from 40 .. 52
[10:29:40.173] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:29:50.565] INFO: Test took 10392ms.
[10:29:50.664] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:29:50.683] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[10:29:51.500] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[10:29:52.315] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[10:29:53.126] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[10:29:53.951] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[10:29:54.776] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[10:29:55.602] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[10:29:56.425] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[10:29:57.245] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[10:29:58.065] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[10:29:58.890] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[10:29:59.710] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[10:30:00.530] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[10:30:01.347] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[10:30:02.167] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[10:30:02.992] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[10:30:03.815] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 568938496
[10:30:03.882] INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[10:30:03.882] INFO: ---> dac: vcal name: TrimThrFinal ntrig: 10 dacrange: 15 .. 55 (20) hits flags = 16 (plus default)
[10:30:03.890] INFO: dacScan step from 15 .. 34
[10:30:03.890] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:30:22.384] INFO: Test took 18493ms.
[10:30:22.454] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:30:22.464] INFO: dacScan step from 35 .. 54
[10:30:22.465] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:30:48.599] INFO: Test took 26134ms.
[10:30:48.892] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:30:48.922] INFO: dacScan step from 55 .. 55
[10:30:48.922] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:30:52.643] INFO: Test took 3721ms.
[10:30:52.659] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:30:52.662] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[10:30:53.427] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[10:30:54.187] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[10:30:54.944] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[10:30:55.708] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[10:30:56.469] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[10:30:57.226] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[10:30:57.991] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[10:30:58.756] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[10:30:59.527] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[10:31:00.291] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[10:31:01.051] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[10:31:01.817] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[10:31:02.590] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[10:31:03.365] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[10:31:04.131] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[10:31:04.894] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 568942592
[10:31:04.945] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//dacParameters35_C0.dat
[10:31:04.946] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//dacParameters35_C1.dat
[10:31:04.946] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//dacParameters35_C2.dat
[10:31:04.946] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//dacParameters35_C3.dat
[10:31:04.946] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//dacParameters35_C4.dat
[10:31:04.946] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//dacParameters35_C5.dat
[10:31:04.946] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//dacParameters35_C6.dat
[10:31:04.946] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//dacParameters35_C7.dat
[10:31:04.946] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//dacParameters35_C8.dat
[10:31:04.946] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//dacParameters35_C9.dat
[10:31:04.946] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//dacParameters35_C10.dat
[10:31:04.946] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//dacParameters35_C11.dat
[10:31:04.946] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//dacParameters35_C12.dat
[10:31:04.946] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//dacParameters35_C13.dat
[10:31:04.946] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//dacParameters35_C14.dat
[10:31:04.947] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//dacParameters35_C15.dat
[10:31:04.947] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//trimParameters35_C0.dat
[10:31:04.952] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//trimParameters35_C1.dat
[10:31:04.957] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//trimParameters35_C2.dat
[10:31:04.963] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//trimParameters35_C3.dat
[10:31:04.968] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//trimParameters35_C4.dat
[10:31:04.974] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//trimParameters35_C5.dat
[10:31:04.979] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//trimParameters35_C6.dat
[10:31:04.984] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//trimParameters35_C7.dat
[10:31:04.990] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//trimParameters35_C8.dat
[10:31:04.995] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//trimParameters35_C9.dat
[10:31:04.001] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//trimParameters35_C10.dat
[10:31:04.006] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//trimParameters35_C11.dat
[10:31:05.011] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//trimParameters35_C12.dat
[10:31:05.017] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//trimParameters35_C13.dat
[10:31:05.022] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//trimParameters35_C14.dat
[10:31:05.028] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//trimParameters35_C15.dat
[10:31:05.033] INFO: PixTestTrim::trimTest() done
[10:31:05.033] INFO: vtrim: 130 118 122 119 103 130 110 128 123 111 121 100 107 112 94 142
[10:31:05.033] INFO: vthrcomp: 103 104 107 101 99 100 97 100 95 88 88 99 87 95 100 104
[10:31:05.033] INFO: vcal mean: 35.04 35.01 35.01 35.01 34.99 35.10 35.07 35.09 34.98 34.96 35.05 35.00 35.00 34.90 35.04 35.04
[10:31:05.033] INFO: vcal RMS: 1.59 1.70 1.37 1.20 1.11 1.45 1.11 1.08 1.27 1.09 1.28 1.10 1.18 1.51 1.09 1.37
[10:31:05.033] INFO: bits mean: 9.27 8.98 8.54 9.10 10.09 9.50 10.24 9.30 9.76 9.27 9.24 10.06 9.58 9.97 9.00 9.10
[10:31:05.033] INFO: bits RMS: 2.52 2.57 2.31 2.66 2.60 2.42 2.32 2.61 2.48 2.35 2.34 2.52 2.60 2.40 2.83 2.43
[10:31:05.038] INFO: ----------------------------------------------------------------------
[10:31:05.038] INFO: PixTestTrim::trimBitTest() ntrig = 10, vtrims = 255 240 150 100
[10:31:05.038] INFO: ----------------------------------------------------------------------
[10:31:05.043] DEBUG: <PixTestTrim.cc/trimBitTest:L515> trimBitTest determine threshold map without trims
[10:31:05.043] INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 10 dacrange: 0 .. 199 (20) hits flags = 16 (plus default)
[10:31:05.051] INFO: dacScan step from 0 .. 19
[10:31:05.051] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:31:23.187] INFO: Test took 18136ms.
[10:31:23.223] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:31:23.223] INFO: dacScan step from 20 .. 39
[10:31:23.223] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:31:41.482] INFO: Test took 18258ms.
[10:31:41.534] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:31:41.537] INFO: dacScan step from 40 .. 59
[10:31:41.537] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:32:04.619] INFO: Test took 23082ms.
[10:32:04.858] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:32:04.885] INFO: dacScan step from 60 .. 79
[10:32:04.885] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:32:31.822] INFO: Test took 26937ms.
[10:32:32.103] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:32:32.132] INFO: dacScan step from 80 .. 99
[10:32:32.132] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:32:59.033] INFO: Test took 26901ms.
[10:32:59.313] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:32:59.341] INFO: dacScan step from 100 .. 119
[10:32:59.341] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:33:26.325] INFO: Test took 26984ms.
[10:33:26.600] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:33:26.627] INFO: dacScan step from 120 .. 139
[10:33:26.628] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:33:55.154] INFO: Test took 28526ms.
[10:33:55.427] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:33:55.466] INFO: dacScan step from 140 .. 159
[10:33:55.466] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:34:22.675] INFO: Test took 27209ms.
[10:34:22.949] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:34:22.977] INFO: dacScan step from 160 .. 179
[10:34:22.977] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:34:50.035] INFO: Test took 27058ms.
[10:34:50.307] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:34:50.335] INFO: dacScan step from 180 .. 199
[10:34:50.335] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:35:18.142] INFO: Test took 27807ms.
[10:35:18.418] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:35:18.446] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[10:35:19.829] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[10:35:21.228] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[10:35:22.659] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[10:35:24.043] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[10:35:25.406] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[10:35:26.834] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[10:35:28.204] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[10:35:29.588] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[10:35:30.961] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[10:35:32.339] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[10:35:33.758] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[10:35:35.137] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[10:35:36.496] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[10:35:37.860] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[10:35:39.238] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[10:35:40.635] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 568954880
[10:35:40.636] DEBUG: <PixTestTrim.cc/trimBitTest:L530> trimBitTest initDUT with trim bits = 14
[10:35:40.699] DEBUG: <PixTestTrim.cc/trimBitTest:L536> trimBitTest threshold map with trim = 14
[10:35:40.699] INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 10 dacrange: 0 .. 134 (20) hits flags = 16 (plus default)
[10:35:40.707] INFO: dacScan step from 0 .. 19
[10:35:40.707] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:35:58.856] INFO: Test took 18149ms.
[10:35:58.894] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:35:58.894] INFO: dacScan step from 20 .. 39
[10:35:58.894] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:36:17.583] INFO: Test took 18689ms.
[10:36:17.665] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:36:17.673] INFO: dacScan step from 40 .. 59
[10:36:17.673] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:36:42.346] INFO: Test took 24673ms.
[10:36:42.618] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:36:42.647] INFO: dacScan step from 60 .. 79
[10:36:42.647] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:37:09.584] INFO: Test took 26937ms.
[10:37:09.855] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:37:09.883] INFO: dacScan step from 80 .. 99
[10:37:09.883] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:37:36.782] INFO: Test took 26899ms.
[10:37:37.052] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:37:37.080] INFO: dacScan step from 100 .. 119
[10:37:37.080] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:38:04.152] INFO: Test took 27072ms.
[10:38:04.429] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:38:04.457] INFO: dacScan step from 120 .. 134
[10:38:04.457] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:38:26.104] INFO: Test took 21647ms.
[10:38:26.310] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:38:26.332] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[10:38:27.505] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[10:38:28.688] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[10:38:29.868] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[10:38:31.043] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[10:38:32.220] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[10:38:33.405] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[10:38:34.577] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[10:38:35.739] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[10:38:36.910] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[10:38:38.074] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[10:38:39.239] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[10:38:40.409] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[10:38:41.582] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[10:38:42.754] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[10:38:43.929] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[10:38:45.095] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 568954880
[10:38:45.096] DEBUG: <PixTestTrim.cc/trimBitTest:L530> trimBitTest initDUT with trim bits = 13
[10:38:45.158] DEBUG: <PixTestTrim.cc/trimBitTest:L536> trimBitTest threshold map with trim = 13
[10:38:45.158] INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 10 dacrange: 0 .. 118 (20) hits flags = 16 (plus default)
[10:38:45.167] INFO: dacScan step from 0 .. 19
[10:38:45.167] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:39:03.296] INFO: Test took 18129ms.
[10:39:03.334] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:39:03.335] INFO: dacScan step from 20 .. 39
[10:39:03.335] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:39:22.816] INFO: Test took 19481ms.
[10:39:22.939] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:39:22.953] INFO: dacScan step from 40 .. 59
[10:39:22.953] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:39:48.839] INFO: Test took 25886ms.
[10:39:49.124] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:39:49.154] INFO: dacScan step from 60 .. 79
[10:39:49.154] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:40:16.148] INFO: Test took 26994ms.
[10:40:16.422] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:40:16.450] INFO: dacScan step from 80 .. 99
[10:40:16.450] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:40:43.377] INFO: Test took 26927ms.
[10:40:43.653] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:40:43.681] INFO: dacScan step from 100 .. 118
[10:40:43.681] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:41:09.497] INFO: Test took 25816ms.
[10:41:09.759] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:41:09.786] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[10:41:10.882] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[10:41:11.979] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[10:41:13.083] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[10:41:14.178] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[10:41:15.271] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[10:41:16.365] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[10:41:17.466] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[10:41:18.565] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[10:41:19.659] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[10:41:20.751] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[10:41:21.846] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[10:41:22.939] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[10:41:24.027] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[10:41:25.125] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[10:41:26.223] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[10:41:27.325] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 568958976
[10:41:27.326] DEBUG: <PixTestTrim.cc/trimBitTest:L530> trimBitTest initDUT with trim bits = 11
[10:41:27.389] DEBUG: <PixTestTrim.cc/trimBitTest:L536> trimBitTest threshold map with trim = 11
[10:41:27.389] INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 10 dacrange: 0 .. 107 (20) hits flags = 16 (plus default)
[10:41:27.397] INFO: dacScan step from 0 .. 19
[10:41:27.397] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:41:45.549] INFO: Test took 18151ms.
[10:41:45.588] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:41:45.588] INFO: dacScan step from 20 .. 39
[10:41:45.588] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:42:05.685] INFO: Test took 20097ms.
[10:42:05.838] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:42:05.858] INFO: dacScan step from 40 .. 59
[10:42:05.858] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:42:32.153] INFO: Test took 26295ms.
[10:42:32.433] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:42:32.462] INFO: dacScan step from 60 .. 79
[10:42:32.462] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:42:59.521] INFO: Test took 27059ms.
[10:42:59.799] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:42:59.827] INFO: dacScan step from 80 .. 99
[10:42:59.827] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:43:26.845] INFO: Test took 27018ms.
[10:43:27.124] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:43:27.153] INFO: dacScan step from 100 .. 107
[10:43:27.153] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:43:39.384] INFO: Test took 12231ms.
[10:43:39.493] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:43:39.506] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[10:43:40.540] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[10:43:41.578] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[10:43:42.615] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[10:43:43.647] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[10:43:44.691] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[10:43:45.733] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[10:43:46.779] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[10:43:47.820] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[10:43:48.857] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[10:43:49.901] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[10:43:50.935] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[10:43:51.975] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[10:43:53.016] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[10:43:54.059] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[10:43:55.104] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[10:43:56.147] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 568958976
[10:43:56.148] DEBUG: <PixTestTrim.cc/trimBitTest:L530> trimBitTest initDUT with trim bits = 7
[10:43:56.210] DEBUG: <PixTestTrim.cc/trimBitTest:L536> trimBitTest threshold map with trim = 7
[10:43:56.210] INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 10 dacrange: 0 .. 101 (20) hits flags = 16 (plus default)
[10:43:56.219] INFO: dacScan step from 0 .. 19
[10:43:56.219] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:44:14.402] INFO: Test took 18183ms.
[10:44:14.444] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:44:14.445] INFO: dacScan step from 20 .. 39
[10:44:14.445] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:44:35.697] INFO: Test took 21252ms.
[10:44:35.893] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:44:35.915] INFO: dacScan step from 40 .. 59
[10:44:35.915] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:45:02.600] INFO: Test took 26685ms.
[10:45:02.886] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:45:02.914] INFO: dacScan step from 60 .. 79
[10:45:02.914] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:45:29.806] INFO: Test took 26892ms.
[10:45:30.082] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:45:30.110] INFO: dacScan step from 80 .. 99
[10:45:30.110] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:45:57.084] INFO: Test took 26974ms.
[10:45:57.362] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:45:57.390] INFO: dacScan step from 100 .. 101
[10:45:57.390] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:46:02.326] INFO: Test took 4936ms.
[10:46:02.355] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:46:02.361] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[10:46:03.369] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[10:46:04.383] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[10:46:05.395] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[10:46:06.405] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[10:46:07.425] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[10:46:08.440] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[10:46:09.453] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[10:46:10.463] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[10:46:11.476] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[10:46:12.487] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[10:46:13.495] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[10:46:14.511] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[10:46:15.526] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[10:46:16.540] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[10:46:17.556] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[10:46:18.570] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 568958976
[10:46:18.686] INFO: PixTestTrim::trimBitTest() done
[10:46:18.688] INFO: PixTestTrim::doTest() done, duration: 1996 seconds
[10:46:18.688] DEBUG: <PixTestTrim.cc/~PixTestTrim:L104> PixTestTrim dtor
[10:46:19.264] DEBUG: <PixTest.cc/setTestParameter:L569> setting ntrig to new value 10
[10:46:19.264] DEBUG: <PixTestPhOptimization.cc/setParameter:L37> setting fParNtrig ->10<- from sval = 10
[10:46:19.264] DEBUG: <PixTestPhOptimization.cc/setParameter:L42> setting fSafetyMarginLow ->20<- from sval = 20
[10:46:19.264] DEBUG: <PixTestPhOptimization.cc/setParameter:L48> setting fVcalMax ->100<- from sval = 100
[10:46:19.264] DEBUG: <PixTestPhOptimization.cc/setParameter:L53> setting fQuantMax ->0.98<- from sval = 0.98
[10:46:19.264] INFO: ######################################################################
[10:46:19.264] INFO: PixTestPhOptimization::doTest() Ntrig = 10
[10:46:19.264] INFO: ######################################################################
[10:46:19.266] DEBUG: <PixTest.cc/efficiencyMaps:L328> attempt #0
[10:46:22.954] INFO: Test took 3688ms.
[10:46:22.972] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:46:22.972] DEBUG: <PixTest.cc/efficiencyMaps:L339> eff result size = 66536
[10:46:22.972] DEBUG: <PixTest.cc/efficiencyMaps:L344> Create hists PixelAlive_C0 .. PixelAlive_C15
[10:46:22.975] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [0, 0, 0] has eff 0/10
[10:46:22.975] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [0, 0, 0]
[10:46:22.975] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [0, 0, 1] has eff 0/10
[10:46:22.975] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [0, 0, 1]
[10:46:22.976] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [0, 40, 27] has eff 2/10
[10:46:22.976] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [0, 40, 27]
[10:46:22.976] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [0, 40, 28] has eff 0/10
[10:46:22.976] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [0, 40, 28]
[10:46:22.976] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [0, 28, 49] has eff 0/10
[10:46:22.976] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [0, 28, 49]
[10:46:22.976] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [0, 49, 78] has eff 1/10
[10:46:22.976] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [0, 49, 78]
[10:46:22.976] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [1, 16, 9] has eff 0/10
[10:46:22.976] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [1, 16, 9]
[10:46:22.976] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [1, 17, 9] has eff 0/10
[10:46:22.976] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [1, 17, 9]
[10:46:22.976] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [1, 16, 10] has eff 0/10
[10:46:22.976] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [1, 16, 10]
[10:46:22.976] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [1, 17, 10] has eff 0/10
[10:46:22.976] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [1, 17, 10]
[10:46:22.976] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [1, 43, 46] has eff 0/10
[10:46:22.976] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [1, 43, 46]
[10:46:22.976] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [1, 37, 63] has eff 0/10
[10:46:22.976] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [1, 37, 63]
[10:46:22.976] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [2, 11, 62] has eff 0/10
[10:46:22.976] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [2, 11, 62]
[10:46:22.976] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [2, 42, 75] has eff 0/10
[10:46:22.976] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [2, 42, 75]
[10:46:22.976] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [3, 39, 42] has eff 3/10
[10:46:22.976] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [3, 39, 42]
[10:46:22.976] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [5, 33, 35] has eff 7/10
[10:46:22.976] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [5, 33, 35]
[10:46:22.976] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [5, 46, 36] has eff 0/10
[10:46:22.976] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [5, 46, 36]
[10:46:22.976] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [5, 25, 56] has eff 5/10
[10:46:22.976] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [5, 25, 56]
[10:46:22.977] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [5, 50, 70] has eff 0/10
[10:46:22.977] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [5, 50, 70]
[10:46:22.977] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [7, 3, 70] has eff 9/10
[10:46:22.977] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [7, 3, 70]
[10:46:22.977] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [8, 0, 70] has eff 0/10
[10:46:22.977] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [8, 0, 70]
[10:46:22.977] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [8, 46, 75] has eff 0/10
[10:46:22.977] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [8, 46, 75]
[10:46:22.977] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [10, 47, 20] has eff 0/10
[10:46:22.977] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [10, 47, 20]
[10:46:22.977] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [12, 21, 22] has eff 1/10
[10:46:22.977] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [12, 21, 22]
[10:46:22.977] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [12, 30, 49] has eff 0/10
[10:46:22.977] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [12, 30, 49]
[10:46:22.978] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [13, 49, 14] has eff 0/10
[10:46:22.978] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [13, 49, 14]
[10:46:22.978] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [13, 2, 73] has eff 0/10
[10:46:22.978] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [13, 2, 73]
[10:46:22.978] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [13, 18, 76] has eff 0/10
[10:46:22.978] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [13, 18, 76]
[10:46:22.978] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [13, 19, 76] has eff 0/10
[10:46:22.978] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [13, 19, 76]
[10:46:22.978] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [15, 50, 0] has eff 0/10
[10:46:22.978] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [15, 50, 0]
[10:46:22.978] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [15, 51, 0] has eff 0/10
[10:46:22.978] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [15, 51, 0]
[10:46:22.983] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L239> Number of bad pixels found: 31
[10:46:22.983] DEBUG: <PixTestPhOptimization.cc/doTest:L124> **********Ph range will be optimised on the whole ROC***********
[10:46:22.983] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L276> ROC type is newer than digv2
[10:46:22.983] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L277> ROC type is psi46digv21respin
[10:46:23.172] DEBUG: <PixTest.cc/phMaps:L264> attempt #0
[10:46:26.859] INFO: Test took 3687ms.
[10:46:26.919] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:46:26.919] DEBUG: <PixTest.cc/phMaps:L275> eff result size = 66535
[10:46:26.919] DEBUG: <PixTest.cc/phMaps:L282> Create hists maxphmap_C0 .. maxphmap_C15
[10:46:26.923] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 175.926
[10:46:26.923] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,6] phvalue 176
[10:46:26.923] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 174.283
[10:46:26.923] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [4 ,7] phvalue 174
[10:46:26.924] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 170.652
[10:46:26.924] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [6 ,5] phvalue 171
[10:46:26.924] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 175.683
[10:46:26.924] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [14 ,7] phvalue 175
[10:46:26.924] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 165.202
[10:46:26.924] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [6 ,5] phvalue 166
[10:46:26.924] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 171.467
[10:46:26.924] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [4 ,5] phvalue 172
[10:46:26.924] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 181.394
[10:46:26.924] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [6 ,8] phvalue 182
[10:46:26.924] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 176.083
[10:46:26.924] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,5] phvalue 177
[10:46:26.924] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 171.304
[10:46:26.924] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [4 ,7] phvalue 171
[10:46:26.924] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 165.148
[10:46:26.924] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [4 ,6] phvalue 165
[10:46:26.925] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 179.34
[10:46:26.925] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,7] phvalue 180
[10:46:26.925] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 184.031
[10:46:26.925] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,16] phvalue 184
[10:46:26.925] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 177.019
[10:46:26.925] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,5] phvalue 177
[10:46:26.925] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 167.602
[10:46:26.925] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,6] phvalue 168
[10:46:26.925] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 166.117
[10:46:26.925] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [4 ,5] phvalue 167
[10:46:26.925] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 173.025
[10:46:26.925] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,10] phvalue 173
[10:46:26.925] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L427> ROC type is newer than digv2
[10:46:26.925] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L428> ROC type is psi46digv21respin
[10:46:26.925] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L450> init_phScale=150, flag_minPh = 0, minph = 0
[10:46:26.933] DEBUG: <PixTest.cc/phMaps:L264> attempt #0
[10:46:30.636] INFO: Test took 3703ms.
[10:46:30.696] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:46:30.696] DEBUG: <PixTest.cc/phMaps:L275> eff result size = 66534
[10:46:30.696] DEBUG: <PixTest.cc/phMaps:L282> Create hists minphmap_C0 .. minphmap_C15
[10:46:30.699] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L457> result size 0

[10:46:30.700] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L484> done. init_phScale=155, flag_minPh = 1, minph = 55minph_roc = 4
[10:46:30.700] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 71.3108
[10:46:30.700] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [4 ,12] phvalue 72
[10:46:30.700] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 75.8078
[10:46:30.700] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,26] phvalue 76
[10:46:30.700] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 60.1783
[10:46:30.700] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,6] phvalue 61
[10:46:30.700] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 70.5614
[10:46:30.700] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,32] phvalue 71
[10:46:30.700] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 60.1893
[10:46:30.700] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,10] phvalue 61
[10:46:30.701] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 61.696
[10:46:30.701] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,43] phvalue 62
[10:46:30.701] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 76.7016
[10:46:30.701] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,32] phvalue 77
[10:46:30.701] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 70.7741
[10:46:30.701] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [4 ,13] phvalue 71
[10:46:30.701] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 65.8132
[10:46:30.701] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [7 ,67] phvalue 66
[10:46:30.701] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 67.3061
[10:46:30.701] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,6] phvalue 68
[10:46:30.701] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 67.8844
[10:46:30.701] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [6 ,14] phvalue 68
[10:46:30.701] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 78.5558
[10:46:30.701] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [14 ,25] phvalue 79
[10:46:30.701] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 70.4291
[10:46:30.701] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [4 ,68] phvalue 71
[10:46:30.702] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 64.8265
[10:46:30.702] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [8 ,42] phvalue 65
[10:46:30.702] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 64.3118
[10:46:30.702] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,24] phvalue 65
[10:46:30.702] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 61.7721
[10:46:30.702] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [8 ,9] phvalue 62
[10:46:30.704] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 4, 12, 0 0
[10:46:30.704] INFO: The DUT currently contains the following objects:
[10:46:30.704] INFO: 2 TBM Cores tbm08c (2 ON)
[10:46:30.704] INFO: TBM Core alpha (0): 7 registers set
[10:46:30.704] INFO: TBM Core beta (1): 7 registers set
[10:46:30.704] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:46:30.704] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:30.704] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:30.704] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:30.704] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:30.704] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:30.704] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:30.704] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:30.704] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:30.704] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:30.704] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:30.704] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:30.704] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:30.704] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:30.704] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:30.704] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:30.704] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:31.795] INFO: Test took 1091ms.
[10:46:31.796] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[10:46:31.796] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 26, 1 1
[10:46:31.796] INFO: The DUT currently contains the following objects:
[10:46:31.796] INFO: 2 TBM Cores tbm08c (2 ON)
[10:46:31.796] INFO: TBM Core alpha (0): 7 registers set
[10:46:31.796] INFO: TBM Core beta (1): 7 registers set
[10:46:31.796] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:46:31.796] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:31.796] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:31.796] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:31.796] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:31.796] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:31.796] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:31.796] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:31.796] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:31.796] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:31.796] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:31.796] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:31.796] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:31.796] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:31.796] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:31.796] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:31.796] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:32.887] INFO: Test took 1091ms.
[10:46:32.887] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[10:46:32.887] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 6, 2 2
[10:46:32.887] INFO: The DUT currently contains the following objects:
[10:46:32.887] INFO: 2 TBM Cores tbm08c (2 ON)
[10:46:32.887] INFO: TBM Core alpha (0): 7 registers set
[10:46:32.887] INFO: TBM Core beta (1): 7 registers set
[10:46:32.888] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:46:32.888] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:32.888] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:32.888] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:32.888] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:32.888] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:32.888] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:32.888] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:32.888] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:32.888] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:32.888] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:32.888] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:32.888] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:32.888] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:32.888] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:32.888] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:32.888] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:33.978] INFO: Test took 1090ms.
[10:46:33.979] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[10:46:33.979] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 32, 3 3
[10:46:33.979] INFO: The DUT currently contains the following objects:
[10:46:33.979] INFO: 2 TBM Cores tbm08c (2 ON)
[10:46:33.979] INFO: TBM Core alpha (0): 7 registers set
[10:46:33.979] INFO: TBM Core beta (1): 7 registers set
[10:46:33.979] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:46:33.979] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:33.979] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:33.979] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:33.979] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:33.979] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:33.979] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:33.979] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:33.979] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:33.979] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:33.979] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:33.979] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:33.979] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:33.979] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:33.979] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:33.979] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:33.979] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:35.070] INFO: Test took 1091ms.
[10:46:35.070] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[10:46:35.070] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 10, 4 4
[10:46:35.070] INFO: The DUT currently contains the following objects:
[10:46:35.070] INFO: 2 TBM Cores tbm08c (2 ON)
[10:46:35.070] INFO: TBM Core alpha (0): 7 registers set
[10:46:35.070] INFO: TBM Core beta (1): 7 registers set
[10:46:35.070] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:46:35.070] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:35.070] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:35.070] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:35.070] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:35.070] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:35.070] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:35.071] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:35.071] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:35.071] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:35.071] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:35.071] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:35.071] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:35.071] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:35.071] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:35.071] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:35.071] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:36.162] INFO: Test took 1091ms.
[10:46:36.162] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[10:46:36.162] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 43, 5 5
[10:46:36.162] INFO: The DUT currently contains the following objects:
[10:46:36.162] INFO: 2 TBM Cores tbm08c (2 ON)
[10:46:36.162] INFO: TBM Core alpha (0): 7 registers set
[10:46:36.162] INFO: TBM Core beta (1): 7 registers set
[10:46:36.162] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:46:36.163] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:36.163] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:36.163] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:36.163] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:36.163] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:36.163] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:36.163] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:36.163] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:36.163] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:36.163] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:36.163] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:36.163] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:36.163] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:36.163] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:36.163] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:36.163] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:37.253] INFO: Test took 1090ms.
[10:46:37.254] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[10:46:37.254] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 32, 6 6
[10:46:37.254] INFO: The DUT currently contains the following objects:
[10:46:37.254] INFO: 2 TBM Cores tbm08c (2 ON)
[10:46:37.254] INFO: TBM Core alpha (0): 7 registers set
[10:46:37.254] INFO: TBM Core beta (1): 7 registers set
[10:46:37.254] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:46:37.254] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:37.254] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:37.254] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:37.254] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:37.254] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:37.254] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:37.254] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:37.254] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:37.254] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:37.254] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:37.254] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:37.254] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:37.254] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:37.254] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:37.254] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:37.254] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:38.345] INFO: Test took 1091ms.
[10:46:38.346] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[10:46:38.346] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 4, 13, 7 7
[10:46:38.346] INFO: The DUT currently contains the following objects:
[10:46:38.346] INFO: 2 TBM Cores tbm08c (2 ON)
[10:46:38.346] INFO: TBM Core alpha (0): 7 registers set
[10:46:38.346] INFO: TBM Core beta (1): 7 registers set
[10:46:38.346] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:46:38.346] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:38.346] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:38.346] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:38.346] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:38.346] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:38.346] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:38.346] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:38.346] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:38.346] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:38.346] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:38.346] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:38.346] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:38.346] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:38.346] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:38.346] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:38.346] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:39.437] INFO: Test took 1091ms.
[10:46:39.437] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[10:46:39.438] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 7, 67, 8 8
[10:46:39.438] INFO: The DUT currently contains the following objects:
[10:46:39.438] INFO: 2 TBM Cores tbm08c (2 ON)
[10:46:39.438] INFO: TBM Core alpha (0): 7 registers set
[10:46:39.438] INFO: TBM Core beta (1): 7 registers set
[10:46:39.438] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:46:39.438] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:39.438] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:39.438] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:39.438] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:39.438] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:39.438] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:39.438] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:39.438] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:39.438] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:39.438] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:39.438] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:39.438] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:39.438] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:39.438] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:39.438] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:39.438] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:40.529] INFO: Test took 1091ms.
[10:46:40.529] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[10:46:40.529] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 6, 9 9
[10:46:40.529] INFO: The DUT currently contains the following objects:
[10:46:40.529] INFO: 2 TBM Cores tbm08c (2 ON)
[10:46:40.529] INFO: TBM Core alpha (0): 7 registers set
[10:46:40.529] INFO: TBM Core beta (1): 7 registers set
[10:46:40.529] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:46:40.529] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:40.529] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:40.529] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:40.529] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:40.529] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:40.530] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:40.530] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:40.530] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:40.530] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:40.530] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:40.530] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:40.530] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:40.530] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:40.530] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:40.530] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:40.530] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:41.620] INFO: Test took 1090ms.
[10:46:41.621] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[10:46:41.621] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 6, 14, 10 10
[10:46:41.621] INFO: The DUT currently contains the following objects:
[10:46:41.621] INFO: 2 TBM Cores tbm08c (2 ON)
[10:46:41.621] INFO: TBM Core alpha (0): 7 registers set
[10:46:41.621] INFO: TBM Core beta (1): 7 registers set
[10:46:41.621] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:46:41.621] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:41.621] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:41.621] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:41.621] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:41.621] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:41.621] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:41.621] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:41.621] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:41.621] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:41.621] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:41.621] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:41.621] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:41.621] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:41.621] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:41.621] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:41.621] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:42.712] INFO: Test took 1091ms.
[10:46:42.713] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[10:46:42.713] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 14, 25, 11 11
[10:46:42.713] INFO: The DUT currently contains the following objects:
[10:46:42.713] INFO: 2 TBM Cores tbm08c (2 ON)
[10:46:42.713] INFO: TBM Core alpha (0): 7 registers set
[10:46:42.713] INFO: TBM Core beta (1): 7 registers set
[10:46:42.713] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:46:42.713] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:42.713] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:42.713] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:42.713] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:42.713] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:42.713] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:42.713] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:42.713] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:42.713] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:42.713] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:42.713] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:42.713] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:42.713] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:42.713] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:42.713] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:42.713] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:43.804] INFO: Test took 1091ms.
[10:46:43.804] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[10:46:43.804] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 4, 68, 12 12
[10:46:43.805] INFO: The DUT currently contains the following objects:
[10:46:43.805] INFO: 2 TBM Cores tbm08c (2 ON)
[10:46:43.805] INFO: TBM Core alpha (0): 7 registers set
[10:46:43.805] INFO: TBM Core beta (1): 7 registers set
[10:46:43.805] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:46:43.805] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:43.805] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:43.805] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:43.805] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:43.805] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:43.805] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:43.805] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:43.805] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:43.805] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:43.805] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:43.805] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:43.805] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:43.805] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:43.805] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:43.805] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:43.805] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:44.895] INFO: Test took 1090ms.
[10:46:44.896] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[10:46:44.896] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 8, 42, 13 13
[10:46:44.896] INFO: The DUT currently contains the following objects:
[10:46:44.896] INFO: 2 TBM Cores tbm08c (2 ON)
[10:46:44.896] INFO: TBM Core alpha (0): 7 registers set
[10:46:44.896] INFO: TBM Core beta (1): 7 registers set
[10:46:44.896] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:46:44.896] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:44.896] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:44.896] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:44.896] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:44.896] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:44.896] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:44.896] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:44.896] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:44.896] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:44.896] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:44.896] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:44.896] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:44.896] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:44.896] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:44.896] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:44.896] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:45.987] INFO: Test took 1091ms.
[10:46:45.988] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[10:46:45.988] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 24, 14 14
[10:46:45.988] INFO: The DUT currently contains the following objects:
[10:46:45.988] INFO: 2 TBM Cores tbm08c (2 ON)
[10:46:45.988] INFO: TBM Core alpha (0): 7 registers set
[10:46:45.988] INFO: TBM Core beta (1): 7 registers set
[10:46:45.988] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:46:45.988] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:45.988] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:45.988] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:45.988] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:45.988] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:45.988] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:45.988] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:45.988] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:45.988] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:45.988] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:45.988] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:45.988] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:45.988] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:45.988] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:45.988] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:45.988] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:47.079] INFO: Test took 1091ms.
[10:46:47.080] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[10:46:47.080] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 8, 9, 15 15
[10:46:47.080] INFO: The DUT currently contains the following objects:
[10:46:47.080] INFO: 2 TBM Cores tbm08c (2 ON)
[10:46:47.080] INFO: TBM Core alpha (0): 7 registers set
[10:46:47.080] INFO: TBM Core beta (1): 7 registers set
[10:46:47.080] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:46:47.080] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:47.080] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:47.080] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:47.080] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:47.080] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:47.080] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:47.080] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:47.080] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:47.080] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:47.080] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:47.080] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:47.080] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:47.080] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:47.080] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:47.080] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:47.080] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:46:48.171] INFO: Test took 1091ms.
[10:46:48.171] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[10:46:48.171] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 32 on ROC0
[10:46:48.171] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 29 on ROC1
[10:46:48.171] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 32 on ROC2
[10:46:48.171] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 31 on ROC3
[10:46:48.171] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 29 on ROC4
[10:46:48.171] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 30 on ROC5
[10:46:48.171] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 32 on ROC6
[10:46:48.171] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 30 on ROC7
[10:46:48.171] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 31 on ROC8
[10:46:48.171] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 30 on ROC9
[10:46:48.171] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 32 on ROC10
[10:46:48.171] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 31 on ROC11
[10:46:48.171] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 32 on ROC12
[10:46:48.171] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 32 on ROC13
[10:46:48.171] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 34 on ROC14
[10:46:48.171] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 32 on ROC15
[10:46:48.176] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:49:38.055] INFO: Test took 169879ms.
[10:49:39.552] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:52:28.706] INFO: Test took 169154ms.
[10:52:30.299] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[10:52:30.299] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip0
[10:52:30.299] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[10:52:30.300] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip1
[10:52:30.300] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[10:52:30.300] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip2
[10:52:30.300] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[10:52:30.300] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip3
[10:52:30.300] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[10:52:30.301] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip4
[10:52:30.301] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[10:52:30.301] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip5
[10:52:30.301] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[10:52:30.301] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip6
[10:52:30.301] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[10:52:30.302] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip7
[10:52:30.302] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[10:52:30.302] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip8
[10:52:30.302] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[10:52:30.302] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip9
[10:52:30.302] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[10:52:30.303] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip10
[10:52:30.303] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[10:52:30.303] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip11
[10:52:30.303] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[10:52:30.303] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip12
[10:52:30.303] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[10:52:30.304] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip13
[10:52:30.304] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[10:52:30.304] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip14
[10:52:30.304] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[10:52:30.304] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip15
[10:52:30.304] INFO: safety margin for low PH: adding 0, margin is now 20
[10:52:30.310] INFO: safety margin for low PH: adding 0, margin is now 20
[10:52:30.315] INFO: safety margin for low PH: adding 0, margin is now 20
[10:52:30.321] INFO: safety margin for low PH: adding 0, margin is now 20
[10:52:30.326] INFO: safety margin for low PH: adding 0, margin is now 20
[10:52:30.332] INFO: safety margin for low PH: adding 0, margin is now 20
[10:52:30.337] INFO: safety margin for low PH: adding 0, margin is now 20
[10:52:30.343] INFO: safety margin for low PH: adding 1, margin is now 21
[10:52:30.348] INFO: safety margin for low PH: adding 2, margin is now 22
[10:52:30.354] INFO: safety margin for low PH: adding 3, margin is now 23
[10:52:30.359] INFO: safety margin for low PH: adding 4, margin is now 24
[10:52:30.365] INFO: safety margin for low PH: adding 5, margin is now 25
[10:52:30.370] INFO: safety margin for low PH: adding 6, margin is now 26
[10:52:30.376] INFO: safety margin for low PH: adding 7, margin is now 27
[10:52:30.381] INFO: safety margin for low PH: adding 8, margin is now 28
[10:52:30.387] INFO: safety margin for low PH: adding 9, margin is now 29
[10:52:30.392] INFO: safety margin for low PH: adding 10, margin is now 30
[10:52:30.398] INFO: safety margin for low PH: adding 0, margin is now 20
[10:52:30.403] INFO: safety margin for low PH: adding 0, margin is now 20
[10:52:30.409] INFO: safety margin for low PH: adding 0, margin is now 20
[10:52:30.414] INFO: safety margin for low PH: adding 0, margin is now 20
[10:52:30.420] INFO: safety margin for low PH: adding 0, margin is now 20
[10:52:30.425] INFO: safety margin for low PH: adding 0, margin is now 20
[10:52:30.431] INFO: safety margin for low PH: adding 0, margin is now 20
[10:52:30.436] INFO: safety margin for low PH: adding 0, margin is now 20
[10:52:30.442] INFO: safety margin for low PH: adding 0, margin is now 20
[10:52:30.447] DEBUG: <PixTestPhOptimization.cc/doTest:L172> optimisation done
[10:52:30.497] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//dacParameters35_C0.dat
[10:52:30.497] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//dacParameters35_C1.dat
[10:52:30.497] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//dacParameters35_C2.dat
[10:52:30.497] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//dacParameters35_C3.dat
[10:52:30.497] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//dacParameters35_C4.dat
[10:52:30.497] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//dacParameters35_C5.dat
[10:52:30.497] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//dacParameters35_C6.dat
[10:52:30.497] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//dacParameters35_C7.dat
[10:52:30.497] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//dacParameters35_C8.dat
[10:52:30.498] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//dacParameters35_C9.dat
[10:52:30.498] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//dacParameters35_C10.dat
[10:52:30.498] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//dacParameters35_C11.dat
[10:52:30.498] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//dacParameters35_C12.dat
[10:52:30.498] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//dacParameters35_C13.dat
[10:52:30.498] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//dacParameters35_C14.dat
[10:52:30.498] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//dacParameters35_C15.dat
[10:52:34.188] INFO: Test took 3686ms.
[10:52:38.121] INFO: Test took 3655ms.
[10:52:42.086] INFO: Test took 3688ms.
[10:52:42.366] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:52:43.268] INFO: Test took 902ms.
[10:52:43.271] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:52:44.363] INFO: Test took 1092ms.
[10:52:44.366] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:52:45.457] INFO: Test took 1091ms.
[10:52:45.460] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:52:46.550] INFO: Test took 1090ms.
[10:52:46.553] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:52:47.644] INFO: Test took 1091ms.
[10:52:47.647] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:52:48.737] INFO: Test took 1090ms.
[10:52:48.741] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:52:49.831] INFO: Test took 1090ms.
[10:52:49.834] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:52:50.924] INFO: Test took 1090ms.
[10:52:50.927] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:52:52.017] INFO: Test took 1090ms.
[10:52:52.020] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:52:53.110] INFO: Test took 1090ms.
[10:52:53.113] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:52:54.204] INFO: Test took 1091ms.
[10:52:54.207] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:52:55.297] INFO: Test took 1090ms.
[10:52:55.300] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:52:56.391] INFO: Test took 1091ms.
[10:52:56.394] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:52:57.484] INFO: Test took 1090ms.
[10:52:57.487] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:52:58.577] INFO: Test took 1090ms.
[10:52:58.581] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:52:59.671] INFO: Test took 1091ms.
[10:52:59.674] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:53:00.764] INFO: Test took 1090ms.
[10:53:00.767] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:53:01.858] INFO: Test took 1091ms.
[10:53:01.861] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:53:02.951] INFO: Test took 1090ms.
[10:53:02.954] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:53:04.044] INFO: Test took 1090ms.
[10:53:04.047] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:53:05.138] INFO: Test took 1091ms.
[10:53:05.141] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:53:06.231] INFO: Test took 1090ms.
[10:53:06.234] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:53:07.324] INFO: Test took 1091ms.
[10:53:07.327] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:53:08.416] INFO: Test took 1089ms.
[10:53:08.419] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:53:09.510] INFO: Test took 1091ms.
[10:53:09.513] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:53:10.603] INFO: Test took 1091ms.
[10:53:10.606] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:53:11.696] INFO: Test took 1090ms.
[10:53:11.699] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:53:12.789] INFO: Test took 1090ms.
[10:53:12.792] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:53:13.882] INFO: Test took 1090ms.
[10:53:13.885] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:53:14.975] INFO: Test took 1090ms.
[10:53:14.978] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:53:16.068] INFO: Test took 1090ms.
[10:53:16.071] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:53:17.161] INFO: Test took 1090ms.
[10:53:17.746] INFO: PixTestPhOptimization::doTest() done, duration: 418 seconds
[10:53:17.746] INFO: PH scale (per ROC): 64 61 63 64 77 69 78 71 66 63 71 75 74 74 67 67
[10:53:17.746] INFO: PH offset (per ROC): 184 181 192 184 187 189 176 179 188 188 182 173 178 184 189 190
[10:53:17.889] INFO: ######################################################################
[10:53:17.889] INFO: PixTestGainPedestal::fullTest() ntrig = 10
[10:53:17.889] INFO: ######################################################################
[10:53:17.889] DEBUG: <PixTestGainPedestal.cc/measure:L188> using FLAGS = 16
[10:53:17.900] INFO: scanning low vcal = 50
[10:53:21.621] INFO: Test took 3721ms.
[10:53:21.678] INFO: scanning low vcal = 100
[10:53:25.417] INFO: Test took 3739ms.
[10:53:25.475] INFO: scanning low vcal = 150
[10:53:29.218] INFO: Test took 3743ms.
[10:53:29.275] INFO: scanning low vcal = 200
[10:53:33.011] INFO: Test took 3736ms.
[10:53:33.068] INFO: scanning low vcal = 250
[10:53:36.805] INFO: Test took 3737ms.
[10:53:36.864] INFO: scanning high vcal = 30 (= 210 in low range)
[10:53:40.601] INFO: Test took 3737ms.
[10:53:40.660] INFO: scanning high vcal = 50 (= 350 in low range)
[10:53:44.398] INFO: Test took 3738ms.
[10:53:44.455] INFO: scanning high vcal = 70 (= 490 in low range)
[10:53:48.194] INFO: Test took 3739ms.
[10:53:48.251] INFO: scanning high vcal = 90 (= 630 in low range)
[10:53:51.989] INFO: Test took 3738ms.
[10:53:52.047] INFO: scanning high vcal = 200 (= 1400 in low range)
[10:53:55.789] INFO: Test took 3742ms.
[10:53:56.105] INFO: PixTestGainPedestal::measure() done
[10:53:56.106] DEBUG: <PixTestGainPedestal.cc/fit:L377> Create hist gainPedestalP1_C0
[10:53:56.106] DEBUG: <PixTestGainPedestal.cc/fit:L377> Create hist gainPedestalP1_C1
[10:53:56.107] DEBUG: <PixTestGainPedestal.cc/fit:L377> Create hist gainPedestalP1_C2
[10:53:56.107] DEBUG: <PixTestGainPedestal.cc/fit:L377> Create hist gainPedestalP1_C3
[10:53:56.107] DEBUG: <PixTestGainPedestal.cc/fit:L377> Create hist gainPedestalP1_C4
[10:53:56.107] DEBUG: <PixTestGainPedestal.cc/fit:L377> Create hist gainPedestalP1_C5
[10:53:56.107] DEBUG: <PixTestGainPedestal.cc/fit:L377> Create hist gainPedestalP1_C6
[10:53:56.107] DEBUG: <PixTestGainPedestal.cc/fit:L377> Create hist gainPedestalP1_C7
[10:53:56.107] DEBUG: <PixTestGainPedestal.cc/fit:L377> Create hist gainPedestalP1_C8
[10:53:56.108] DEBUG: <PixTestGainPedestal.cc/fit:L377> Create hist gainPedestalP1_C9
[10:53:56.108] DEBUG: <PixTestGainPedestal.cc/fit:L377> Create hist gainPedestalP1_C10
[10:53:56.108] DEBUG: <PixTestGainPedestal.cc/fit:L377> Create hist gainPedestalP1_C11
[10:53:56.108] DEBUG: <PixTestGainPedestal.cc/fit:L377> Create hist gainPedestalP1_C12
[10:53:56.108] DEBUG: <PixTestGainPedestal.cc/fit:L377> Create hist gainPedestalP1_C13
[10:53:56.108] DEBUG: <PixTestGainPedestal.cc/fit:L377> Create hist gainPedestalP1_C14
[10:53:56.108] DEBUG: <PixTestGainPedestal.cc/fit:L377> Create hist gainPedestalP1_C15
[10:54:18.286] INFO: PixTestGainPedestal::fit() done
[10:54:18.286] INFO: non-linearity mean: 0.954 0.954 0.964 0.956 0.960 0.965 0.969 0.956 0.954 0.959 0.958 0.958 0.950 0.962 0.957 0.953
[10:54:18.286] INFO: non-linearity RMS: 0.009 0.007 0.007 0.008 0.007 0.006 0.004 0.007 0.007 0.007 0.006 0.006 0.007 0.007 0.007 0.009
[10:54:18.286] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//phCalibrationFitErr35_C0.dat
[10:54:18.302] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//phCalibrationFitErr35_C1.dat
[10:54:18.319] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//phCalibrationFitErr35_C2.dat
[10:54:18.335] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//phCalibrationFitErr35_C3.dat
[10:54:18.352] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//phCalibrationFitErr35_C4.dat
[10:54:18.368] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//phCalibrationFitErr35_C5.dat
[10:54:18.385] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//phCalibrationFitErr35_C6.dat
[10:54:18.401] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//phCalibrationFitErr35_C7.dat
[10:54:18.417] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//phCalibrationFitErr35_C8.dat
[10:54:18.434] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//phCalibrationFitErr35_C9.dat
[10:54:18.450] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//phCalibrationFitErr35_C10.dat
[10:54:18.466] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//phCalibrationFitErr35_C11.dat
[10:54:18.482] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//phCalibrationFitErr35_C12.dat
[10:54:18.499] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//phCalibrationFitErr35_C13.dat
[10:54:18.515] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//phCalibrationFitErr35_C14.dat
[10:54:18.532] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//000_Fulltest_p17//phCalibrationFitErr35_C15.dat
[10:54:18.548] INFO: PixTestGainPedestal::doTest() done, duration: 60 seconds
[10:54:18.548] DEBUG: <PixTestGainPedestal.cc/~PixTestGainPedestal:L121> PixTestGainPedestal dtor
[10:54:18.554] DEBUG: <PixTestFullTest.cc/~PixTestFullTest:L78> PixTestFullTest dtor
[10:54:18.554] INFO: enter test to run
[10:54:18.554] INFO: test: q no parameter change
[10:54:18.554] DEBUG: <PixMonitor.cc/dumpSummaries:L34> PixMonitor::dumpSummaries
[10:54:18.686] QUIET: Connection to board 105 closed.
[10:54:18.687] INFO: pXar: this is the end, my friend
[10:54:18.687] DEBUG: <PixSetup.cc/~PixSetup:L68> PixSetup free fPxarMemory
MoReWeb-v0.6.7-17-g62372b6 on branch psi46master