[11:12:00.638] INFO: *** Welcome to pxar ***
[11:12:00.638] INFO: *** Today: 2015/06/26
[11:12:00.638] INFO: readRocDacs: /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//dacParameters_C0.dat .. /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//dacParameters_C15.dat
[11:12:00.638] INFO: readTbmDacs: /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//tbmParameters_C0a.dat .. /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//tbmParameters_C0b.dat
[11:12:00.638] INFO: readMaskFile: /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//defaultMaskFile.dat
[11:12:00.638] INFO: readTrimFile: /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//trimParameters_C0.dat .. /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//trimParameters_C15.dat
[11:12:00.697] INFO: clk: 4
[11:12:00.697] INFO: ctr: 4
[11:12:00.697] INFO: sda: 19
[11:12:00.697] INFO: tin: 9
[11:12:00.697] INFO: level: 15
[11:12:00.697] INFO: triggerdelay: 0
[11:12:00.697] QUIET: Instanciating API for pxar v2.2.4+51~gdb2a247
[11:12:00.697] INFO: Log level: DEBUG
[11:12:00.710] QUIET: Connection to board DTB_WV7UX2 opened.
[11:12:00.713] 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
------------------------------------------------------
[11:12:00.716] INFO: RPC call hashes of host and DTB match: 447413373
[11:12:02.263] INFO: DUT info:
[11:12:02.263] INFO: The DUT currently contains the following objects:
[11:12:02.263] INFO: 2 TBM Cores tbm08c (2 ON)
[11:12:02.263] INFO: TBM Core alpha (0): 7 registers set
[11:12:02.263] INFO: TBM Core beta (1): 7 registers set
[11:12:02.263] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[11:12:02.263] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[11:12:02.263] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[11:12:02.263] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[11:12:02.263] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[11:12:02.263] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[11:12:02.263] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[11:12:02.263] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[11:12:02.263] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[11:12:02.263] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[11:12:02.263] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[11:12:02.264] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[11:12:02.264] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[11:12:02.264] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[11:12:02.264] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[11:12:02.264] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[11:12:02.264] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->BB<-
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> dumpall: checkbox(0)
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> dumpproblematic: checkbox(0)
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 5
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> vcals: 250
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->BB2<-
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> vcals: 222
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> plwidth: 35
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> pix: 11,20
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> targetia: 24
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->BB3<-
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> dumpall: checkbox(0)
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> dumpproblematic: checkbox(0)
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 5
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> vcals: 250
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->DacDacScan<-
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> phmap: checkbox
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> dac1: caldel
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> dac1lo: 0
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> dac1hi: 255
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> dac2: vthrcomp
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> dac2lo: 0
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> dac2hi: 255
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> pix: 11,20
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->DacScan<-
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> phmap: checkbox(1)
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> allpixels: checkbox(0)
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> unmasked: checkbox(0)
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> dac: vcal
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> daclo: 0
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> dachi: 255
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> pix: 11,20
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->GainPedestal<-
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> showfits: checkbox(0)
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> extended: checkbox(0)
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> dumphists: checkbox(0)
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> measure: button
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> fit: button
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> save: button
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->HighRate<-
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> pix: 11,20
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> maskhotpixels: button
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> savemaskfile: checkbox(0)
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> maskfilename: default
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> caldelscan: button
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> xpixelalive: button
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 50
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> vcal: 200
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> xnoisemaps: button
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> daclo: 0
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> dachi: 100
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> dacs/step: 20
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> rundaq: button
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> trgfrequency(khz): 20
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> runseconds: 2
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> triggerdelay: 20
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> delaytbm: checkbox
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> filltree: checkbox
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->IV<-
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> port: /dev/FIXME
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> voltagestart: 0
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> voltagestop: 600
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> voltagestep: 5
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> delay: 1
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> compliance(ua): 100
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->PhOptimization<-
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> safetymarginlow: 20
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> saturationvcal: 100
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L107> quantilesaturation: 0.98
[11:12:02.264] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->PixelAlive<-
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> vcal: 200
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> alivetest: button
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> masktest: button
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> addressdecodingtest: button
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Pretest<-
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> programroc: button
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> targetia: 24
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> setvana: button
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> iterations: 100
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> settimings: button
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> findworkingpixel: button
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> setvthrcompcaldel: button
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> pix: 11,20
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> vcal: 250
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> deltavthrcomp: 50
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> fraccaldel: 0.5
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 5
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> savedacs: button
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Readback<-
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> calibratevd: button
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> calibrateva: button
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> calibrateia: button
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> readbackvbg: button
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> getcalibratedvbg: button
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> usecalvd: checkbox(1)
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> usecalva: checkbox(0)
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> setvana: button
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Scurves<-
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> adjustvcal: checkbox(1)
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> dumpall: checkbox(0)
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> dumpproblematic: checkbox(0)
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> dumpoutputfile: checkbox(0)
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 50
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> dac: VthrComp
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> daclo: 0
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> dachi: 200
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> dacs/step: 10
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> scurves: button
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Timing<-
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> fastscan: checkbox(0)
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> targetclk: 4
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> clocksdascan: button
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> phasescan: button
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> levelscan: button
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> tbmphasescan: button
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> rocdelayscan: button
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> timingtest: button
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> saveparameters: button
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Trim<-
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> trim: button
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> vcal: 35
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> trimbits: button
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Xray<-
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> maskhotpixels: button
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> savemaskfile: checkbox(0)
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> maskfilename: default
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> source: Ag
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> phrun: button
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> runseconds: 100
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> trgfrequency(khz): 100
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> ratescan: button
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> vthrcompmin: 10
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> vthrcompmax: 80
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> stepseconds: 5
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> delaytbm: checkbox
[11:12:02.265] DEBUG: <PixTestParameters.cc/dump:L107> filltree: checkbox
[11:12:02.265] DEBUG: <PixSetup.cc/init:L81> PixSetup init start; getCurrentRSS() = 31674368
[11:12:02.265] DEBUG: <PixSetup.cc/init:L87> fPixTestParameters = 0xf987d0
[11:12:02.265] DEBUG: <PixSetup.cc/init:L88> fConfigParameters = 0xcf1980
[11:12:02.265] DEBUG: <PixSetup.cc/init:L89> fPxarMemory = 0x7f078dd94010
[11:12:02.265] DEBUG: <PixSetup.cc/init:L90> fPxarMemHi = 0x7f0793fff510
[11:12:02.265] DEBUG: <PixSetup.cc/init:L106> PixSetup init done; getCurrentRSS() = 31731712 fPxarMemory = 0x7f078dd94010
[11:12:02.265] DEBUG: <PixTestFactory.cc/PixTestFactory:L51> PixTestFactory::PixTestFactory()
[11:12:02.667] INFO: enter 'restricted' command line mode
[11:12:02.667] INFO: enter test to run
[11:12:02.667] INFO: test: Pretest no parameter change
[11:12:02.667] INFO: running: pretest
[11:12:02.672] INFO: ######################################################################
[11:12:02.672] INFO: PixTestPretest::doTest()
[11:12:02.673] INFO: ######################################################################
[11:12:02.674] INFO: ----------------------------------------------------------------------
[11:12:02.674] INFO: PixTestPretest::programROC()
[11:12:02.674] INFO: ----------------------------------------------------------------------
[11:12:20.695] INFO: PixTestPretest::programROC() done: ROCs are all programmable
[11:12:20.695] INFO: IA differences per ROC: 19.3 19.3 17.7 19.3 20.1 16.1 19.3 20.9 17.7 18.5 20.1 18.5 20.9 17.7 19.3 19.3
[11:12:20.763] INFO: ----------------------------------------------------------------------
[11:12:20.763] INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[11:12:20.763] INFO: ----------------------------------------------------------------------
[11:12:20.867] DEBUG: <PixTestPretest.cc/setVana:L254> offset current from other 15 ROCs is 68.5312 mA
[11:12:20.968] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 0 iter 0 Vana 78 Ia 23.0687 mA
[11:12:21.069] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 1 Vana 84 Ia 25.4688 mA
[11:12:21.170] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 2 Vana 76 Ia 23.0687 mA
[11:12:21.270] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 3 Vana 82 Ia 24.6688 mA
[11:12:21.371] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 4 Vana 79 Ia 23.0687 mA
[11:12:21.472] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 5 Vana 85 Ia 25.4688 mA
[11:12:21.572] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 6 Vana 77 Ia 23.8687 mA
[11:12:21.674] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 1 iter 0 Vana 78 Ia 23.0687 mA
[11:12:21.775] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 1 Vana 84 Ia 24.6688 mA
[11:12:21.876] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 2 Vana 81 Ia 24.6688 mA
[11:12:21.977] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 3 Vana 78 Ia 23.0687 mA
[11:12:22.078] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 4 Vana 84 Ia 24.6688 mA
[11:12:22.178] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 5 Vana 81 Ia 23.8687 mA
[11:12:22.280] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 2 iter 0 Vana 78 Ia 22.2688 mA
[11:12:22.380] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 2 iter 1 Vana 88 Ia 24.6688 mA
[11:12:22.481] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 2 iter 2 Vana 85 Ia 23.8687 mA
[11:12:22.582] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 3 iter 0 Vana 78 Ia 23.0687 mA
[11:12:22.683] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 1 Vana 84 Ia 24.6688 mA
[11:12:22.783] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 2 Vana 81 Ia 23.8687 mA
[11:12:22.885] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 4 iter 0 Vana 78 Ia 24.6688 mA
[11:12:22.985] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 4 iter 1 Vana 75 Ia 23.8687 mA
[11:12:23.087] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 5 iter 0 Vana 78 Ia 19.8688 mA
[11:12:23.188] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 1 Vana 103 Ia 25.4688 mA
[11:12:23.288] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 2 Vana 95 Ia 23.0687 mA
[11:12:23.388] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 3 Vana 101 Ia 24.6688 mA
[11:12:23.489] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 4 Vana 98 Ia 23.8687 mA
[11:12:23.591] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 6 iter 0 Vana 78 Ia 23.0687 mA
[11:12:23.691] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 1 Vana 84 Ia 24.6688 mA
[11:12:23.792] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 2 Vana 81 Ia 23.8687 mA
[11:12:23.893] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 7 iter 0 Vana 78 Ia 24.6688 mA
[11:12:23.994] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 7 iter 1 Vana 75 Ia 23.8687 mA
[11:12:24.096] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 8 iter 0 Vana 78 Ia 21.4688 mA
[11:12:24.197] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 8 iter 1 Vana 93 Ia 24.6688 mA
[11:12:24.297] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 8 iter 2 Vana 90 Ia 23.8687 mA
[11:12:24.399] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 9 iter 0 Vana 78 Ia 22.2688 mA
[11:12:24.499] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 9 iter 1 Vana 88 Ia 24.6688 mA
[11:12:24.600] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 9 iter 2 Vana 85 Ia 23.8687 mA
[11:12:24.702] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 10 iter 0 Vana 78 Ia 23.8687 mA
[11:12:24.803] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 11 iter 0 Vana 78 Ia 22.2688 mA
[11:12:24.904] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter 1 Vana 88 Ia 23.8687 mA
[11:12:24.005] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 12 iter 0 Vana 78 Ia 24.6688 mA
[11:12:25.106] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter 1 Vana 75 Ia 23.8687 mA
[11:12:25.208] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 13 iter 0 Vana 78 Ia 21.4688 mA
[11:12:25.309] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 1 Vana 93 Ia 24.6688 mA
[11:12:25.409] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 2 Vana 90 Ia 24.6688 mA
[11:12:25.510] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 3 Vana 87 Ia 23.8687 mA
[11:12:25.612] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 14 iter 0 Vana 78 Ia 22.2688 mA
[11:12:25.712] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 1 Vana 88 Ia 24.6688 mA
[11:12:25.813] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 2 Vana 85 Ia 23.8687 mA
[11:12:25.914] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 15 iter 0 Vana 78 Ia 23.0687 mA
[11:12:26.015] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 1 Vana 84 Ia 25.4688 mA
[11:12:26.115] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 2 Vana 76 Ia 23.0687 mA
[11:12:26.216] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 3 Vana 82 Ia 24.6688 mA
[11:12:26.317] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 4 Vana 79 Ia 23.8687 mA
[11:12:26.361] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 0 Vana 77
[11:12:26.362] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 1 Vana 81
[11:12:26.362] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 2 Vana 85
[11:12:26.362] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 3 Vana 81
[11:12:26.362] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 4 Vana 75
[11:12:26.362] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 5 Vana 98
[11:12:26.363] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 6 Vana 81
[11:12:26.363] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 7 Vana 75
[11:12:26.363] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 8 Vana 90
[11:12:26.363] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 9 Vana 85
[11:12:26.363] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 10 Vana 78
[11:12:26.363] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 11 Vana 88
[11:12:26.364] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 12 Vana 75
[11:12:26.364] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 13 Vana 87
[11:12:26.364] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 14 Vana 85
[11:12:26.364] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 15 Vana 79
[11:12:26.467] INFO: PixTestPretest::setVana() done, Module Ia 385.9 mA = 24.1188 mA/ROC
[11:12:26.468] INFO: ----------------------------------------------------------------------
[11:12:26.468] INFO: PixTestPreTest::setTimings()
[11:12:26.468] INFO: ----------------------------------------------------------------------
[11:12:26.469] DEBUG: <PixTestPretest.cc/setTimings:L392> Testing Timing: Attempt #1
[11:12:27.432] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:12:27.432] INFO: Decoding statistics:
[11:12:27.432] INFO: General information:
[11:12:27.432] INFO: 16bit words read: 120
[11:12:27.432] INFO: valid events total: 10
[11:12:27.432] INFO: empty events: 10
[11:12:27.433] INFO: valid events with pixels: 0
[11:12:27.433] INFO: valid pixel hits: 0
[11:12:27.433] INFO: Event errors: 0
[11:12:27.433] INFO: start marker: 0
[11:12:27.433] INFO: stop marker: 0
[11:12:27.433] INFO: overflow: 0
[11:12:27.433] INFO: invalid 5bit words: 0
[11:12:27.433] INFO: invalid XOR eye diagram: 0
[11:12:27.433] INFO: TBM errors: 0
[11:12:27.433] INFO: flawed TBM headers: 0
[11:12:27.433] INFO: flawed TBM trailers: 0
[11:12:27.433] INFO: event ID mismatches: 0
[11:12:27.433] INFO: ROC errors: 0
[11:12:27.433] INFO: missing ROC header(s): 0
[11:12:27.433] INFO: misplaced readback start: 0
[11:12:27.433] INFO: Pixel decoding errors: 0
[11:12:27.433] INFO: pixel data incomplete: 0
[11:12:27.433] INFO: pixel address: 0
[11:12:27.433] INFO: pulse height fill bit: 0
[11:12:27.433] INFO: buffer corruption: 0
[11:12:27.433] INFO: ----------------------------------------------------------------------
[11:12:27.433] INFO: Default timings are good. No timing scan needed.
[11:12:27.433] INFO: ----------------------------------------------------------------------
[11:12:27.433] INFO: Test took 965 ms.
[11:12:27.433] INFO: PixTestPretest::setTimings() done.
[11:12:27.625] INFO: ----------------------------------------------------------------------
[11:12:27.625] INFO: PixTestPretest::findWorkingPixel()
[11:12:27.625] INFO: ----------------------------------------------------------------------
[11:12:34.798] INFO: Test took 7171ms.
[11:12:35.025] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C0 OK, with vthrComp = 91 and Delta(CalDel) = 63
[11:12:35.027] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C1 OK, with vthrComp = 88 and Delta(CalDel) = 56
[11:12:35.029] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C2 OK, with vthrComp = 97 and Delta(CalDel) = 59
[11:12:35.031] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C3 OK, with vthrComp = 84 and Delta(CalDel) = 56
[11:12:35.034] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C4 OK, with vthrComp = 93 and Delta(CalDel) = 62
[11:12:35.036] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C5 OK, with vthrComp = 99 and Delta(CalDel) = 62
[11:12:35.038] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C6 OK, with vthrComp = 94 and Delta(CalDel) = 61
[11:12:35.040] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C7 OK, with vthrComp = 111 and Delta(CalDel) = 58
[11:12:35.042] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C8 OK, with vthrComp = 81 and Delta(CalDel) = 63
[11:12:35.044] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C9 OK, with vthrComp = 65 and Delta(CalDel) = 61
[11:12:35.047] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C10 OK, with vthrComp = 73 and Delta(CalDel) = 62
[11:12:35.049] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C11 OK, with vthrComp = 81 and Delta(CalDel) = 61
[11:12:35.051] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C12 OK, with vthrComp = 88 and Delta(CalDel) = 61
[11:12:35.053] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C13 OK, with vthrComp = 87 and Delta(CalDel) = 58
[11:12:35.055] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C14 OK, with vthrComp = 92 and Delta(CalDel) = 64
[11:12:35.057] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C15 OK, with vthrComp = 98 and Delta(CalDel) = 56
[11:12:35.081] INFO: Found working pixel in all ROCs: col/row = 12/22
[11:12:35.129] INFO: ----------------------------------------------------------------------
[11:12:35.129] INFO: PixTestPretest::setVthrCompCalDel()
[11:12:35.129] INFO: ----------------------------------------------------------------------
[11:12:42.304] INFO: Test took 7170ms.
[11:12:42.355] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 143 +/- 31.5
[11:12:42.531] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 106 +/- 26.5
[11:12:42.533] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 113 +/- 30
[11:12:42.535] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 124 +/- 29
[11:12:42.537] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 135 +/- 30
[11:12:42.539] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 140 +/- 31
[11:12:42.541] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 142 +/- 30.5
[11:12:42.544] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 130 +/- 29.5
[11:12:42.546] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 139 +/- 30.5
[11:12:42.548] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 158 +/- 32
[11:12:42.550] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 147 +/- 31.5
[11:12:42.552] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 139 +/- 30
[11:12:42.555] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 144 +/- 30.5
[11:12:42.557] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 133 +/- 28.5
[11:12:42.559] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 144 +/- 31.5
[11:12:42.561] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 114 +/- 29
[11:12:42.612] INFO: PixTestPretest::setVthrCompCalDel() done
[11:12:42.612] INFO: CalDel: 143 106 113 124 135 140 142 130 139 158 147 139 144 133 144 114
[11:12:42.612] INFO: VthrComp: 51 51 54 51 51 51 51 51 51 51 51 51 51 51 51 51
[11:12:42.616] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//dacParameters_C0.dat
[11:12:42.616] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//dacParameters_C1.dat
[11:12:42.616] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//dacParameters_C2.dat
[11:12:42.616] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//dacParameters_C3.dat
[11:12:42.616] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//dacParameters_C4.dat
[11:12:42.616] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//dacParameters_C5.dat
[11:12:42.616] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//dacParameters_C6.dat
[11:12:42.617] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//dacParameters_C7.dat
[11:12:42.617] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//dacParameters_C8.dat
[11:12:42.617] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//dacParameters_C9.dat
[11:12:42.617] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//dacParameters_C10.dat
[11:12:42.617] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//dacParameters_C11.dat
[11:12:42.617] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//dacParameters_C12.dat
[11:12:42.617] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//dacParameters_C13.dat
[11:12:42.617] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//dacParameters_C14.dat
[11:12:42.617] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//dacParameters_C15.dat
[11:12:42.617] INFO: PixTestPretest::doTest() done, duration: 39 seconds
[11:12:42.617] DEBUG: <PixTestPretest.cc/~PixTestPretest:L134> PixTestPretest dtor
[11:12:42.687] INFO: enter test to run
[11:12:42.687] INFO: test: Fulltest no parameter change
[11:12:42.687] INFO: running: fulltest
[11:12:42.687] DEBUG: <PixTestFullTest.cc/init:L49> PixTestFullTest::init()
[11:12:42.687] DEBUG: <PixTestFullTest.cc/PixTestFullTest:L20> PixTestFullTest ctor(PixSetup &a, string, TGTab *)
[11:12:42.687] INFO: ######################################################################
[11:12:42.687] INFO: PixTestFullTest::doTest()
[11:12:42.687] INFO: ######################################################################
[11:12:42.687] DEBUG: <PixTestAlive.cc/init:L77> PixTestAlive::init()
[11:12:42.687] DEBUG: <PixTestAlive.cc/PixTestAlive:L21> PixTestAlive ctor(PixSetup &a, string, TGTab *)
[11:12:42.689] INFO: ######################################################################
[11:12:42.689] INFO: PixTestAlive::doTest()
[11:12:42.689] INFO: ######################################################################
[11:12:42.690] INFO: ----------------------------------------------------------------------
[11:12:42.690] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[11:12:42.690] INFO: ----------------------------------------------------------------------
[11:12:42.692] DEBUG: <PixTest.cc/efficiencyMaps:L328> attempt #0
[11:12:46.370] INFO: Test took 3677ms.
[11:12:46.388] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:12:46.388] DEBUG: <PixTest.cc/efficiencyMaps:L339> eff result size = 66541
[11:12:46.388] DEBUG: <PixTest.cc/efficiencyMaps:L344> Create hists PixelAlive_C0 .. PixelAlive_C15
[11:12:46.628] INFO: PixTestAlive::aliveTest() done
[11:12:46.628] INFO: number of dead pixels (per ROC): 4 4 1 0 0 0 0 0 1 0 0 0 2 4 1 2
[11:12:46.628] 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
[11:12:46.629] INFO: ----------------------------------------------------------------------
[11:12:46.629] INFO: PixTestAlive::maskTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[11:12:46.629] INFO: ----------------------------------------------------------------------
[11:12:46.631] DEBUG: <PixTest.cc/efficiencyMaps:L328> attempt #0
[11:12:49.283] INFO: Test took 2652ms.
[11:12:49.284] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:12:49.284] DEBUG: <PixTest.cc/efficiencyMaps:L339> eff result size = 0
[11:12:49.284] DEBUG: <PixTest.cc/efficiencyMaps:L344> Create hists MaskTest_C0 .. MaskTest_C15
[11:12:49.285] INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[11:12:49.524] INFO: PixTestAlive::maskTest() done
[11:12:49.524] INFO: number of mask-defect pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:12:49.525] INFO: ----------------------------------------------------------------------
[11:12:49.525] INFO: PixTestAlive::addressDecodingTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[11:12:49.525] INFO: ----------------------------------------------------------------------
[11:12:49.527] DEBUG: <PixTest.cc/efficiencyMaps:L328> attempt #0
[11:12:53.216] INFO: Test took 3689ms.
[11:12:53.233] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:12:53.233] DEBUG: <PixTest.cc/efficiencyMaps:L339> eff result size = 66541
[11:12:53.233] DEBUG: <PixTest.cc/efficiencyMaps:L344> Create hists AddressDecodingTest_C0 .. AddressDecodingTest_C15
[11:12:53.475] INFO: PixTestAlive::addressDecodingTest() done
[11:12:53.475] INFO: number of address-decoding pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:12:53.475] INFO: PixTestAlive::doTest() done, duration: 10 seconds
[11:12:53.475] DEBUG: <PixTestAlive.cc/~PixTestAlive:L109> PixTestAlive dtor
[11:12:53.479] DEBUG: <PixTestBBMap.cc/init:L79> PixTestBBMap::init()
[11:12:53.479] DEBUG: <PixTestBBMap.cc/PixTestBBMap:L27> PixTestBBMap ctor(PixSetup &a, string, TGTab *)
[11:12:53.481] INFO: ######################################################################
[11:12:53.481] INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[11:12:53.481] INFO: ######################################################################
[11:12:53.485] INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (30) hits flags = 2 (plus default)
[11:12:53.496] INFO: dacScan step from 0 .. 29
[11:12:53.496] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:13:11.107] INFO: Test took 17611ms.
[11:13:11.140] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:13:11.140] INFO: dacScan step from 30 .. 59
[11:13:11.140] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:13:29.898] INFO: Test took 18758ms.
[11:13:29.005] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:13:30.019] INFO: dacScan step from 60 .. 89
[11:13:30.019] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:13:53.640] INFO: Test took 23621ms.
[11:13:53.895] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:13:53.935] INFO: dacScan step from 90 .. 119
[11:13:53.935] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:14:17.941] INFO: Test took 24006ms.
[11:14:18.194] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:14:18.235] INFO: dacScan step from 120 .. 149
[11:14:18.235] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:14:40.804] INFO: Test took 22569ms.
[11:14:40.992] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:14:41.020] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[11:14:42.257] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[11:14:43.514] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[11:14:44.775] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[11:14:46.024] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[11:14:47.259] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[11:14:48.494] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[11:14:49.741] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[11:14:51.025] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[11:14:52.233] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[11:14:53.386] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[11:14:54.579] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[11:14:55.827] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[11:14:56.000] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[11:14:58.203] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[11:14:59.431] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[11:15:00.680] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 259993600
[11:15:00.726] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C0_V0
[11:15:00.727] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 96 (obtained for minval = 0) start: 96 .. 117 last peak: 58.3907 last sigma: 5.89669 lcuts[0] = 76.0808 lcuts[1] = 117.358
[11:15:00.728] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C1_V0
[11:15:00.728] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 98 (obtained for minval = 0) start: 98 .. 122 last peak: 53.9541 last sigma: 6.88841 lcuts[0] = 74.6193 lcuts[1] = 122.838
[11:15:00.728] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C2_V0
[11:15:00.729] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 105 (obtained for minval = 0) start: 105 .. 129 last peak: 59.4818 last sigma: 7.01595 lcuts[0] = 80.5296 lcuts[1] = 129.641
[11:15:00.729] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C3_V0
[11:15:00.729] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 101 (obtained for minval = 0) start: 101 .. 123 last peak: 60.0694 last sigma: 6.37102 lcuts[0] = 79.1824 lcuts[1] = 123.78
[11:15:00.730] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C4_V0
[11:15:00.730] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 94 (obtained for minval = 0) start: 94 .. 116 last peak: 54.7964 last sigma: 6.12878 lcuts[0] = 73.1828 lcuts[1] = 116.084
[11:15:00.730] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C5_V0
[11:15:00.731] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 98 (obtained for minval = 0) start: 98 .. 118 last peak: 60.3367 last sigma: 5.81728 lcuts[0] = 77.7885 lcuts[1] = 118.509
[11:15:00.731] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C6_V0
[11:15:00.731] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 99 (obtained for minval = 0) start: 99 .. 120 last peak: 59.4904 last sigma: 6.11579 lcuts[0] = 77.8377 lcuts[1] = 120.648
[11:15:00.731] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C7_V0
[11:15:00.732] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 107 (obtained for minval = 0) start: 107 .. 132 last peak: 62.4789 last sigma: 7.00097 lcuts[0] = 83.4818 lcuts[1] = 132.489
[11:15:00.732] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C8_V0
[11:15:00.732] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 90 (obtained for minval = 0) start: 90 .. 108 last peak: 56.0493 last sigma: 5.27669 lcuts[0] = 71.8794 lcuts[1] = 108.816
[11:15:00.733] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C9_V0
[11:15:00.733] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 77 (obtained for minval = 0) start: 77 .. 92 last peak: 49.5374 last sigma: 4.30523 lcuts[0] = 62.4531 lcuts[1] = 92.5897
[11:15:00.733] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C10_V0
[11:15:00.733] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 89 (obtained for minval = 0) start: 89 .. 108 last peak: 55.1047 last sigma: 5.34473 lcuts[0] = 71.1389 lcuts[1] = 108.552
[11:15:00.734] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C11_V0
[11:15:00.734] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 98 (obtained for minval = 0) start: 98 .. 118 last peak: 60.1014 last sigma: 5.87121 lcuts[0] = 77.715 lcuts[1] = 118.814
[11:15:00.734] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C12_V0
[11:15:00.735] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 78 (obtained for minval = 0) start: 78 .. 94 last peak: 47.8131 last sigma: 4.69003 lcuts[0] = 61.8832 lcuts[1] = 94.7134
[11:15:00.735] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C13_V0
[11:15:00.735] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 79 (obtained for minval = 0) start: 79 .. 95 last peak: 48.5382 last sigma: 4.73649 lcuts[0] = 62.7476 lcuts[1] = 95.9031
[11:15:00.736] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C14_V0
[11:15:00.736] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 87 (obtained for minval = 0) start: 87 .. 109 last peak: 48.4413 last sigma: 6.07483 lcuts[0] = 66.6658 lcuts[1] = 109.19
[11:15:00.736] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C15_V0
[11:15:00.737] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 99 (obtained for minval = 0) start: 99 .. 120 last peak: 58.5495 last sigma: 6.2415 lcuts[0] = 77.274 lcuts[1] = 120.964
[11:15:00.738] INFO: PixTestBBMap::doTest() done, duration: 127 seconds
[11:15:00.738] INFO: number of dead bumps (per ROC): 5 2 2 2 0 2 0 1 2 3 2 4 1 1 3 2
[11:15:00.738] INFO: separation cut (per ROC): 97 99 106 102 95 99 100 108 91 78 90 99 79 80 88 100
[11:15:00.738] DEBUG: <PixTestBBMap.cc/~PixTestBBMap:L97> PixTestBBMap dtor
[11:15:00.804] DEBUG: <PixTestScurves.cc/setParameter:L92> set fOutputFilename =
[11:15:00.806] INFO: ######################################################################
[11:15:00.806] INFO: PixTestScurves::fullTest() ntrig = 50
[11:15:00.806] INFO: ######################################################################
[11:15:00.806] INFO: ----------------------------------------------------------------------
[11:15:00.806] INFO: PixTestScurves::scurves(Vcal), ntrig = 50
[11:15:00.806] INFO: ----------------------------------------------------------------------
[11:15:00.806] INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 0 .. 149 (10) hits flags = 16 (plus default)
[11:15:00.814] INFO: dacScan step from 0 .. 9
[11:15:00.814] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:15:34.276] INFO: Test took 33462ms.
[11:15:34.342] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:15:34.342] INFO: dacScan step from 10 .. 19
[11:15:34.342] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:16:07.822] INFO: Test took 33480ms.
[11:16:07.885] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:16:07.885] INFO: dacScan step from 20 .. 29
[11:16:07.886] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:16:41.342] INFO: Test took 33456ms.
[11:16:41.405] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:16:41.405] INFO: dacScan step from 30 .. 39
[11:16:41.405] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:17:14.889] INFO: Test took 33484ms.
[11:17:14.953] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:17:14.953] INFO: dacScan step from 40 .. 49
[11:17:14.953] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:17:48.430] INFO: Test took 33477ms.
[11:17:48.493] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:17:48.493] INFO: dacScan step from 50 .. 59
[11:17:48.493] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:18:22.102] INFO: Test took 33609ms.
[11:18:22.167] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:18:22.167] INFO: dacScan step from 60 .. 69
[11:18:22.167] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0










[11:18:55.783] INFO: Test took 33616ms.
[11:18:55.850] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:18:55.850] INFO: dacScan step from 70 .. 79
[11:18:55.850] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0







[11:19:29.873] INFO: Test took 34023ms.
[11:19:29.987] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:19:29.990] INFO: dacScan step from 80 .. 89
[11:19:29.990] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0










[11:20:08.343] INFO: Test took 38353ms.
[11:20:08.601] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:20:08.611] INFO: dacScan step from 90 .. 99
[11:20:08.611] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0





[11:20:54.102] INFO: Test took 45491ms.
[11:20:54.532] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:20:54.549] INFO: dacScan step from 100 .. 109
[11:20:54.549] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0








[11:21:46.455] INFO: Test took 51906ms.
[11:21:47.026] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:21:47.042] INFO: dacScan step from 110 .. 119
[11:21:47.042] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0









[11:22:42.101] INFO: Test took 55059ms.
[11:22:42.676] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:22:42.691] INFO: dacScan step from 120 .. 129
[11:22:42.691] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0















[11:23:39.456] INFO: Test took 56765ms.
[11:23:40.022] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:23:40.037] INFO: dacScan step from 130 .. 139
[11:23:40.037] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0








[11:24:37.429] INFO: Test took 57392ms.
[11:24:37.990] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:24:37.005] INFO: dacScan step from 140 .. 149
[11:24:37.005] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0








[11:25:33.135] INFO: Test took 55130ms.
[11:25:33.695] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:25:33.711] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[11:25:33.711] INFO: dumping ASCII scurve output file: SCurveData
[11:25:34.937] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[11:25:34.937] INFO: dumping ASCII scurve output file: SCurveData
[11:25:36.155] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[11:25:36.155] INFO: dumping ASCII scurve output file: SCurveData
[11:25:37.361] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[11:25:37.361] INFO: dumping ASCII scurve output file: SCurveData
[11:25:38.586] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[11:25:38.586] INFO: dumping ASCII scurve output file: SCurveData
[11:25:39.829] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[11:25:39.829] INFO: dumping ASCII scurve output file: SCurveData
[11:25:41.045] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[11:25:41.045] INFO: dumping ASCII scurve output file: SCurveData
[11:25:42.275] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[11:25:42.275] INFO: dumping ASCII scurve output file: SCurveData
[11:25:43.502] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[11:25:43.502] INFO: dumping ASCII scurve output file: SCurveData
[11:25:44.740] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[11:25:44.740] INFO: dumping ASCII scurve output file: SCurveData
[11:25:45.998] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[11:25:45.998] INFO: dumping ASCII scurve output file: SCurveData
[11:25:47.230] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[11:25:47.230] INFO: dumping ASCII scurve output file: SCurveData
[11:25:48.459] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[11:25:48.459] INFO: dumping ASCII scurve output file: SCurveData
[11:25:49.720] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[11:25:49.720] INFO: dumping ASCII scurve output file: SCurveData
[11:25:50.965] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[11:25:50.965] INFO: dumping ASCII scurve output file: SCurveData
[11:25:52.201] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[11:25:52.201] INFO: dumping ASCII scurve output file: SCurveData
[11:25:53.420] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 560492544
[11:25:53.466] INFO: PixTestScurves::scurves() done
[11:25:53.466] INFO: Vcal mean: 96.85 101.46 106.86 98.56 87.71 103.48 93.96 92.77 85.42 80.40 92.10 92.77 78.72 82.18 89.40 101.50
[11:25:53.466] INFO: Vcal RMS: 6.94 7.08 6.48 6.47 5.37 6.50 5.29 6.19 5.80 4.44 6.21 5.51 4.99 5.06 5.64 6.13
[11:25:53.466] INFO: PixTestScurves::fullTest() done, duration: 652 seconds
[11:25:53.466] DEBUG: <PixTestScurves.cc/~PixTestScurves:L141> PixTestScurves dtor
[11:25:53.528] INFO: ######################################################################
[11:25:53.528] INFO: PixTestTrim::doTest()
[11:25:53.528] INFO: ######################################################################
[11:25:53.529] INFO: ----------------------------------------------------------------------
[11:25:53.529] INFO: PixTestTrim::trimTest() ntrig = 10, vcal = 35
[11:25:53.529] INFO: ----------------------------------------------------------------------
[11:25:53.597] INFO: ---> VthrComp thr map (minimal VthrComp)
[11:25:53.597] INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 5 dacrange: 0 .. 159 (20) hits flags = 16 (plus default)
[11:25:53.606] INFO: dacScan step from 0 .. 19
[11:25:53.606] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:26:05.003] INFO: Test took 12397ms.
[11:26:06.024] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:26:06.024] INFO: dacScan step from 20 .. 39
[11:26:06.024] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:26:18.443] INFO: Test took 12419ms.
[11:26:18.464] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:26:18.465] INFO: dacScan step from 40 .. 59
[11:26:18.465] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:26:30.886] INFO: Test took 12421ms.
[11:26:30.907] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:26:30.907] INFO: dacScan step from 60 .. 79
[11:26:30.908] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:26:43.328] INFO: Test took 12420ms.
[11:26:43.350] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:26:43.350] INFO: dacScan step from 80 .. 99
[11:26:43.350] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:26:56.094] INFO: Test took 12744ms.
[11:26:56.147] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:26:56.153] INFO: dacScan step from 100 .. 119
[11:26:56.153] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:27:11.105] INFO: Test took 14952ms.
[11:27:11.255] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:27:11.280] INFO: dacScan step from 120 .. 139
[11:27:11.280] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:27:27.918] INFO: Test took 16638ms.
[11:27:28.066] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:27:28.090] INFO: dacScan step from 140 .. 159
[11:27:28.090] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:27:41.308] INFO: Test took 13218ms.
[11:27:41.370] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:27:41.380] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[11:27:42.526] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[11:27:43.702] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[11:27:44.881] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[11:27:46.028] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[11:27:47.178] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[11:27:48.310] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[11:27:49.464] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[11:27:50.654] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[11:27:51.765] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[11:27:52.843] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[11:27:53.946] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[11:27:55.099] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[11:27:56.209] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[11:27:57.343] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[11:27:58.513] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[11:27:59.687] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 560517120
[11:27:59.689] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 95.4741 minThrLimit = 95.4368 minThrNLimit = 115.11 -> result = 95.4741 -> 95
[11:27:59.689] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 100.779 minThrLimit = 100.689 minThrNLimit = 123.17 -> result = 100.779 -> 100
[11:27:59.690] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 102.87 minThrLimit = 102.867 minThrNLimit = 125.085 -> result = 102.87 -> 102
[11:27:59.690] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 96.2877 minThrLimit = 96.247 minThrNLimit = 117.177 -> result = 96.2877 -> 96
[11:27:59.690] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 91.8187 minThrLimit = 91.7902 minThrNLimit = 115.563 -> result = 91.8187 -> 91
[11:27:59.691] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 96.4616 minThrLimit = 96.4376 minThrNLimit = 114.741 -> result = 96.4616 -> 96
[11:27:59.691] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 95.2481 minThrLimit = 95.2165 minThrNLimit = 117.224 -> result = 95.2481 -> 95
[11:27:59.691] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 99.1027 minThrLimit = 99.0995 minThrNLimit = 123.676 -> result = 99.1027 -> 99
[11:27:59.692] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 86.2446 minThrLimit = 86.2372 minThrNLimit = 107.447 -> result = 86.2446 -> 86
[11:27:59.692] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 81.0176 minThrLimit = 80.9135 minThrNLimit = 99.746 -> result = 81.0176 -> 81
[11:27:59.692] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 88.4634 minThrLimit = 88.3883 minThrNLimit = 106.309 -> result = 88.4634 -> 88
[11:27:59.693] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 94.6766 minThrLimit = 94.6682 minThrNLimit = 116.458 -> result = 94.6766 -> 94
[11:27:59.693] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 82.4952 minThrLimit = 82.4915 minThrNLimit = 104.837 -> result = 82.4952 -> 82
[11:27:59.693] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 86.3781 minThrLimit = 86.3639 minThrNLimit = 109.036 -> result = 86.3781 -> 86
[11:27:59.694] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 94.9138 minThrLimit = 94.8957 minThrNLimit = 118.561 -> result = 94.9138 -> 94
[11:27:59.694] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 99.6843 minThrLimit = 99.6006 minThrNLimit = 119.969 -> result = 99.6843 -> 99
[11:27:59.694] INFO: ROC 0 VthrComp = 95
[11:27:59.694] INFO: ROC 1 VthrComp = 100
[11:27:59.694] INFO: ROC 2 VthrComp = 102
[11:27:59.694] INFO: ROC 3 VthrComp = 96
[11:27:59.695] INFO: ROC 4 VthrComp = 91
[11:27:59.695] INFO: ROC 5 VthrComp = 96
[11:27:59.695] INFO: ROC 6 VthrComp = 95
[11:27:59.695] INFO: ROC 7 VthrComp = 99
[11:27:59.695] INFO: ROC 8 VthrComp = 86
[11:27:59.695] INFO: ROC 9 VthrComp = 81
[11:27:59.695] INFO: ROC 10 VthrComp = 88
[11:27:59.696] INFO: ROC 11 VthrComp = 94
[11:27:59.696] INFO: ROC 12 VthrComp = 82
[11:27:59.696] INFO: ROC 13 VthrComp = 86
[11:27:59.696] INFO: ROC 14 VthrComp = 94
[11:27:59.696] INFO: ROC 15 VthrComp = 99
[11:27:59.696] INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[11:27:59.697] INFO: ---> dac: vcal name: TrimThr1 ntrig: 5 dacrange: 0 .. 159 (20) hits flags = 16 (plus default)
[11:27:59.705] INFO: dacScan step from 0 .. 19
[11:27:59.705] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:28:12.102] INFO: Test took 12397ms.
[11:28:12.124] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:28:12.124] INFO: dacScan step from 20 .. 39
[11:28:12.124] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:28:24.630] INFO: Test took 12506ms.
[11:28:24.661] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:28:24.664] INFO: dacScan step from 40 .. 59
[11:28:24.664] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:28:39.705] INFO: Test took 15041ms.
[11:28:39.853] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:28:39.878] INFO: dacScan step from 60 .. 79
[11:28:39.878] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:28:56.554] INFO: Test took 16676ms.
[11:28:56.721] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:28:56.749] INFO: dacScan step from 80 .. 99
[11:28:56.749] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:29:13.439] INFO: Test took 16690ms.
[11:29:13.601] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:29:13.629] INFO: dacScan step from 100 .. 119
[11:29:13.629] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:29:30.390] INFO: Test took 16761ms.
[11:29:30.554] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:29:30.582] INFO: dacScan step from 120 .. 139
[11:29:30.582] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:29:48.812] INFO: Test took 18230ms.
[11:29:48.977] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:29:48.005] INFO: dacScan step from 140 .. 159
[11:29:48.005] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:30:05.903] INFO: Test took 16898ms.
[11:30:06.065] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:30:06.093] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[11:30:07.445] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[11:30:08.805] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[11:30:10.175] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[11:30:11.522] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[11:30:12.859] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[11:30:14.234] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[11:30:15.584] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[11:30:16.924] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[11:30:18.260] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[11:30:19.595] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[11:30:20.953] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[11:30:22.300] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[11:30:23.634] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[11:30:24.960] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[11:30:26.314] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[11:30:27.678] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 560517120
[11:30:27.679] INFO: roc 0 with ID = 0 has maximal Vcal 63.0112 for pixel 21/76 mean/min/max = 47.2227/31.3837/63.0617
[11:30:27.680] INFO: roc 1 with ID = 1 has maximal Vcal 63.2257 for pixel 0/49 mean/min/max = 47.503/31.6245/63.3816
[11:30:27.680] INFO: roc 2 with ID = 2 has maximal Vcal 66.6232 for pixel 18/1 mean/min/max = 49.7501/32.8306/66.6696
[11:30:27.680] INFO: roc 3 with ID = 3 has maximal Vcal 64.0032 for pixel 0/34 mean/min/max = 47.4692/30.8132/64.1252
[11:30:27.680] INFO: roc 4 with ID = 4 has maximal Vcal 58.7032 for pixel 0/51 mean/min/max = 45.7397/32.7314/58.7479
[11:30:27.681] INFO: roc 5 with ID = 5 has maximal Vcal 65.6618 for pixel 7/69 mean/min/max = 48.6236/31.374/65.8731
[11:30:27.681] INFO: roc 6 with ID = 6 has maximal Vcal 58.6749 for pixel 5/12 mean/min/max = 45.2895/31.6976/58.8815
[11:30:27.681] INFO: roc 7 with ID = 7 has maximal Vcal 60.5796 for pixel 5/21 mean/min/max = 46.1551/31.5288/60.7814
[11:30:27.681] INFO: roc 8 with ID = 8 has maximal Vcal 60.1757 for pixel 0/76 mean/min/max = 45.9281/31.5774/60.2788
[11:30:27.682] INFO: roc 9 with ID = 9 has maximal Vcal 58.1076 for pixel 2/37 mean/min/max = 45.0842/31.9563/58.2122
[11:30:27.682] INFO: roc 10 with ID = 10 has maximal Vcal 63.6896 for pixel 0/69 mean/min/max = 47.9688/32.091/63.8466
[11:30:27.682] INFO: roc 11 with ID = 11 has maximal Vcal 58.8895 for pixel 6/0 mean/min/max = 45.9898/32.7825/59.1972
[11:30:27.682] INFO: roc 12 with ID = 12 has maximal Vcal 58.9973 for pixel 5/54 mean/min/max = 45.5107/31.9934/59.028
[11:30:27.683] INFO: roc 13 with ID = 13 has maximal Vcal 57.1327 for pixel 23/16 mean/min/max = 44.9487/32.504/57.3934
[11:30:27.683] INFO: roc 14 with ID = 14 has maximal Vcal 59.0357 for pixel 0/77 mean/min/max = 45.7229/32.2377/59.208
[11:30:27.683] INFO: roc 15 with ID = 15 has maximal Vcal 62.4866 for pixel 21/66 mean/min/max = 47.3312/32.0956/62.5667
[11:30:27.683] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:31:41.948] INFO: Test took 74265ms.
[11:31:42.723] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.4438 < 35 for itrim = 130; old thr = 34.0586 ... break
[11:31:42.748] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.2362 < 35 for itrim = 122; old thr = 32.6375 ... break
[11:31:42.770] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 36.4843 < 35 for itrim = 115; old thr = 33.469 ... break
[11:31:42.790] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.7851 < 35 for itrim = 115; old thr = 34.1281 ... break
[11:31:42.818] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.089 < 35 for itrim = 111; old thr = 32.403 ... break
[11:31:42.840] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.0989 < 35 for itrim = 127; old thr = 34.1798 ... break
[11:31:42.865] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.2481 < 35 for itrim = 99; old thr = 34.6187 ... break
[11:31:42.901] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.2892 < 35 for itrim = 126; old thr = 34.3337 ... break
[11:31:42.926] DEBUG: <PixTestTrim.cc/trimTest:L309> vtrim: vcal = 36.4862 < 35 for itrim+1 = 112; old thr = 33.5959 ... break
[11:31:42.948] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.2472 < 35 for itrim = 110; old thr = 33.7461 ... break
[11:31:42.966] DEBUG: <PixTestTrim.cc/trimTest:L309> vtrim: vcal = 35.7943 < 35 for itrim+1 = 113; old thr = 34.2823 ... break
[11:31:42.998] DEBUG: <PixTestTrim.cc/trimTest:L309> vtrim: vcal = 36.5282 < 35 for itrim+1 = 105; old thr = 34.7803 ... break
[11:31:43.033] DEBUG: <PixTestTrim.cc/trimTest:L309> vtrim: vcal = 35.8758 < 35 for itrim+1 = 111; old thr = 34.8682 ... break
[11:31:43.069] DEBUG: <PixTestTrim.cc/trimTest:L309> vtrim: vcal = 36.1129 < 35 for itrim+1 = 115; old thr = 34.4699 ... break
[11:31:43.094] DEBUG: <PixTestTrim.cc/trimTest:L309> vtrim: vcal = 36.5247 < 35 for itrim+1 = 98; old thr = 33.9459 ... break
[11:31:43.122] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.3927 < 35 for itrim = 137; old thr = 32.0917 ... break
[11:31:43.185] INFO: ---> dac: vcal name: TrimThr2 ntrig: 10 dacrange: 0 .. 199 (20) hits flags = 16 (plus default)
[11:31:43.194] INFO: dacScan step from 0 .. 19
[11:31:43.194] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:32:01.420] INFO: Test took 18226ms.
[11:32:01.470] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:32:01.472] INFO: dacScan step from 20 .. 39
[11:32:01.472] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:32:23.762] INFO: Test took 22290ms.
[11:32:23.989] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:32:24.016] INFO: dacScan step from 40 .. 59
[11:32:24.016] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:32:50.739] INFO: Test took 26723ms.
[11:32:51.020] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:32:51.048] INFO: dacScan step from 60 .. 79
[11:32:51.048] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:33:17.969] INFO: Test took 26921ms.
[11:33:18.249] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:33:18.278] INFO: dacScan step from 80 .. 99
[11:33:18.278] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:33:45.184] INFO: Test took 26906ms.
[11:33:45.467] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:33:45.496] INFO: dacScan step from 100 .. 119
[11:33:45.496] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:34:12.428] INFO: Test took 26932ms.
[11:34:12.703] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:34:12.732] INFO: dacScan step from 120 .. 139
[11:34:12.732] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:34:41.187] INFO: Test took 28455ms.
[11:34:41.464] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:34:41.492] INFO: dacScan step from 140 .. 159
[11:34:41.492] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:35:08.629] INFO: Test took 27137ms.
[11:35:08.905] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:35:08.933] INFO: dacScan step from 160 .. 179
[11:35:08.933] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:35:35.986] INFO: Test took 27053ms.
[11:35:36.267] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:35:36.296] INFO: dacScan step from 180 .. 199
[11:35:36.297] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:36:04.109] INFO: Test took 27812ms.
[11:36:04.391] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:36:04.420] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[11:36:05.812] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[11:36:07.215] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[11:36:08.626] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[11:36:09.988] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[11:36:11.345] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[11:36:12.743] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[11:36:14.102] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[11:36:15.482] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[11:36:16.839] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[11:36:18.199] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[11:36:19.566] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[11:36:20.919] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[11:36:22.265] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[11:36:23.610] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[11:36:24.983] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[11:36:26.372] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 565010432
[11:36:26.374] INFO: ---> TrimStepCorr4 extremal thresholds: 0.019880 .. 255.000000
[11:36:26.435] INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 4 dacrange: 0 .. 255 (20) hits flags = 16 (plus default)
[11:36:26.444] INFO: dacScan step from 0 .. 19
[11:36:26.444] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:36:37.690] INFO: Test took 11246ms.
[11:36:37.711] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:36:37.711] INFO: dacScan step from 20 .. 39
[11:36:37.711] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:36:49.800] INFO: Test took 12089ms.
[11:36:49.882] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:36:49.897] INFO: dacScan step from 40 .. 59
[11:36:49.898] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:37:04.432] INFO: Test took 14534ms.
[11:37:04.581] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:37:04.609] INFO: dacScan step from 60 .. 79
[11:37:04.610] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:37:19.348] INFO: Test took 14738ms.
[11:37:19.491] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:37:19.519] INFO: dacScan step from 80 .. 99
[11:37:19.519] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:37:34.262] INFO: Test took 14743ms.
[11:37:34.407] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:37:34.435] INFO: dacScan step from 100 .. 119
[11:37:34.436] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:37:49.263] INFO: Test took 14827ms.
[11:37:49.406] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:37:49.434] INFO: dacScan step from 120 .. 139
[11:37:49.435] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:38:05.712] INFO: Test took 16277ms.
[11:38:05.854] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:38:05.882] INFO: dacScan step from 140 .. 159
[11:38:05.882] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:38:20.851] INFO: Test took 14969ms.
[11:38:20.994] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:38:21.022] INFO: dacScan step from 160 .. 179
[11:38:21.022] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:38:35.917] INFO: Test took 14895ms.
[11:38:36.060] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:38:36.088] INFO: dacScan step from 180 .. 199
[11:38:36.088] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:38:51.726] INFO: Test took 15638ms.
[11:38:51.869] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:38:51.897] INFO: dacScan step from 200 .. 219
[11:38:51.897] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:39:06.649] INFO: Test took 14752ms.
[11:39:06.792] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:39:06.820] INFO: dacScan step from 220 .. 239
[11:39:06.820] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:39:21.562] INFO: Test took 14742ms.
[11:39:21.705] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:39:21.732] INFO: dacScan step from 240 .. 255
[11:39:21.733] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:39:34.020] INFO: Test took 12287ms.
[11:39:34.135] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:39:34.158] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[11:39:35.885] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[11:39:37.612] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[11:39:39.353] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[11:39:41.072] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[11:39:42.794] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[11:39:44.538] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[11:39:46.252] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[11:39:47.972] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[11:39:49.693] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[11:39:51.431] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[11:39:53.152] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[11:39:54.859] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[11:39:56.567] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[11:39:58.268] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[11:39:59.979] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[11:40:01.694] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 565014528
[11:40:01.761] INFO: ---> TrimStepCorr2 extremal thresholds: 3.500000 .. 76.767398
[11:40:01.824] INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 4 dacrange: 3 .. 86 (20) hits flags = 16 (plus default)
[11:40:01.832] INFO: dacScan step from 3 .. 22
[11:40:01.832] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:40:13.093] INFO: Test took 11261ms.
[11:40:13.114] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:40:13.114] INFO: dacScan step from 23 .. 42
[11:40:13.114] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:40:25.617] INFO: Test took 12503ms.
[11:40:25.717] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:40:25.737] INFO: dacScan step from 43 .. 62
[11:40:25.737] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:40:40.446] INFO: Test took 14709ms.
[11:40:40.590] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:40:40.618] INFO: dacScan step from 63 .. 82
[11:40:40.618] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:40:55.364] INFO: Test took 14746ms.
[11:40:55.509] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:40:55.537] INFO: dacScan step from 83 .. 86
[11:40:55.537] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:41:00.493] INFO: Test took 4956ms.
[11:41:00.523] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:41:00.530] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[11:41:01.634] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[11:41:02.742] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[11:41:03.853] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[11:41:04.956] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[11:41:06.054] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[11:41:07.169] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[11:41:08.278] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[11:41:09.382] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[11:41:10.480] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[11:41:11.586] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[11:41:12.689] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[11:41:13.792] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[11:41:14.898] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[11:41:16.007] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[11:41:17.115] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[11:41:18.223] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 565137408
[11:41:18.289] INFO: ---> TrimStepCorr1a extremal thresholds: 1.461449 .. 66.650240
[11:41:18.352] INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 4 dacrange: 1 .. 76 (20) hits flags = 16 (plus default)
[11:41:18.360] INFO: dacScan step from 1 .. 20
[11:41:18.360] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:41:29.608] INFO: Test took 11248ms.
[11:41:29.629] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:41:29.629] INFO: dacScan step from 21 .. 40
[11:41:29.629] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:41:41.782] INFO: Test took 12153ms.
[11:41:41.864] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:41:41.880] INFO: dacScan step from 41 .. 60
[11:41:41.881] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:41:56.575] INFO: Test took 14694ms.
[11:41:56.720] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:41:56.748] INFO: dacScan step from 61 .. 76
[11:41:56.748] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:42:09.024] INFO: Test took 12276ms.
[11:42:09.138] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:42:09.161] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[11:42:10.201] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[11:42:11.240] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[11:42:12.292] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[11:42:13.340] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[11:42:14.394] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[11:42:15.444] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[11:42:16.495] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[11:42:17.545] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[11:42:18.592] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[11:42:19.640] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[11:42:20.683] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[11:42:21.720] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[11:42:22.762] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[11:42:23.806] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[11:42:24.844] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[11:42:25.895] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 565137408
[11:42:25.962] INFO: ---> TrimStepCorr1b extremal thresholds: 0.359351 .. 45.346430
[11:42:26.025] INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 4 dacrange: 0 .. 55 (20) hits flags = 16 (plus default)
[11:42:26.034] INFO: dacScan step from 0 .. 19
[11:42:26.034] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:42:37.279] INFO: Test took 11245ms.
[11:42:37.300] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:42:37.300] INFO: dacScan step from 20 .. 39
[11:42:37.300] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:42:49.305] INFO: Test took 12005ms.
[11:42:49.381] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:42:49.398] INFO: dacScan step from 40 .. 55
[11:42:49.398] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:43:01.618] INFO: Test took 12220ms.
[11:43:01.739] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:43:01.763] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[11:43:02.652] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[11:43:03.542] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[11:43:04.430] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[11:43:05.318] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[11:43:06.205] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[11:43:07.092] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[11:43:07.979] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[11:43:08.864] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[11:43:09.749] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[11:43:10.637] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[11:43:11.527] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[11:43:12.415] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[11:43:13.299] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[11:43:14.187] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[11:43:15.077] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[11:43:15.968] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 565137408
[11:43:16.035] INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[11:43:16.035] INFO: ---> dac: vcal name: TrimThrFinal ntrig: 10 dacrange: 15 .. 55 (20) hits flags = 16 (plus default)
[11:43:16.043] INFO: dacScan step from 15 .. 34
[11:43:16.044] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:43:34.503] INFO: Test took 18459ms.
[11:43:34.573] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:43:34.586] INFO: dacScan step from 35 .. 54
[11:43:34.586] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:44:00.700] INFO: Test took 26114ms.
[11:44:00.993] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:44:01.023] INFO: dacScan step from 55 .. 55
[11:44:01.023] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:44:04.742] INFO: Test took 3719ms.
[11:44:04.757] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:44:04.760] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[11:44:05.495] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[11:44:06.231] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[11:44:06.963] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[11:44:07.697] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[11:44:08.429] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[11:44:09.159] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[11:44:09.889] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[11:44:10.622] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[11:44:11.357] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[11:44:12.089] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[11:44:12.826] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[11:44:13.561] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[11:44:14.295] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[11:44:15.027] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[11:44:15.760] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[11:44:16.498] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 565141504
[11:44:16.549] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//dacParameters35_C0.dat
[11:44:16.549] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//dacParameters35_C1.dat
[11:44:16.549] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//dacParameters35_C2.dat
[11:44:16.549] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//dacParameters35_C3.dat
[11:44:16.549] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//dacParameters35_C4.dat
[11:44:16.550] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//dacParameters35_C5.dat
[11:44:16.550] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//dacParameters35_C6.dat
[11:44:16.550] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//dacParameters35_C7.dat
[11:44:16.550] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//dacParameters35_C8.dat
[11:44:16.550] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//dacParameters35_C9.dat
[11:44:16.550] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//dacParameters35_C10.dat
[11:44:16.550] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//dacParameters35_C11.dat
[11:44:16.550] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//dacParameters35_C12.dat
[11:44:16.550] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//dacParameters35_C13.dat
[11:44:16.550] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//dacParameters35_C14.dat
[11:44:16.550] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//dacParameters35_C15.dat
[11:44:16.550] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//trimParameters35_C0.dat
[11:44:16.556] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//trimParameters35_C1.dat
[11:44:16.561] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//trimParameters35_C2.dat
[11:44:16.566] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//trimParameters35_C3.dat
[11:44:16.572] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//trimParameters35_C4.dat
[11:44:16.577] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//trimParameters35_C5.dat
[11:44:16.582] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//trimParameters35_C6.dat
[11:44:16.587] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//trimParameters35_C7.dat
[11:44:16.593] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//trimParameters35_C8.dat
[11:44:16.598] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//trimParameters35_C9.dat
[11:44:16.603] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//trimParameters35_C10.dat
[11:44:16.609] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//trimParameters35_C11.dat
[11:44:16.614] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//trimParameters35_C12.dat
[11:44:16.619] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//trimParameters35_C13.dat
[11:44:16.625] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//trimParameters35_C14.dat
[11:44:16.630] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//trimParameters35_C15.dat
[11:44:16.635] INFO: PixTestTrim::trimTest() done
[11:44:16.635] INFO: vtrim: 130 122 115 115 111 127 99 126 112 110 113 105 111 115 98 137
[11:44:16.635] INFO: vthrcomp: 95 100 102 96 91 96 95 99 86 81 88 94 82 86 94 99
[11:44:16.635] INFO: vcal mean: 35.00 34.98 35.06 35.00 35.06 35.06 35.02 35.02 34.96 35.04 35.03 35.04 35.05 35.02 35.02 35.06
[11:44:16.635] INFO: vcal RMS: 1.47 1.63 1.32 1.35 1.02 1.58 1.28 1.16 1.31 1.07 1.10 1.08 1.28 1.53 1.07 1.38
[11:44:16.635] INFO: bits mean: 9.77 9.60 9.26 9.31 9.71 9.51 9.66 9.51 9.54 10.25 9.33 9.58 9.86 10.24 9.40 9.73
[11:44:16.635] INFO: bits RMS: 2.49 2.55 2.40 2.74 2.47 2.52 2.68 2.73 2.67 2.34 2.58 2.51 2.53 2.33 2.72 2.50
[11:44:16.641] INFO: ----------------------------------------------------------------------
[11:44:16.641] INFO: PixTestTrim::trimBitTest() ntrig = 10, vtrims = 255 240 150 100
[11:44:16.641] INFO: ----------------------------------------------------------------------
[11:44:16.645] DEBUG: <PixTestTrim.cc/trimBitTest:L515> trimBitTest determine threshold map without trims
[11:44:16.645] INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 10 dacrange: 0 .. 199 (20) hits flags = 16 (plus default)
[11:44:16.654] INFO: dacScan step from 0 .. 19
[11:44:16.654] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:44:34.794] INFO: Test took 18140ms.
[11:44:34.829] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:44:34.829] INFO: dacScan step from 20 .. 39
[11:44:34.830] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:44:53.113] INFO: Test took 18283ms.
[11:44:53.166] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:44:53.170] INFO: dacScan step from 40 .. 59
[11:44:53.170] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:45:16.536] INFO: Test took 23366ms.
[11:45:16.782] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:45:16.810] INFO: dacScan step from 60 .. 79
[11:45:16.810] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:45:43.620] INFO: Test took 26810ms.
[11:45:43.897] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:45:43.926] INFO: dacScan step from 80 .. 99
[11:45:43.926] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:46:10.817] INFO: Test took 26891ms.
[11:46:11.090] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:46:11.118] INFO: dacScan step from 100 .. 119
[11:46:11.118] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:46:38.092] INFO: Test took 26974ms.
[11:46:38.368] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:46:38.398] INFO: dacScan step from 120 .. 139
[11:46:38.398] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:47:06.877] INFO: Test took 28479ms.
[11:47:07.152] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:47:07.180] INFO: dacScan step from 140 .. 159
[11:47:07.181] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:47:34.354] INFO: Test took 27173ms.
[11:47:34.628] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:47:34.656] INFO: dacScan step from 160 .. 179
[11:47:34.657] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:48:01.692] INFO: Test took 27035ms.
[11:48:01.967] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:48:01.995] INFO: dacScan step from 180 .. 199
[11:48:01.995] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:48:29.759] INFO: Test took 27764ms.
[11:48:30.034] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:48:30.063] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[11:48:31.434] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[11:48:32.826] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[11:48:34.248] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[11:48:35.620] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[11:48:36.970] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[11:48:38.382] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[11:48:39.753] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[11:48:41.120] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[11:48:42.472] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[11:48:43.818] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[11:48:45.190] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[11:48:46.535] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[11:48:47.881] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[11:48:49.228] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[11:48:50.592] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[11:48:51.981] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 565153792
[11:48:51.982] DEBUG: <PixTestTrim.cc/trimBitTest:L530> trimBitTest initDUT with trim bits = 14
[11:48:52.044] DEBUG: <PixTestTrim.cc/trimBitTest:L536> trimBitTest threshold map with trim = 14
[11:48:52.044] INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 10 dacrange: 0 .. 163 (20) hits flags = 16 (plus default)
[11:48:52.053] INFO: dacScan step from 0 .. 19
[11:48:52.053] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:49:10.195] INFO: Test took 18142ms.
[11:49:10.232] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:49:10.232] INFO: dacScan step from 20 .. 39
[11:49:10.232] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:49:28.973] INFO: Test took 18741ms.
[11:49:29.058] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:49:29.067] INFO: dacScan step from 40 .. 59
[11:49:29.067] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:49:53.978] INFO: Test took 24911ms.
[11:49:54.252] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:49:54.283] INFO: dacScan step from 60 .. 79
[11:49:54.283] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:50:21.207] INFO: Test took 26924ms.
[11:50:21.483] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:50:21.512] INFO: dacScan step from 80 .. 99
[11:50:21.512] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:50:48.497] INFO: Test took 26985ms.
[11:50:48.772] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:50:48.800] INFO: dacScan step from 100 .. 119
[11:50:48.800] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:51:15.741] INFO: Test took 26941ms.
[11:51:16.015] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:51:16.044] INFO: dacScan step from 120 .. 139
[11:51:16.044] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:51:44.385] INFO: Test took 28341ms.
[11:51:44.656] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:51:44.684] INFO: dacScan step from 140 .. 159
[11:51:44.684] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:52:11.885] INFO: Test took 27201ms.
[11:52:12.155] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:52:12.184] INFO: dacScan step from 160 .. 163
[11:52:12.184] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:52:19.559] INFO: Test took 7375ms.
[11:52:19.614] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:52:19.621] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[11:52:20.914] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[11:52:22.221] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[11:52:23.529] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[11:52:24.817] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[11:52:26.107] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[11:52:27.408] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[11:52:28.702] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[11:52:29.989] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[11:52:31.275] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[11:52:32.558] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[11:52:33.839] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[11:52:35.127] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[11:52:36.400] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[11:52:37.684] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[11:52:38.984] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[11:52:40.282] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 565153792
[11:52:40.283] DEBUG: <PixTestTrim.cc/trimBitTest:L530> trimBitTest initDUT with trim bits = 13
[11:52:40.345] DEBUG: <PixTestTrim.cc/trimBitTest:L536> trimBitTest threshold map with trim = 13
[11:52:40.345] INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 10 dacrange: 0 .. 143 (20) hits flags = 16 (plus default)
[11:52:40.354] INFO: dacScan step from 0 .. 19
[11:52:40.354] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:52:58.497] INFO: Test took 18143ms.
[11:52:58.534] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:52:58.534] INFO: dacScan step from 20 .. 39
[11:52:58.535] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:53:18.139] INFO: Test took 19604ms.
[11:53:18.268] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:53:18.284] INFO: dacScan step from 40 .. 59
[11:53:18.284] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:53:44.308] INFO: Test took 26024ms.
[11:53:44.592] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:53:44.621] INFO: dacScan step from 60 .. 79
[11:53:44.622] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:54:11.609] INFO: Test took 26987ms.
[11:54:11.885] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:54:11.913] INFO: dacScan step from 80 .. 99
[11:54:11.913] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:54:38.887] INFO: Test took 26974ms.
[11:54:39.163] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:54:39.191] INFO: dacScan step from 100 .. 119
[11:54:39.191] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:55:06.142] INFO: Test took 26951ms.
[11:55:06.410] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:55:06.438] INFO: dacScan step from 120 .. 139
[11:55:06.438] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:55:34.877] INFO: Test took 28439ms.
[11:55:35.151] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:55:35.180] INFO: dacScan step from 140 .. 143
[11:55:35.180] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:55:42.748] INFO: Test took 7568ms.
[11:55:42.803] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:55:42.811] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[11:55:44.024] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[11:55:45.246] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[11:55:46.474] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[11:55:47.687] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[11:55:48.905] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[11:55:50.134] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[11:55:51.353] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[11:55:52.572] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[11:55:53.787] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[11:55:54.004] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[11:55:56.217] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[11:55:57.423] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[11:55:58.631] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[11:55:59.840] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[11:56:01.066] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[11:56:02.292] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 565157888
[11:56:02.292] DEBUG: <PixTestTrim.cc/trimBitTest:L530> trimBitTest initDUT with trim bits = 11
[11:56:02.355] DEBUG: <PixTestTrim.cc/trimBitTest:L536> trimBitTest threshold map with trim = 11
[11:56:02.355] INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 10 dacrange: 0 .. 129 (20) hits flags = 16 (plus default)
[11:56:02.364] INFO: dacScan step from 0 .. 19
[11:56:02.364] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:56:20.497] INFO: Test took 18133ms.
[11:56:20.535] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:56:20.535] INFO: dacScan step from 20 .. 39
[11:56:20.535] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:56:40.795] INFO: Test took 20259ms.
[11:56:40.954] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:56:40.973] INFO: dacScan step from 40 .. 59
[11:56:40.973] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:57:07.404] INFO: Test took 26431ms.
[11:57:07.689] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:57:07.718] INFO: dacScan step from 60 .. 79
[11:57:07.719] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:57:34.729] INFO: Test took 27010ms.
[11:57:34.001] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:57:35.030] INFO: dacScan step from 80 .. 99
[11:57:35.030] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:58:02.031] INFO: Test took 27001ms.
[11:58:02.303] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:58:02.332] INFO: dacScan step from 100 .. 119
[11:58:02.332] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:58:29.305] INFO: Test took 26973ms.
[11:58:29.580] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:58:29.609] INFO: dacScan step from 120 .. 129
[11:58:29.609] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:58:44.672] INFO: Test took 15063ms.
[11:58:44.808] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:58:44.824] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[11:58:45.984] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[11:58:47.142] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[11:58:48.309] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[11:58:49.459] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[11:58:50.611] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[11:58:51.775] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[11:58:52.928] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[11:58:54.087] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[11:58:55.239] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[11:58:56.399] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[11:58:57.561] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[11:58:58.721] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[11:58:59.876] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[11:59:01.029] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[11:59:02.186] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[11:59:03.345] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 565157888
[11:59:03.346] DEBUG: <PixTestTrim.cc/trimBitTest:L530> trimBitTest initDUT with trim bits = 7
[11:59:03.408] DEBUG: <PixTestTrim.cc/trimBitTest:L536> trimBitTest threshold map with trim = 7
[11:59:03.408] INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 10 dacrange: 0 .. 102 (20) hits flags = 16 (plus default)
[11:59:03.417] INFO: dacScan step from 0 .. 19
[11:59:03.417] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:59:21.618] INFO: Test took 18201ms.
[11:59:21.661] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:59:21.662] INFO: dacScan step from 20 .. 39
[11:59:21.662] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:59:43.146] INFO: Test took 21484ms.
[11:59:43.348] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:59:43.372] INFO: dacScan step from 40 .. 59
[11:59:43.372] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[12:00:10.136] INFO: Test took 26764ms.
[12:00:10.420] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:00:10.450] INFO: dacScan step from 60 .. 79
[12:00:10.450] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[12:00:37.336] INFO: Test took 26886ms.
[12:00:37.608] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:00:37.636] INFO: dacScan step from 80 .. 99
[12:00:37.636] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[12:01:04.608] INFO: Test took 26972ms.
[12:01:04.880] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:01:04.908] INFO: dacScan step from 100 .. 102
[12:01:04.909] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[12:01:11.063] INFO: Test took 6154ms.
[12:01:11.104] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:01:11.111] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[12:01:12.136] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[12:01:13.159] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[12:01:14.179] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[12:01:15.202] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[12:01:16.227] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[12:01:17.251] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[12:01:18.281] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[12:01:19.304] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[12:01:20.323] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[12:01:21.339] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[12:01:22.367] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[12:01:23.386] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[12:01:24.410] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[12:01:25.432] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[12:01:26.462] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[12:01:27.481] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 565157888
[12:01:27.599] INFO: PixTestTrim::trimBitTest() done
[12:01:27.600] INFO: PixTestTrim::doTest() done, duration: 2134 seconds
[12:01:27.600] DEBUG: <PixTestTrim.cc/~PixTestTrim:L104> PixTestTrim dtor
[12:01:28.181] DEBUG: <PixTest.cc/setTestParameter:L569> setting ntrig to new value 10
[12:01:28.182] DEBUG: <PixTestPhOptimization.cc/setParameter:L37> setting fParNtrig ->10<- from sval = 10
[12:01:28.182] DEBUG: <PixTestPhOptimization.cc/setParameter:L42> setting fSafetyMarginLow ->20<- from sval = 20
[12:01:28.182] DEBUG: <PixTestPhOptimization.cc/setParameter:L48> setting fVcalMax ->100<- from sval = 100
[12:01:28.182] DEBUG: <PixTestPhOptimization.cc/setParameter:L53> setting fQuantMax ->0.98<- from sval = 0.98
[12:01:28.182] INFO: ######################################################################
[12:01:28.182] INFO: PixTestPhOptimization::doTest() Ntrig = 10
[12:01:28.182] INFO: ######################################################################
[12:01:28.183] DEBUG: <PixTest.cc/efficiencyMaps:L328> attempt #0
[12:01:31.871] INFO: Test took 3687ms.
[12:01:31.889] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:01:31.889] DEBUG: <PixTest.cc/efficiencyMaps:L339> eff result size = 66532
[12:01:31.889] DEBUG: <PixTest.cc/efficiencyMaps:L344> Create hists PixelAlive_C0 .. PixelAlive_C15
[12:01:31.892] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [0, 0, 0] has eff 0/10
[12:01:31.892] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [0, 0, 0]
[12:01:31.892] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [0, 0, 1] has eff 0/10
[12:01:31.892] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [0, 0, 1]
[12:01:31.892] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [0, 28, 49] has eff 0/10
[12:01:31.892] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [0, 28, 49]
[12:01:31.892] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [1, 16, 9] has eff 0/10
[12:01:31.892] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [1, 16, 9]
[12:01:31.892] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [1, 17, 9] has eff 0/10
[12:01:31.892] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [1, 17, 9]
[12:01:31.892] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [1, 16, 10] has eff 0/10
[12:01:31.892] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [1, 16, 10]
[12:01:31.892] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [1, 17, 10] has eff 0/10
[12:01:31.892] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [1, 17, 10]
[12:01:31.892] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [1, 43, 46] has eff 0/10
[12:01:31.892] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [1, 43, 46]
[12:01:31.892] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [2, 47, 54] has eff 4/10
[12:01:31.893] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [2, 47, 54]
[12:01:31.893] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [2, 42, 75] has eff 0/10
[12:01:31.893] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [2, 42, 75]
[12:01:31.893] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [3, 48, 41] has eff 0/10
[12:01:31.893] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [3, 48, 41]
[12:01:31.893] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [3, 41, 45] has eff 0/10
[12:01:31.893] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [3, 41, 45]
[12:01:31.893] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [5, 25, 22] has eff 0/10
[12:01:31.893] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [5, 25, 22]
[12:01:31.893] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [5, 37, 37] has eff 0/10
[12:01:31.893] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [5, 37, 37]
[12:01:31.893] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [5, 31, 42] has eff 0/10
[12:01:31.893] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [5, 31, 42]
[12:01:31.893] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [5, 44, 46] has eff 0/10
[12:01:31.893] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [5, 44, 46]
[12:01:31.893] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [5, 34, 57] has eff 0/10
[12:01:31.893] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [5, 34, 57]
[12:01:31.893] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [5, 31, 60] has eff 1/10
[12:01:31.893] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [5, 31, 60]
[12:01:31.893] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [5, 43, 67] has eff 1/10
[12:01:31.893] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [5, 43, 67]
[12:01:31.893] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [6, 27, 29] has eff 0/10
[12:01:31.893] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [6, 27, 29]
[12:01:31.893] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [6, 40, 76] has eff 0/10
[12:01:31.893] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [6, 40, 76]
[12:01:31.893] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [7, 36, 76] has eff 4/10
[12:01:31.893] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [7, 36, 76]
[12:01:31.894] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [8, 49, 69] has eff 0/10
[12:01:31.894] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [8, 49, 69]
[12:01:31.894] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [8, 0, 70] has eff 0/10
[12:01:31.894] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [8, 0, 70]
[12:01:31.894] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [10, 47, 20] has eff 7/10
[12:01:31.894] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [10, 47, 20]
[12:01:31.894] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [11, 48, 34] has eff 4/10
[12:01:31.894] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [11, 48, 34]
[12:01:31.894] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [12, 21, 22] has eff 0/10
[12:01:31.894] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [12, 21, 22]
[12:01:31.894] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [12, 30, 49] has eff 0/10
[12:01:31.894] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [12, 30, 49]
[12:01:31.894] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [13, 49, 14] has eff 0/10
[12:01:31.894] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [13, 49, 14]
[12:01:31.894] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [13, 2, 73] has eff 0/10
[12:01:31.894] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [13, 2, 73]
[12:01:31.894] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [13, 18, 76] has eff 0/10
[12:01:31.894] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [13, 18, 76]
[12:01:31.894] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [13, 19, 76] has eff 0/10
[12:01:31.894] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [13, 19, 76]
[12:01:31.894] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [15, 50, 0] has eff 0/10
[12:01:31.894] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [15, 50, 0]
[12:01:31.894] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [15, 51, 0] has eff 0/10
[12:01:31.894] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [15, 51, 0]
[12:01:31.899] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L239> Number of bad pixels found: 34
[12:01:31.899] DEBUG: <PixTestPhOptimization.cc/doTest:L124> **********Ph range will be optimised on the whole ROC***********
[12:01:31.899] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L276> ROC type is newer than digv2
[12:01:31.899] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L277> ROC type is psi46digv21respin
[12:01:32.089] DEBUG: <PixTest.cc/phMaps:L264> attempt #0
[12:01:35.781] INFO: Test took 3692ms.
[12:01:35.841] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:01:35.841] DEBUG: <PixTest.cc/phMaps:L275> eff result size = 66532
[12:01:35.841] DEBUG: <PixTest.cc/phMaps:L282> Create hists maxphmap_C0 .. maxphmap_C15
[12:01:35.845] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 205.336
[12:01:35.845] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,6] phvalue 206
[12:01:35.845] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 202.031
[12:01:35.845] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [4 ,6] phvalue 203
[12:01:35.845] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 201.595
[12:01:35.845] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [6 ,5] phvalue 202
[12:01:35.845] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 204.1
[12:01:35.845] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,69] phvalue 204
[12:01:35.845] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 193.819
[12:01:35.845] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [4 ,15] phvalue 193
[12:01:35.845] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 200.75
[12:01:35.845] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [4 ,6] phvalue 200
[12:01:35.846] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 214.851
[12:01:35.846] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [6 ,12] phvalue 215
[12:01:35.846] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 209.296
[12:01:35.846] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,7] phvalue 209
[12:01:35.846] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 200.776
[12:01:35.846] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,15] phvalue 200
[12:01:35.846] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 194.553
[12:01:35.846] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [4 ,6] phvalue 195
[12:01:35.846] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 212.714
[12:01:35.846] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,7] phvalue 213
[12:01:35.846] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 216.481
[12:01:35.846] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,16] phvalue 216
[12:01:35.846] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 211.294
[12:01:35.846] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,5] phvalue 212
[12:01:35.846] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 196.622
[12:01:35.846] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,7] phvalue 197
[12:01:35.847] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 193.827
[12:01:35.847] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [4 ,6] phvalue 193
[12:01:35.847] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 205.53
[12:01:35.847] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,10] phvalue 205
[12:01:35.847] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L427> ROC type is newer than digv2
[12:01:35.847] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L428> ROC type is psi46digv21respin
[12:01:35.847] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L450> init_phScale=150, flag_minPh = 0, minph = 0
[12:01:35.855] DEBUG: <PixTest.cc/phMaps:L264> attempt #0
[12:01:39.557] INFO: Test took 3702ms.
[12:01:39.617] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:01:39.617] DEBUG: <PixTest.cc/phMaps:L275> eff result size = 66531
[12:01:39.617] DEBUG: <PixTest.cc/phMaps:L282> Create hists minphmap_C0 .. minphmap_C15
[12:01:39.620] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L457> result size 0

[12:01:39.621] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L484> done. init_phScale=155, flag_minPh = 1, minph = 72minph_roc = 4
[12:01:39.621] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 88.5413
[12:01:39.621] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [4 ,44] phvalue 89
[12:01:39.621] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 93.6758
[12:01:39.621] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,62] phvalue 94
[12:01:39.621] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 77.8166
[12:01:39.621] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,6] phvalue 78
[12:01:39.621] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 88.8549
[12:01:39.621] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,50] phvalue 89
[12:01:39.622] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 76.3296
[12:01:39.622] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,13] phvalue 77
[12:01:39.622] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 78.0507
[12:01:39.622] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [7 ,12] phvalue 79
[12:01:39.622] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 96.2402
[12:01:39.622] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,13] phvalue 97
[12:01:39.622] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 89.9273
[12:01:39.622] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [4 ,14] phvalue 89
[12:01:39.622] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 84.5756
[12:01:39.622] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [12 ,66] phvalue 85
[12:01:39.622] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 84.2535
[12:01:39.622] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,7] phvalue 85
[12:01:39.622] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 87.202
[12:01:39.622] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [6 ,14] phvalue 88
[12:01:39.623] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 99.2738
[12:01:39.623] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [14 ,42] phvalue 100
[12:01:39.623] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 90.2627
[12:01:39.623] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [4 ,67] phvalue 90
[12:01:39.623] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 81.2115
[12:01:39.623] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [8 ,50] phvalue 82
[12:01:39.623] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 78.7873
[12:01:39.623] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [6 ,66] phvalue 79
[12:01:39.623] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 77.9593
[12:01:39.623] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [8 ,12] phvalue 77
[12:01:39.626] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 4, 44, 0 0
[12:01:39.626] INFO: The DUT currently contains the following objects:
[12:01:39.626] INFO: 2 TBM Cores tbm08c (2 ON)
[12:01:39.626] INFO: TBM Core alpha (0): 7 registers set
[12:01:39.626] INFO: TBM Core beta (1): 7 registers set
[12:01:39.626] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:01:39.626] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:39.626] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:39.626] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:39.626] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:39.626] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:39.626] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:39.626] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:39.626] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:39.626] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:39.626] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:39.626] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:39.626] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:39.626] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:39.626] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:39.626] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:39.626] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:40.716] INFO: Test took 1090ms.
[12:01:40.717] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[12:01:40.717] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 62, 1 1
[12:01:40.717] INFO: The DUT currently contains the following objects:
[12:01:40.717] INFO: 2 TBM Cores tbm08c (2 ON)
[12:01:40.717] INFO: TBM Core alpha (0): 7 registers set
[12:01:40.717] INFO: TBM Core beta (1): 7 registers set
[12:01:40.717] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:01:40.717] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:40.717] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:40.717] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:40.717] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:40.717] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:40.717] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:40.717] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:40.717] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:40.717] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:40.717] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:40.717] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:40.717] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:40.717] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:40.717] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:40.718] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:40.718] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:41.809] INFO: Test took 1091ms.
[12:01:41.809] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[12:01:41.809] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 6, 2 2
[12:01:41.809] INFO: The DUT currently contains the following objects:
[12:01:41.809] INFO: 2 TBM Cores tbm08c (2 ON)
[12:01:41.809] INFO: TBM Core alpha (0): 7 registers set
[12:01:41.809] INFO: TBM Core beta (1): 7 registers set
[12:01:41.809] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:01:41.809] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:41.809] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:41.809] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:41.809] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:41.809] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:41.809] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:41.809] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:41.809] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:41.809] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:41.810] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:41.810] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:41.810] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:41.810] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:41.810] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:41.810] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:41.810] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:42.900] INFO: Test took 1090ms.
[12:01:42.901] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[12:01:42.901] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 50, 3 3
[12:01:42.901] INFO: The DUT currently contains the following objects:
[12:01:42.901] INFO: 2 TBM Cores tbm08c (2 ON)
[12:01:42.901] INFO: TBM Core alpha (0): 7 registers set
[12:01:42.901] INFO: TBM Core beta (1): 7 registers set
[12:01:42.901] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:01:42.901] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:42.901] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:42.901] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:42.901] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:42.901] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:42.901] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:42.901] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:42.901] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:42.901] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:42.901] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:42.901] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:42.901] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:42.901] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:42.901] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:42.901] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:42.901] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:43.992] INFO: Test took 1091ms.
[12:01:43.992] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[12:01:43.992] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 13, 4 4
[12:01:43.992] INFO: The DUT currently contains the following objects:
[12:01:43.993] INFO: 2 TBM Cores tbm08c (2 ON)
[12:01:43.993] INFO: TBM Core alpha (0): 7 registers set
[12:01:43.993] INFO: TBM Core beta (1): 7 registers set
[12:01:43.993] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:01:43.993] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:43.993] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:43.993] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:43.993] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:43.993] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:43.993] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:43.993] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:43.993] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:43.993] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:43.993] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:43.993] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:43.993] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:43.993] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:43.993] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:43.993] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:43.993] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:45.083] INFO: Test took 1090ms.
[12:01:45.084] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[12:01:45.084] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 7, 12, 5 5
[12:01:45.084] INFO: The DUT currently contains the following objects:
[12:01:45.084] INFO: 2 TBM Cores tbm08c (2 ON)
[12:01:45.084] INFO: TBM Core alpha (0): 7 registers set
[12:01:45.084] INFO: TBM Core beta (1): 7 registers set
[12:01:45.084] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:01:45.084] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:45.084] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:45.084] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:45.084] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:45.084] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:45.084] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:45.084] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:45.084] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:45.084] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:45.084] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:45.084] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:45.084] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:45.084] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:45.084] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:45.084] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:45.084] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:46.175] INFO: Test took 1091ms.
[12:01:46.176] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[12:01:46.176] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 13, 6 6
[12:01:46.176] INFO: The DUT currently contains the following objects:
[12:01:46.176] INFO: 2 TBM Cores tbm08c (2 ON)
[12:01:46.176] INFO: TBM Core alpha (0): 7 registers set
[12:01:46.176] INFO: TBM Core beta (1): 7 registers set
[12:01:46.176] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:01:46.176] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:46.176] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:46.176] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:46.176] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:46.176] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:46.176] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:46.176] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:46.176] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:46.176] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:46.176] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:46.176] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:46.176] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:46.176] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:46.176] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:46.176] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:46.176] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:47.266] INFO: Test took 1090ms.
[12:01:47.267] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[12:01:47.267] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 4, 14, 7 7
[12:01:47.267] INFO: The DUT currently contains the following objects:
[12:01:47.267] INFO: 2 TBM Cores tbm08c (2 ON)
[12:01:47.267] INFO: TBM Core alpha (0): 7 registers set
[12:01:47.267] INFO: TBM Core beta (1): 7 registers set
[12:01:47.267] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:01:47.267] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:47.267] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:47.267] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:47.267] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:47.267] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:47.267] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:47.267] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:47.267] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:47.267] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:47.267] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:47.267] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:47.267] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:47.267] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:47.267] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:47.267] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:47.267] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:48.358] INFO: Test took 1091ms.
[12:01:48.358] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[12:01:48.359] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 12, 66, 8 8
[12:01:48.359] INFO: The DUT currently contains the following objects:
[12:01:48.359] INFO: 2 TBM Cores tbm08c (2 ON)
[12:01:48.359] INFO: TBM Core alpha (0): 7 registers set
[12:01:48.359] INFO: TBM Core beta (1): 7 registers set
[12:01:48.359] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:01:48.359] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:48.359] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:48.359] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:48.359] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:48.359] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:48.359] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:48.359] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:48.359] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:48.359] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:48.359] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:48.359] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:48.359] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:48.359] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:48.359] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:48.359] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:48.359] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:49.450] INFO: Test took 1091ms.
[12:01:49.450] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[12:01:49.450] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 7, 9 9
[12:01:49.450] INFO: The DUT currently contains the following objects:
[12:01:49.450] INFO: 2 TBM Cores tbm08c (2 ON)
[12:01:49.450] INFO: TBM Core alpha (0): 7 registers set
[12:01:49.451] INFO: TBM Core beta (1): 7 registers set
[12:01:49.451] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:01:49.451] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:49.451] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:49.451] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:49.451] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:49.451] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:49.451] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:49.451] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:49.451] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:49.451] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:49.451] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:49.451] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:49.451] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:49.451] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:49.451] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:49.451] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:49.451] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:50.542] INFO: Test took 1091ms.
[12:01:50.542] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[12:01:50.542] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 6, 14, 10 10
[12:01:50.542] INFO: The DUT currently contains the following objects:
[12:01:50.542] INFO: 2 TBM Cores tbm08c (2 ON)
[12:01:50.542] INFO: TBM Core alpha (0): 7 registers set
[12:01:50.542] INFO: TBM Core beta (1): 7 registers set
[12:01:50.542] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:01:50.542] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:50.542] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:50.542] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:50.542] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:50.543] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:50.543] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:50.543] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:50.543] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:50.543] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:50.543] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:50.543] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:50.543] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:50.543] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:50.543] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:50.543] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:50.543] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:51.633] INFO: Test took 1090ms.
[12:01:51.634] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[12:01:51.634] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 14, 42, 11 11
[12:01:51.634] INFO: The DUT currently contains the following objects:
[12:01:51.634] INFO: 2 TBM Cores tbm08c (2 ON)
[12:01:51.634] INFO: TBM Core alpha (0): 7 registers set
[12:01:51.634] INFO: TBM Core beta (1): 7 registers set
[12:01:51.634] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:01:51.634] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:51.634] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:51.634] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:51.634] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:51.634] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:51.634] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:51.634] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:51.634] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:51.634] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:51.634] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:51.634] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:51.634] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:51.634] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:51.634] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:51.634] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:51.634] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:52.725] INFO: Test took 1091ms.
[12:01:52.726] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[12:01:52.726] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 4, 67, 12 12
[12:01:52.726] INFO: The DUT currently contains the following objects:
[12:01:52.726] INFO: 2 TBM Cores tbm08c (2 ON)
[12:01:52.726] INFO: TBM Core alpha (0): 7 registers set
[12:01:52.726] INFO: TBM Core beta (1): 7 registers set
[12:01:52.726] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:01:52.726] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:52.726] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:52.726] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:52.726] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:52.726] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:52.726] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:52.726] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:52.726] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:52.726] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:52.726] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:52.726] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:52.726] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:52.726] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:52.726] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:52.726] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:52.726] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:53.817] INFO: Test took 1091ms.
[12:01:53.817] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[12:01:53.817] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 8, 50, 13 13
[12:01:53.817] INFO: The DUT currently contains the following objects:
[12:01:53.817] INFO: 2 TBM Cores tbm08c (2 ON)
[12:01:53.817] INFO: TBM Core alpha (0): 7 registers set
[12:01:53.817] INFO: TBM Core beta (1): 7 registers set
[12:01:53.818] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:01:53.818] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:53.818] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:53.818] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:53.818] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:53.818] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:53.818] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:53.818] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:53.818] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:53.818] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:53.818] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:53.818] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:53.818] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:53.818] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:53.818] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:53.818] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:53.818] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:54.908] INFO: Test took 1090ms.
[12:01:54.909] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[12:01:54.909] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 6, 66, 14 14
[12:01:54.909] INFO: The DUT currently contains the following objects:
[12:01:54.909] INFO: 2 TBM Cores tbm08c (2 ON)
[12:01:54.909] INFO: TBM Core alpha (0): 7 registers set
[12:01:54.909] INFO: TBM Core beta (1): 7 registers set
[12:01:54.909] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:01:54.909] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:54.909] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:54.909] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:54.909] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:54.909] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:54.909] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:54.909] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:54.909] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:54.909] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:54.909] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:54.909] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:54.909] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:54.909] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:54.909] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:54.909] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:54.909] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:55.000] INFO: Test took 1091ms.
[12:01:55.000] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[12:01:55.001] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 8, 12, 15 15
[12:01:55.001] INFO: The DUT currently contains the following objects:
[12:01:55.001] INFO: 2 TBM Cores tbm08c (2 ON)
[12:01:55.001] INFO: TBM Core alpha (0): 7 registers set
[12:01:55.001] INFO: TBM Core beta (1): 7 registers set
[12:01:55.001] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:01:55.001] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:55.001] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:55.001] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:55.001] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:55.001] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:55.001] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:55.001] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:55.001] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:55.001] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:55.001] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:55.001] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:55.001] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:55.001] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:55.001] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:55.001] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:55.001] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:01:57.091] INFO: Test took 1090ms.
[12:01:57.092] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[12:01:57.092] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 28 on ROC0
[12:01:57.092] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 33 on ROC1
[12:01:57.092] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 31 on ROC2
[12:01:57.092] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 35 on ROC3
[12:01:57.092] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 32 on ROC4
[12:01:57.092] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 30 on ROC5
[12:01:57.092] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 32 on ROC6
[12:01:57.092] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 29 on ROC7
[12:01:57.092] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 33 on ROC8
[12:01:57.092] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 28 on ROC9
[12:01:57.092] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 32 on ROC10
[12:01:57.092] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 31 on ROC11
[12:01:57.092] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 33 on ROC12
[12:01:57.092] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 32 on ROC13
[12:01:57.092] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 31 on ROC14
[12:01:57.092] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 32 on ROC15
[12:01:57.096] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:04:46.952] INFO: Test took 169856ms.
[12:04:48.446] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:07:37.918] INFO: Test took 169472ms.
[12:07:39.523] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[12:07:39.524] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip0
[12:07:39.524] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[12:07:39.524] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip1
[12:07:39.524] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[12:07:39.525] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip2
[12:07:39.525] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[12:07:39.525] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip3
[12:07:39.525] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[12:07:39.525] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip4
[12:07:39.525] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[12:07:39.526] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip5
[12:07:39.526] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[12:07:39.526] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip6
[12:07:39.526] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[12:07:39.526] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip7
[12:07:39.526] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[12:07:39.527] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip8
[12:07:39.527] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[12:07:39.527] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip9
[12:07:39.527] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[12:07:39.527] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip10
[12:07:39.527] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[12:07:39.528] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip11
[12:07:39.528] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[12:07:39.528] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip12
[12:07:39.528] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[12:07:39.528] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip13
[12:07:39.528] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[12:07:39.529] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip14
[12:07:39.529] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[12:07:39.529] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip15
[12:07:39.529] INFO: safety margin for low PH: adding 0, margin is now 20
[12:07:39.535] INFO: safety margin for low PH: adding 0, margin is now 20
[12:07:39.540] INFO: safety margin for low PH: adding 0, margin is now 20
[12:07:39.546] INFO: safety margin for low PH: adding 0, margin is now 20
[12:07:39.551] INFO: safety margin for low PH: adding 0, margin is now 20
[12:07:39.557] INFO: safety margin for low PH: adding 0, margin is now 20
[12:07:39.562] INFO: safety margin for low PH: adding 0, margin is now 20
[12:07:39.568] INFO: safety margin for low PH: adding 0, margin is now 20
[12:07:39.573] INFO: safety margin for low PH: adding 0, margin is now 20
[12:07:39.579] INFO: safety margin for low PH: adding 0, margin is now 20
[12:07:39.584] INFO: safety margin for low PH: adding 0, margin is now 20
[12:07:39.590] INFO: safety margin for low PH: adding 0, margin is now 20
[12:07:39.595] INFO: safety margin for low PH: adding 0, margin is now 20
[12:07:39.601] INFO: safety margin for low PH: adding 0, margin is now 20
[12:07:39.606] INFO: safety margin for low PH: adding 0, margin is now 20
[12:07:39.612] INFO: safety margin for low PH: adding 0, margin is now 20
[12:07:39.617] DEBUG: <PixTestPhOptimization.cc/doTest:L172> optimisation done
[12:07:39.666] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//dacParameters35_C0.dat
[12:07:39.666] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//dacParameters35_C1.dat
[12:07:39.666] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//dacParameters35_C2.dat
[12:07:39.666] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//dacParameters35_C3.dat
[12:07:39.666] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//dacParameters35_C4.dat
[12:07:39.666] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//dacParameters35_C5.dat
[12:07:39.666] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//dacParameters35_C6.dat
[12:07:39.666] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//dacParameters35_C7.dat
[12:07:39.666] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//dacParameters35_C8.dat
[12:07:39.666] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//dacParameters35_C9.dat
[12:07:39.667] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//dacParameters35_C10.dat
[12:07:39.667] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//dacParameters35_C11.dat
[12:07:39.667] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//dacParameters35_C12.dat
[12:07:39.667] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//dacParameters35_C13.dat
[12:07:39.667] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//dacParameters35_C14.dat
[12:07:39.667] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//dacParameters35_C15.dat
[12:07:43.357] INFO: Test took 3686ms.
[12:07:47.292] INFO: Test took 3659ms.
[12:07:51.264] INFO: Test took 3691ms.
[12:07:51.546] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:07:52.447] INFO: Test took 901ms.
[12:07:52.450] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:07:53.540] INFO: Test took 1090ms.
[12:07:53.543] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:07:54.633] INFO: Test took 1090ms.
[12:07:54.636] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:07:55.727] INFO: Test took 1091ms.
[12:07:55.730] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:07:56.820] INFO: Test took 1090ms.
[12:07:56.823] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:07:57.913] INFO: Test took 1090ms.
[12:07:57.916] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:07:58.007] INFO: Test took 1091ms.
[12:07:59.010] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:08:00.100] INFO: Test took 1091ms.
[12:08:00.103] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:08:01.194] INFO: Test took 1091ms.
[12:08:01.197] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:08:02.288] INFO: Test took 1091ms.
[12:08:02.291] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:08:03.381] INFO: Test took 1090ms.
[12:08:03.384] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:08:04.474] INFO: Test took 1090ms.
[12:08:04.478] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:08:05.567] INFO: Test took 1090ms.
[12:08:05.571] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:08:06.661] INFO: Test took 1091ms.
[12:08:06.664] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:08:07.754] INFO: Test took 1090ms.
[12:08:07.757] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:08:08.847] INFO: Test took 1090ms.
[12:08:08.850] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:08:09.940] INFO: Test took 1090ms.
[12:08:09.943] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:08:11.034] INFO: Test took 1091ms.
[12:08:11.037] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:08:12.127] INFO: Test took 1090ms.
[12:08:12.130] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:08:13.220] INFO: Test took 1090ms.
[12:08:13.223] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:08:14.313] INFO: Test took 1090ms.
[12:08:14.316] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:08:15.407] INFO: Test took 1091ms.
[12:08:15.410] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:08:16.500] INFO: Test took 1090ms.
[12:08:16.503] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:08:17.593] INFO: Test took 1090ms.
[12:08:17.596] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:08:18.686] INFO: Test took 1090ms.
[12:08:18.691] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:08:19.780] INFO: Test took 1089ms.
[12:08:19.783] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:08:20.873] INFO: Test took 1090ms.
[12:08:20.876] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:08:21.966] INFO: Test took 1090ms.
[12:08:21.969] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:08:23.059] INFO: Test took 1090ms.
[12:08:23.063] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:08:24.153] INFO: Test took 1091ms.
[12:08:24.156] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:08:25.246] INFO: Test took 1090ms.
[12:08:25.249] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:08:26.339] INFO: Test took 1090ms.
[12:08:26.926] INFO: PixTestPhOptimization::doTest() done, duration: 418 seconds
[12:08:26.926] INFO: PH scale (per ROC): 73 70 73 75 85 78 84 81 76 74 81 87 84 81 76 79
[12:08:26.926] INFO: PH offset (per ROC): 166 161 174 163 169 170 153 160 169 167 161 149 159 164 172 173
[12:08:27.069] INFO: ######################################################################
[12:08:27.069] INFO: PixTestGainPedestal::fullTest() ntrig = 10
[12:08:27.069] INFO: ######################################################################
[12:08:27.069] DEBUG: <PixTestGainPedestal.cc/measure:L188> using FLAGS = 16
[12:08:27.080] INFO: scanning low vcal = 50
[12:08:30.795] INFO: Test took 3715ms.
[12:08:30.852] INFO: scanning low vcal = 100
[12:08:34.597] INFO: Test took 3745ms.
[12:08:34.655] INFO: scanning low vcal = 150
[12:08:38.399] INFO: Test took 3744ms.
[12:08:38.456] INFO: scanning low vcal = 200
[12:08:42.192] INFO: Test took 3736ms.
[12:08:42.250] INFO: scanning low vcal = 250
[12:08:45.984] INFO: Test took 3734ms.
[12:08:46.044] INFO: scanning high vcal = 30 (= 210 in low range)
[12:08:49.784] INFO: Test took 3740ms.
[12:08:49.841] INFO: scanning high vcal = 50 (= 350 in low range)
[12:08:53.581] INFO: Test took 3740ms.
[12:08:53.638] INFO: scanning high vcal = 70 (= 490 in low range)
[12:08:57.373] INFO: Test took 3735ms.
[12:08:57.431] INFO: scanning high vcal = 90 (= 630 in low range)
[12:09:01.167] INFO: Test took 3736ms.
[12:09:01.224] INFO: scanning high vcal = 200 (= 1400 in low range)
[12:09:04.963] INFO: Test took 3739ms.
[12:09:05.281] INFO: PixTestGainPedestal::measure() done
[12:09:05.282] DEBUG: <PixTestGainPedestal.cc/fit:L377> Create hist gainPedestalP1_C0
[12:09:05.282] DEBUG: <PixTestGainPedestal.cc/fit:L377> Create hist gainPedestalP1_C1
[12:09:05.282] DEBUG: <PixTestGainPedestal.cc/fit:L377> Create hist gainPedestalP1_C2
[12:09:05.283] DEBUG: <PixTestGainPedestal.cc/fit:L377> Create hist gainPedestalP1_C3
[12:09:05.283] DEBUG: <PixTestGainPedestal.cc/fit:L377> Create hist gainPedestalP1_C4
[12:09:05.283] DEBUG: <PixTestGainPedestal.cc/fit:L377> Create hist gainPedestalP1_C5
[12:09:05.283] DEBUG: <PixTestGainPedestal.cc/fit:L377> Create hist gainPedestalP1_C6
[12:09:05.283] DEBUG: <PixTestGainPedestal.cc/fit:L377> Create hist gainPedestalP1_C7
[12:09:05.283] DEBUG: <PixTestGainPedestal.cc/fit:L377> Create hist gainPedestalP1_C8
[12:09:05.283] DEBUG: <PixTestGainPedestal.cc/fit:L377> Create hist gainPedestalP1_C9
[12:09:05.284] DEBUG: <PixTestGainPedestal.cc/fit:L377> Create hist gainPedestalP1_C10
[12:09:05.284] DEBUG: <PixTestGainPedestal.cc/fit:L377> Create hist gainPedestalP1_C11
[12:09:05.284] DEBUG: <PixTestGainPedestal.cc/fit:L377> Create hist gainPedestalP1_C12
[12:09:05.284] DEBUG: <PixTestGainPedestal.cc/fit:L377> Create hist gainPedestalP1_C13
[12:09:05.284] DEBUG: <PixTestGainPedestal.cc/fit:L377> Create hist gainPedestalP1_C14
[12:09:05.284] DEBUG: <PixTestGainPedestal.cc/fit:L377> Create hist gainPedestalP1_C15
[12:09:27.121] INFO: PixTestGainPedestal::fit() done
[12:09:27.121] INFO: non-linearity mean: 0.955 0.954 0.962 0.958 0.960 0.960 0.959 0.955 0.951 0.957 0.954 0.957 0.950 0.959 0.955 0.955
[12:09:27.121] INFO: non-linearity RMS: 0.007 0.006 0.006 0.006 0.006 0.006 0.005 0.005 0.006 0.006 0.006 0.005 0.006 0.007 0.006 0.007
[12:09:27.121] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//phCalibrationFitErr35_C0.dat
[12:09:27.137] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//phCalibrationFitErr35_C1.dat
[12:09:27.154] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//phCalibrationFitErr35_C2.dat
[12:09:27.171] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//phCalibrationFitErr35_C3.dat
[12:09:27.187] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//phCalibrationFitErr35_C4.dat
[12:09:27.204] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//phCalibrationFitErr35_C5.dat
[12:09:27.221] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//phCalibrationFitErr35_C6.dat
[12:09:27.238] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//phCalibrationFitErr35_C7.dat
[12:09:27.255] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//phCalibrationFitErr35_C8.dat
[12:09:27.271] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//phCalibrationFitErr35_C9.dat
[12:09:27.288] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//phCalibrationFitErr35_C10.dat
[12:09:27.305] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//phCalibrationFitErr35_C11.dat
[12:09:27.321] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//phCalibrationFitErr35_C12.dat
[12:09:27.338] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//phCalibrationFitErr35_C13.dat
[12:09:27.355] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//phCalibrationFitErr35_C14.dat
[12:09:27.372] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//002_Fulltest_m20//phCalibrationFitErr35_C15.dat
[12:09:27.388] INFO: PixTestGainPedestal::doTest() done, duration: 60 seconds
[12:09:27.388] DEBUG: <PixTestGainPedestal.cc/~PixTestGainPedestal:L121> PixTestGainPedestal dtor
[12:09:27.394] DEBUG: <PixTestFullTest.cc/~PixTestFullTest:L78> PixTestFullTest dtor
[12:09:27.394] INFO: enter test to run
[12:09:27.394] INFO: test: q no parameter change
[12:09:27.394] DEBUG: <PixMonitor.cc/dumpSummaries:L34> PixMonitor::dumpSummaries
[12:09:27.512] QUIET: Connection to board 105 closed.
[12:09:27.513] INFO: pXar: this is the end, my friend
[12:09:27.513] DEBUG: <PixSetup.cc/~PixSetup:L68> PixSetup free fPxarMemory