[10:51:02.417] INFO: *** Welcome to pxar ***
[10:51:02.417] INFO: *** Today: 2015/07/31
[10:51:02.417] INFO: readRocDacs: /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//dacParameters_C0.dat .. /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//dacParameters_C15.dat
[10:51:02.418] INFO: readTbmDacs: /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//tbmParameters_C0a.dat .. /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//tbmParameters_C0b.dat
[10:51:02.418] INFO: readMaskFile: /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//defaultMaskFile.dat
[10:51:02.418] INFO: readTrimFile: /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//trimParameters_C0.dat .. /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//trimParameters_C15.dat
[10:51:02.485] INFO: clk: 4
[10:51:02.485] INFO: ctr: 4
[10:51:02.485] INFO: sda: 19
[10:51:02.485] INFO: tin: 9
[10:51:02.485] INFO: level: 15
[10:51:02.485] INFO: triggerdelay: 0
[10:51:02.485] QUIET: Instanciating API for pxar v2.2.5+67~g3b1c276
[10:51:02.485] INFO: Log level: DEBUG
[10:51:02.493] INFO: Found DTB DTB_WV80Z6
[10:51:02.502] QUIET: Connection to board DTB_WV80Z6 opened.
[10:51:02.505] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 107
HW version: DTB1.2
FW version: 4.2
SW version: 4.2
USB id: DTB_WV80Z6
MAC address: 40D85511806B
Hostname: pixelDTB107
Comment:
------------------------------------------------------
[10:51:02.508] INFO: RPC call hashes of host and DTB match: 447413373
[10:51:04.031] INFO: DUT info:
[10:51:04.031] INFO: The DUT currently contains the following objects:
[10:51:04.031] INFO: 2 TBM Cores tbm08c (2 ON)
[10:51:04.031] INFO: TBM Core alpha (0): 7 registers set
[10:51:04.031] INFO: TBM Core beta (1): 7 registers set
[10:51:04.031] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[10:51:04.031] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[10:51:04.031] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[10:51:04.031] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[10:51:04.031] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[10:51:04.031] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[10:51:04.031] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[10:51:04.031] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[10:51:04.031] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[10:51:04.031] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[10:51:04.031] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[10:51:04.031] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[10:51:04.031] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[10:51:04.031] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[10:51:04.031] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[10:51:04.031] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[10:51:04.031] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->BB<-
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> dumpall: checkbox(0)
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> dumpproblematic: checkbox(0)
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 5
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> vcals: 250
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->BB2<-
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> vcals: 222
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> plwidth: 35
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> pix: 11,20
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> targetia: 24
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->BB3<-
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> dumpall: checkbox(0)
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> dumpproblematic: checkbox(0)
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 5
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> vcals: 250
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Cmd<-
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->DacDacScan<-
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> phmap: checkbox
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> dac1: caldel
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> dac1lo: 0
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> dac1hi: 255
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> dac2: vthrcomp
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> dac2lo: 0
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> dac2hi: 255
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> pix: 11,20
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->DacScan<-
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> phmap: checkbox(1)
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> allpixels: checkbox(0)
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> unmasked: checkbox(0)
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> dac: vcal
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> daclo: 0
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> dachi: 255
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> pix: 11,20
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->GainPedestal<-
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> showfits: checkbox(0)
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> extended: checkbox(0)
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> dumphists: checkbox(0)
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> vcalstep: 10
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> measure: button
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> fit: button
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> save: button
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->HighRate<-
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> pix: 11,20
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> maskhotpixels: button
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> savemaskfile: checkbox(0)
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> maskfilename: default
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> caldelscan: button
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> xpixelalive: button
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 50
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> vcal: 200
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> xnoisemaps: button
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> daclo: 0
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> dachi: 100
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> dacs/step: 20
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> rundaq: button
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> trgfrequency(khz): 20
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> runseconds: 2
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> triggerdelay: 20
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> delaytbm: checkbox
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> filltree: checkbox
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->IV<-
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> port: /dev/FIXME
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> voltagestart: 0
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> voltagestop: 600
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> voltagestep: 5
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> delay: 1
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> compliance(ua): 100
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->PhOptimization<-
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> safetymarginlow: 20
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> saturationvcal: 100
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> quantilesaturation: 0.98
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->PixelAlive<-
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[10:51:04.032] DEBUG: <PixTestParameters.cc/dump:L107> vcal: 200
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> alivetest: button
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> masktest: button
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> addressdecodingtest: button
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Pretest<-
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> programroc: button
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> targetia: 24
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> setvana: button
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> iterations: 100
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> settimings: button
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> findworkingpixel: button
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> setvthrcompcaldel: button
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> pix: 11,20
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> vcal: 250
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> deltavthrcomp: 50
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> fraccaldel: 0.5
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 5
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> savedacs: button
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Readback<-
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> calibratevd: button
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> calibrateva: button
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> calibrateia: button
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> readbackvbg: button
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> getcalibratedvbg: button
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> usecalvd: checkbox(1)
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> usecalva: checkbox(0)
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> setvana: button
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Scurves<-
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> adjustvcal: checkbox(1)
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> dumpall: checkbox(0)
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> dumpproblematic: checkbox(0)
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> dumpoutputfile: checkbox(0)
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 50
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> dac: VthrComp
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> daclo: 0
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> dachi: 200
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> dacs/step: 10
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> scurves: button
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Timing<-
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> fastscan: checkbox(0)
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> targetclk: 4
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> clocksdascan: button
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> phasescan: button
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> levelscan: button
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> tbmphasescan: button
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> rocdelayscan: button
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> timingtest: button
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> saveparameters: button
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Trim<-
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> trim: button
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> vcal: 35
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> trimbits: button
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Xray<-
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> maskhotpixels: button
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> savemaskfile: checkbox(0)
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> maskfilename: default
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> source: Ag
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> phrun: button
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> runseconds: 100
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> trgfrequency(khz): 100
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> ratescan: button
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> vthrcompmin: 10
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> vthrcompmax: 80
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> stepseconds: 5
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> delaytbm: checkbox
[10:51:04.033] DEBUG: <PixTestParameters.cc/dump:L107> filltree: checkbox
[10:51:04.033] DEBUG: <PixSetup.cc/init:L81> PixSetup init start; getCurrentRSS() = 31674368
[10:51:04.033] DEBUG: <PixSetup.cc/init:L87> fPixTestParameters = 0x2653160
[10:51:04.033] DEBUG: <PixSetup.cc/init:L88> fConfigParameters = 0x25b89c0
[10:51:04.033] DEBUG: <PixSetup.cc/init:L89> fPxarMemory = 0x7f8f89d94010
[10:51:04.033] DEBUG: <PixSetup.cc/init:L90> fPxarMemHi = 0x7f8f8ffff510
[10:51:04.033] DEBUG: <PixSetup.cc/init:L106> PixSetup init done; getCurrentRSS() = 31735808 fPxarMemory = 0x7f8f89d94010
[10:51:04.033] DEBUG: <PixTestFactory.cc/PixTestFactory:L52> PixTestFactory::PixTestFactory()
[10:51:04.439] INFO: enter 'restricted' command line mode
[10:51:04.439] INFO: enter test to run
[10:51:04.439] INFO: test: Pretest no parameter change
[10:51:04.439] INFO: running: pretest
[10:51:04.444] INFO: ######################################################################
[10:51:04.444] INFO: PixTestPretest::doTest()
[10:51:04.444] INFO: ######################################################################
[10:51:04.445] INFO: ----------------------------------------------------------------------
[10:51:04.445] INFO: PixTestPretest::programROC()
[10:51:04.445] INFO: ----------------------------------------------------------------------
[10:51:22.466] INFO: PixTestPretest::programROC() done: ROCs are all programmable
[10:51:22.466] INFO: IA differences per ROC: 17.7 16.1 17.7 19.3 20.1 18.5 18.5 19.3 15.3 18.5 17.7 18.5 20.9 18.5 19.3 20.1
[10:51:22.535] INFO: ----------------------------------------------------------------------
[10:51:22.535] INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[10:51:22.535] INFO: ----------------------------------------------------------------------
[10:51:22.642] DEBUG: <PixTestPretest.cc/setVana:L254> offset current from other 15 ROCs is 67.0312 mA
[10:51:22.744] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 0 iter 0 Vana 78 Ia 22.9688 mA
[10:51:22.845] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 1 Vana 84 Ia 24.5687 mA
[10:51:22.946] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 2 Vana 82 Ia 23.7688 mA
[10:51:23.047] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 3 Vana 83 Ia 23.7688 mA
[10:51:23.147] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 4 Vana 84 Ia 24.5687 mA
[10:51:23.248] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 5 Vana 82 Ia 23.7688 mA
[10:51:23.349] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 6 Vana 83 Ia 23.7688 mA
[10:51:23.450] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 7 Vana 84 Ia 24.5687 mA
[10:51:23.550] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 8 Vana 82 Ia 24.5687 mA
[10:51:23.651] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 9 Vana 80 Ia 23.7688 mA
[10:51:23.752] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 10 Vana 81 Ia 23.7688 mA
[10:51:23.853] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 11 Vana 82 Ia 24.5687 mA
[10:51:23.954] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 1 iter 0 Vana 78 Ia 20.5687 mA
[10:51:24.054] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 1 Vana 99 Ia 24.5687 mA
[10:51:24.155] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 2 Vana 97 Ia 24.5687 mA
[10:51:24.255] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 3 Vana 95 Ia 23.7688 mA
[10:51:24.357] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 4 Vana 96 Ia 23.7688 mA
[10:51:24.457] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 5 Vana 97 Ia 24.5687 mA
[10:51:24.559] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 6 Vana 95 Ia 23.7688 mA
[10:51:24.659] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 7 Vana 96 Ia 23.7688 mA
[10:51:24.760] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 8 Vana 97 Ia 24.5687 mA
[10:51:24.861] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 9 Vana 95 Ia 23.7688 mA
[10:51:24.962] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 10 Vana 96 Ia 23.7688 mA
[10:51:25.063] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 11 Vana 97 Ia 23.7688 mA
[10:51:25.164] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 2 iter 0 Vana 78 Ia 22.1688 mA
[10:51:25.265] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 2 iter 1 Vana 89 Ia 24.5687 mA
[10:51:25.366] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 2 iter 2 Vana 87 Ia 24.5687 mA
[10:51:25.466] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 2 iter 3 Vana 85 Ia 24.5687 mA
[10:51:25.567] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 2 iter 4 Vana 83 Ia 23.7688 mA
[10:51:25.668] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 2 iter 5 Vana 84 Ia 23.7688 mA
[10:51:25.768] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 2 iter 6 Vana 85 Ia 23.7688 mA
[10:51:25.869] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 2 iter 7 Vana 86 Ia 24.5687 mA
[10:51:25.969] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 2 iter 8 Vana 84 Ia 23.7688 mA
[10:51:26.070] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 2 iter 9 Vana 85 Ia 23.7688 mA
[10:51:26.171] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 2 iter 10 Vana 86 Ia 24.5687 mA
[10:51:26.272] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 2 iter 11 Vana 84 Ia 23.7688 mA
[10:51:26.373] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 3 iter 0 Vana 78 Ia 23.7688 mA
[10:51:26.474] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 1 Vana 79 Ia 23.7688 mA
[10:51:26.574] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 2 Vana 80 Ia 24.5687 mA
[10:51:26.675] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 3 Vana 78 Ia 23.7688 mA
[10:51:26.775] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 4 Vana 79 Ia 23.7688 mA
[10:51:26.876] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 5 Vana 80 Ia 24.5687 mA
[10:51:26.977] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 6 Vana 78 Ia 23.7688 mA
[10:51:27.078] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 7 Vana 79 Ia 23.7688 mA
[10:51:27.178] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 8 Vana 80 Ia 24.5687 mA
[10:51:27.279] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 9 Vana 78 Ia 23.7688 mA
[10:51:27.380] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 10 Vana 79 Ia 24.5687 mA
[10:51:27.480] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 11 Vana 77 Ia 23.7688 mA
[10:51:27.582] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 4 iter 0 Vana 78 Ia 24.5687 mA
[10:51:27.683] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 4 iter 1 Vana 76 Ia 23.7688 mA
[10:51:27.783] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 4 iter 2 Vana 77 Ia 24.5687 mA
[10:51:27.884] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 4 iter 3 Vana 75 Ia 23.7688 mA
[10:51:27.985] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 4 iter 4 Vana 76 Ia 23.7688 mA
[10:51:28.086] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 4 iter 5 Vana 77 Ia 24.5687 mA
[10:51:28.186] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 4 iter 6 Vana 75 Ia 24.5687 mA
[10:51:28.287] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 4 iter 7 Vana 73 Ia 23.7688 mA
[10:51:28.388] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 4 iter 8 Vana 74 Ia 23.7688 mA
[10:51:28.489] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 4 iter 9 Vana 75 Ia 23.7688 mA
[10:51:28.590] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 4 iter 10 Vana 76 Ia 24.5687 mA
[10:51:28.690] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 4 iter 11 Vana 74 Ia 23.7688 mA
[10:51:28.792] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 5 iter 0 Vana 78 Ia 22.9688 mA
[10:51:28.893] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 1 Vana 84 Ia 25.3687 mA
[10:51:28.993] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 2 Vana 77 Ia 22.9688 mA
[10:51:29.094] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 3 Vana 83 Ia 24.5687 mA
[10:51:29.195] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 4 Vana 81 Ia 24.5687 mA
[10:51:29.296] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 5 Vana 79 Ia 23.7688 mA
[10:51:29.397] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 6 Vana 80 Ia 24.5687 mA
[10:51:29.497] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 7 Vana 78 Ia 22.9688 mA
[10:51:29.598] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 8 Vana 84 Ia 24.5687 mA
[10:51:29.699] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 9 Vana 82 Ia 24.5687 mA
[10:51:29.800] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 10 Vana 80 Ia 24.5687 mA
[10:51:29.900] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 11 Vana 78 Ia 23.7688 mA
[10:51:29.002] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 6 iter 0 Vana 78 Ia 23.7688 mA
[10:51:30.103] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 1 Vana 79 Ia 23.7688 mA
[10:51:30.203] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 2 Vana 80 Ia 24.5687 mA
[10:51:30.304] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 3 Vana 78 Ia 22.9688 mA
[10:51:30.405] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 4 Vana 84 Ia 25.3687 mA
[10:51:30.506] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 5 Vana 77 Ia 22.9688 mA
[10:51:30.606] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 6 Vana 83 Ia 25.3687 mA
[10:51:30.707] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 7 Vana 76 Ia 22.9688 mA
[10:51:30.808] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 8 Vana 82 Ia 24.5687 mA
[10:51:30.909] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 9 Vana 80 Ia 24.5687 mA
[10:51:31.009] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 10 Vana 78 Ia 23.7688 mA
[10:51:31.111] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 11 Vana 79 Ia 23.7688 mA
[10:51:31.212] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 7 iter 0 Vana 78 Ia 23.7688 mA
[10:51:31.312] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 7 iter 1 Vana 79 Ia 23.7688 mA
[10:51:31.413] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 7 iter 2 Vana 80 Ia 24.5687 mA
[10:51:31.514] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 7 iter 3 Vana 78 Ia 23.7688 mA
[10:51:31.615] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 7 iter 4 Vana 79 Ia 22.9688 mA
[10:51:31.716] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 7 iter 5 Vana 85 Ia 25.3687 mA
[10:51:31.817] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 7 iter 6 Vana 78 Ia 22.9688 mA
[10:51:31.918] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 7 iter 7 Vana 84 Ia 25.3687 mA
[10:51:32.018] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 7 iter 8 Vana 77 Ia 22.9688 mA
[10:51:32.119] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 7 iter 9 Vana 83 Ia 24.5687 mA
[10:51:32.220] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 7 iter 10 Vana 81 Ia 24.5687 mA
[10:51:32.321] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 7 iter 11 Vana 79 Ia 22.9688 mA
[10:51:32.422] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 8 iter 0 Vana 78 Ia 19.7687 mA
[10:51:32.523] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 8 iter 1 Vana 103 Ia 24.5687 mA
[10:51:32.624] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 8 iter 2 Vana 101 Ia 24.5687 mA
[10:51:32.725] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 8 iter 3 Vana 99 Ia 23.7688 mA
[10:51:32.826] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 8 iter 4 Vana 100 Ia 24.5687 mA
[10:51:32.927] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 8 iter 5 Vana 98 Ia 23.7688 mA
[10:51:33.027] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 8 iter 6 Vana 99 Ia 24.5687 mA
[10:51:33.128] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 8 iter 7 Vana 97 Ia 23.7688 mA
[10:51:33.229] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 8 iter 8 Vana 98 Ia 23.7688 mA
[10:51:33.329] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 8 iter 9 Vana 99 Ia 23.7688 mA
[10:51:33.430] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 8 iter 10 Vana 100 Ia 24.5687 mA
[10:51:33.531] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 8 iter 11 Vana 98 Ia 23.7688 mA
[10:51:33.632] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 9 iter 0 Vana 78 Ia 22.9688 mA
[10:51:33.733] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 9 iter 1 Vana 84 Ia 24.5687 mA
[10:51:33.834] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 9 iter 2 Vana 82 Ia 24.5687 mA
[10:51:33.935] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 9 iter 3 Vana 80 Ia 23.7688 mA
[10:51:34.035] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 9 iter 4 Vana 81 Ia 23.7688 mA
[10:51:34.136] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 9 iter 5 Vana 82 Ia 24.5687 mA
[10:51:34.237] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 9 iter 6 Vana 80 Ia 23.7688 mA
[10:51:34.338] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 9 iter 7 Vana 81 Ia 24.5687 mA
[10:51:34.439] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 9 iter 8 Vana 79 Ia 22.9688 mA
[10:51:34.540] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 9 iter 9 Vana 85 Ia 24.5687 mA
[10:51:34.640] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 9 iter 10 Vana 83 Ia 24.5687 mA
[10:51:34.741] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 9 iter 11 Vana 81 Ia 23.7688 mA
[10:51:34.843] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 10 iter 0 Vana 78 Ia 22.1688 mA
[10:51:34.944] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 1 Vana 89 Ia 24.5687 mA
[10:51:35.045] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 2 Vana 87 Ia 24.5687 mA
[10:51:35.145] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 3 Vana 85 Ia 24.5687 mA
[10:51:35.246] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 4 Vana 83 Ia 24.5687 mA
[10:51:35.347] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 5 Vana 81 Ia 23.7688 mA
[10:51:35.448] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 6 Vana 82 Ia 23.7688 mA
[10:51:35.549] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 7 Vana 83 Ia 24.5687 mA
[10:51:35.650] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 8 Vana 81 Ia 23.7688 mA
[10:51:35.751] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 9 Vana 82 Ia 23.7688 mA
[10:51:35.852] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 10 Vana 83 Ia 24.5687 mA
[10:51:35.952] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 11 Vana 81 Ia 24.5687 mA
[10:51:36.054] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 11 iter 0 Vana 78 Ia 22.9688 mA
[10:51:36.154] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter 1 Vana 84 Ia 24.5687 mA
[10:51:36.255] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter 2 Vana 82 Ia 24.5687 mA
[10:51:36.356] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter 3 Vana 80 Ia 24.5687 mA
[10:51:36.456] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter 4 Vana 78 Ia 22.9688 mA
[10:51:36.557] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter 5 Vana 84 Ia 24.5687 mA
[10:51:36.658] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter 6 Vana 82 Ia 24.5687 mA
[10:51:36.759] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter 7 Vana 80 Ia 24.5687 mA
[10:51:36.859] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter 8 Vana 78 Ia 22.9688 mA
[10:51:36.960] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter 9 Vana 84 Ia 24.5687 mA
[10:51:37.061] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter 10 Vana 82 Ia 24.5687 mA
[10:51:37.161] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter 11 Vana 80 Ia 24.5687 mA
[10:51:37.262] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 12 iter 0 Vana 78 Ia 25.3687 mA
[10:51:37.363] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter 1 Vana 71 Ia 23.7688 mA
[10:51:37.464] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter 2 Vana 72 Ia 23.7688 mA
[10:51:37.565] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter 3 Vana 73 Ia 23.7688 mA
[10:51:37.666] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter 4 Vana 74 Ia 24.5687 mA
[10:51:37.767] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter 5 Vana 72 Ia 23.7688 mA
[10:51:37.867] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter 6 Vana 73 Ia 24.5687 mA
[10:51:37.968] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter 7 Vana 71 Ia 23.7688 mA
[10:51:38.068] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter 8 Vana 72 Ia 23.7688 mA
[10:51:38.169] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter 9 Vana 73 Ia 24.5687 mA
[10:51:38.269] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter 10 Vana 71 Ia 23.7688 mA
[10:51:38.370] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter 11 Vana 72 Ia 23.7688 mA
[10:51:38.472] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 13 iter 0 Vana 78 Ia 22.9688 mA
[10:51:38.572] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 1 Vana 84 Ia 24.5687 mA
[10:51:38.673] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 2 Vana 82 Ia 24.5687 mA
[10:51:38.774] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 3 Vana 80 Ia 23.7688 mA
[10:51:38.875] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 4 Vana 81 Ia 23.7688 mA
[10:51:38.976] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 5 Vana 82 Ia 24.5687 mA
[10:51:39.076] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 6 Vana 80 Ia 23.7688 mA
[10:51:39.177] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 7 Vana 81 Ia 24.5687 mA
[10:51:39.278] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 8 Vana 79 Ia 22.9688 mA
[10:51:39.379] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 9 Vana 85 Ia 24.5687 mA
[10:51:39.479] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 10 Vana 83 Ia 24.5687 mA
[10:51:39.580] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 11 Vana 81 Ia 23.7688 mA
[10:51:39.682] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 14 iter 0 Vana 78 Ia 23.7688 mA
[10:51:39.783] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 1 Vana 79 Ia 23.7688 mA
[10:51:39.883] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 2 Vana 80 Ia 24.5687 mA
[10:51:39.984] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 3 Vana 78 Ia 23.7688 mA
[10:51:40.085] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 4 Vana 79 Ia 24.5687 mA
[10:51:40.186] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 5 Vana 77 Ia 22.9688 mA
[10:51:40.287] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 6 Vana 83 Ia 25.3687 mA
[10:51:40.388] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 7 Vana 76 Ia 22.9688 mA
[10:51:40.489] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 8 Vana 82 Ia 24.5687 mA
[10:51:40.589] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 9 Vana 80 Ia 24.5687 mA
[10:51:40.691] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 10 Vana 78 Ia 23.7688 mA
[10:51:40.792] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 11 Vana 79 Ia 23.7688 mA
[10:51:40.894] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 15 iter 0 Vana 78 Ia 24.5687 mA
[10:51:40.995] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 1 Vana 76 Ia 23.7688 mA
[10:51:41.096] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 2 Vana 77 Ia 24.5687 mA
[10:51:41.196] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 3 Vana 75 Ia 23.7688 mA
[10:51:41.297] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 4 Vana 76 Ia 23.7688 mA
[10:51:41.398] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 5 Vana 77 Ia 24.5687 mA
[10:51:41.499] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 6 Vana 75 Ia 23.7688 mA
[10:51:41.599] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 7 Vana 76 Ia 23.7688 mA
[10:51:41.700] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 8 Vana 77 Ia 23.7688 mA
[10:51:41.801] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 9 Vana 78 Ia 24.5687 mA
[10:51:41.902] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 10 Vana 76 Ia 23.7688 mA
[10:51:42.003] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 11 Vana 77 Ia 24.5687 mA
[10:51:42.058] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 0 Vana 82
[10:51:42.058] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 1 Vana 97
[10:51:42.059] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 2 Vana 84
[10:51:42.059] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 3 Vana 77
[10:51:42.059] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 4 Vana 74
[10:51:42.059] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 5 Vana 78
[10:51:42.059] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 6 Vana 79
[10:51:42.059] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 7 Vana 79
[10:51:42.059] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 8 Vana 98
[10:51:42.059] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 9 Vana 81
[10:51:42.060] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 10 Vana 81
[10:51:42.060] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 11 Vana 80
[10:51:42.060] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 12 Vana 72
[10:51:42.060] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 13 Vana 81
[10:51:42.061] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 14 Vana 79
[10:51:42.061] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 15 Vana 77
[10:51:42.164] INFO: PixTestPretest::setVana() done, Module Ia 381 mA = 23.8125 mA/ROC
[10:51:42.166] INFO: ----------------------------------------------------------------------
[10:51:42.166] INFO: PixTestPreTest::setTimings()
[10:51:42.166] INFO: ----------------------------------------------------------------------
[10:51:42.166] DEBUG: <PixTestPretest.cc/setTimings:L392> Testing Timing: Attempt #1
[10:51:43.130] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:43.131] INFO: Decoding statistics:
[10:51:43.131] INFO: General information:
[10:51:43.131] INFO: 16bit words read: 120
[10:51:43.131] INFO: valid events total: 10
[10:51:43.131] INFO: empty events: 10
[10:51:43.131] INFO: valid events with pixels: 0
[10:51:43.131] INFO: valid pixel hits: 0
[10:51:43.131] INFO: Event errors: 0
[10:51:43.131] INFO: start marker: 0
[10:51:43.131] INFO: stop marker: 0
[10:51:43.131] INFO: overflow: 0
[10:51:43.131] INFO: invalid 5bit words: 0
[10:51:43.131] INFO: invalid XOR eye diagram: 0
[10:51:43.131] INFO: TBM errors: 0
[10:51:43.131] INFO: flawed TBM headers: 0
[10:51:43.131] INFO: flawed TBM trailers: 0
[10:51:43.131] INFO: event ID mismatches: 0
[10:51:43.131] INFO: ROC errors: 0
[10:51:43.131] INFO: missing ROC header(s): 0
[10:51:43.131] INFO: misplaced readback start: 0
[10:51:43.131] INFO: Pixel decoding errors: 0
[10:51:43.131] INFO: pixel data incomplete: 0
[10:51:43.131] INFO: pixel address: 0
[10:51:43.131] INFO: pulse height fill bit: 0
[10:51:43.131] INFO: buffer corruption: 0
[10:51:43.131] INFO: ----------------------------------------------------------------------
[10:51:43.131] INFO: Default timings are good. No timing scan needed.
[10:51:43.131] INFO: ----------------------------------------------------------------------
[10:51:43.131] INFO: Test took 965 ms.
[10:51:43.131] INFO: PixTestPretest::setTimings() done.
[10:51:43.323] INFO: ----------------------------------------------------------------------
[10:51:43.323] INFO: PixTestPretest::findWorkingPixel()
[10:51:43.323] INFO: ----------------------------------------------------------------------
[10:51:50.579] INFO: Test took 7252ms.
[10:51:50.808] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C0 OK, with vthrComp = 105 and Delta(CalDel) = 56
[10:51:50.810] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C1 OK, with vthrComp = 75 and Delta(CalDel) = 55
[10:51:50.813] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C2 OK, with vthrComp = 76 and Delta(CalDel) = 56
[10:51:50.815] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C3 OK, with vthrComp = 75 and Delta(CalDel) = 57
[10:51:50.817] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C4 OK, with vthrComp = 72 and Delta(CalDel) = 57
[10:51:50.819] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C5 OK, with vthrComp = 109 and Delta(CalDel) = 59
[10:51:50.821] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C6 OK, with vthrComp = 74 and Delta(CalDel) = 57
[10:51:50.824] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C7 OK, with vthrComp = 105 and Delta(CalDel) = 58
[10:51:50.826] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C8 OK, with vthrComp = 87 and Delta(CalDel) = 59
[10:51:50.828] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C9 OK, with vthrComp = 83 and Delta(CalDel) = 59
[10:51:50.830] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C10 OK, with vthrComp = 88 and Delta(CalDel) = 58
[10:51:50.833] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C11 OK, with vthrComp = 110 and Delta(CalDel) = 57
[10:51:50.835] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C12 OK, with vthrComp = 101 and Delta(CalDel) = 56
[10:51:50.837] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C13 OK, with vthrComp = 74 and Delta(CalDel) = 56
[10:51:50.839] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C14 OK, with vthrComp = 93 and Delta(CalDel) = 56
[10:51:50.842] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C15 OK, with vthrComp = 95 and Delta(CalDel) = 60
[10:51:50.865] INFO: Found working pixel in all ROCs: col/row = 12/22
[10:51:50.914] INFO: ----------------------------------------------------------------------
[10:51:50.914] INFO: PixTestPretest::setVthrCompCalDel()
[10:51:50.914] INFO: ----------------------------------------------------------------------
[10:51:58.215] INFO: Test took 7296ms.
[10:51:58.265] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 114 +/- 28.5
[10:51:58.441] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 114 +/- 28.5
[10:51:58.444] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 108 +/- 28
[10:51:58.446] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 113 +/- 29.5
[10:51:58.448] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 129 +/- 29.5
[10:51:58.451] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 113 +/- 29.5
[10:51:58.453] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 123 +/- 28.5
[10:51:58.455] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 118 +/- 28.5
[10:51:58.457] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 116 +/- 29.5
[10:51:58.460] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 121 +/- 29
[10:51:58.462] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 109 +/- 29
[10:51:58.464] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 120 +/- 28
[10:51:58.466] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 126 +/- 29
[10:51:58.469] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 116 +/- 27.5
[10:51:58.471] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 113 +/- 29.5
[10:51:58.473] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 123 +/- 30.5
[10:51:58.524] INFO: PixTestPretest::setVthrCompCalDel() done
[10:51:58.524] INFO: CalDel: 114 114 108 113 129 113 123 118 116 121 109 120 126 116 113 123
[10:51:58.524] INFO: VthrComp: 51 51 51 51 51 53 51 51 51 51 51 51 51 51 51 51
[10:51:58.527] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//dacParameters_C0.dat
[10:51:58.527] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//dacParameters_C1.dat
[10:51:58.527] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//dacParameters_C2.dat
[10:51:58.528] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//dacParameters_C3.dat
[10:51:58.528] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//dacParameters_C4.dat
[10:51:58.528] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//dacParameters_C5.dat
[10:51:58.528] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//dacParameters_C6.dat
[10:51:58.528] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//dacParameters_C7.dat
[10:51:58.528] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//dacParameters_C8.dat
[10:51:58.528] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//dacParameters_C9.dat
[10:51:58.528] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//dacParameters_C10.dat
[10:51:58.528] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//dacParameters_C11.dat
[10:51:58.529] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//dacParameters_C12.dat
[10:51:58.529] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//dacParameters_C13.dat
[10:51:58.529] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//dacParameters_C14.dat
[10:51:58.529] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//dacParameters_C15.dat
[10:51:58.529] INFO: PixTestPretest::doTest() done, duration: 54 seconds
[10:51:58.529] DEBUG: <PixTestPretest.cc/~PixTestPretest:L134> PixTestPretest dtor
[10:51:58.604] INFO: enter test to run
[10:51:58.604] INFO: test: Fulltest no parameter change
[10:51:58.604] INFO: running: fulltest
[10:51:58.604] DEBUG: <PixTestFullTest.cc/init:L49> PixTestFullTest::init()
[10:51:58.604] DEBUG: <PixTestFullTest.cc/PixTestFullTest:L20> PixTestFullTest ctor(PixSetup &a, string, TGTab *)
[10:51:58.604] INFO: ######################################################################
[10:51:58.604] INFO: PixTestFullTest::doTest()
[10:51:58.604] INFO: ######################################################################
[10:51:58.604] DEBUG: <PixTestAlive.cc/init:L77> PixTestAlive::init()
[10:51:58.604] DEBUG: <PixTestAlive.cc/PixTestAlive:L21> PixTestAlive ctor(PixSetup &a, string, TGTab *)
[10:51:58.606] INFO: ######################################################################
[10:51:58.606] INFO: PixTestAlive::doTest()
[10:51:58.606] INFO: ######################################################################
[10:51:58.608] INFO: ----------------------------------------------------------------------
[10:51:58.608] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[10:51:58.608] INFO: ----------------------------------------------------------------------
[10:51:58.610] DEBUG: <PixTest.cc/efficiencyMaps:L328> attempt #0
[10:52:02.324] INFO: Test took 3714ms.
[10:52:02.345] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:52:02.345] DEBUG: <PixTest.cc/efficiencyMaps:L339> eff result size = 66533
[10:52:02.345] DEBUG: <PixTest.cc/efficiencyMaps:L344> Create hists PixelAlive_C0 .. PixelAlive_C15
[10:52:02.584] INFO: PixTestAlive::aliveTest() done
[10:52:02.585] INFO: number of dead pixels (per ROC): 2 0 0 0 0 0 1 4 6 2 0 0 0 4 0 8
[10:52:02.585] DEBUG: <PixTestAlive.cc/aliveTest:L188> number of red-efficiency pixels: 2 0 0 0 0 0 1 4 6 2 1 0 0 4 0 8
[10:52:02.586] INFO: ----------------------------------------------------------------------
[10:52:02.586] INFO: PixTestAlive::maskTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[10:52:02.586] INFO: ----------------------------------------------------------------------
[10:52:02.589] DEBUG: <PixTest.cc/efficiencyMaps:L328> attempt #0
[10:52:05.266] INFO: Test took 2677ms.
[10:52:05.269] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:52:05.269] DEBUG: <PixTest.cc/efficiencyMaps:L339> eff result size = 0
[10:52:05.269] DEBUG: <PixTest.cc/efficiencyMaps:L344> Create hists MaskTest_C0 .. MaskTest_C15
[10:52:05.269] INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[10:52:05.509] INFO: PixTestAlive::maskTest() done
[10:52:05.509] INFO: number of mask-defect pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[10:52:05.510] INFO: ----------------------------------------------------------------------
[10:52:05.510] INFO: PixTestAlive::addressDecodingTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[10:52:05.510] INFO: ----------------------------------------------------------------------
[10:52:05.512] DEBUG: <PixTest.cc/efficiencyMaps:L328> attempt #0
[10:52:09.221] INFO: Test took 3709ms.
[10:52:09.238] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:52:09.238] DEBUG: <PixTest.cc/efficiencyMaps:L339> eff result size = 66533
[10:52:09.239] DEBUG: <PixTest.cc/efficiencyMaps:L344> Create hists AddressDecodingTest_C0 .. AddressDecodingTest_C15
[10:52:09.482] INFO: PixTestAlive::addressDecodingTest() done
[10:52:09.482] INFO: number of address-decoding pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[10:52:09.482] INFO: PixTestAlive::doTest() done, duration: 10 seconds
[10:52:09.482] DEBUG: <PixTestAlive.cc/~PixTestAlive:L109> PixTestAlive dtor
[10:52:09.486] DEBUG: <PixTestBBMap.cc/init:L79> PixTestBBMap::init()
[10:52:09.487] DEBUG: <PixTestBBMap.cc/PixTestBBMap:L27> PixTestBBMap ctor(PixSetup &a, string, TGTab *)
[10:52:09.488] INFO: ######################################################################
[10:52:09.488] INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[10:52:09.488] INFO: ######################################################################
[10:52:09.493] INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (30) hits flags = 2 (plus default)
[10:52:09.505] INFO: dacScan step from 0 .. 29
[10:52:09.505] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:52:27.393] INFO: Test took 17888ms.
[10:52:27.433] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:52:27.433] INFO: dacScan step from 30 .. 59
[10:52:27.433] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:52:48.686] INFO: Test took 21253ms.
[10:52:48.885] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:52:48.928] INFO: dacScan step from 60 .. 89
[10:52:48.929] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:53:13.363] INFO: Test took 24434ms.
[10:53:13.620] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:53:13.706] INFO: dacScan step from 90 .. 119
[10:53:13.706] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:53:37.999] INFO: Test took 24293ms.
[10:53:38.257] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:53:38.337] INFO: dacScan step from 120 .. 149
[10:53:38.337] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:54:00.220] INFO: Test took 21883ms.
[10:54:00.399] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:54:00.464] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[10:54:01.872] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[10:54:03.272] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[10:54:04.618] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[10:54:05.949] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[10:54:07.128] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[10:54:08.373] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[10:54:09.518] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[10:54:10.733] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[10:54:11.907] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[10:54:13.127] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[10:54:14.340] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[10:54:15.546] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[10:54:16.734] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[10:54:17.909] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[10:54:19.087] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[10:54:20.312] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 266817536
[10:54:20.359] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C0_V0
[10:54:20.360] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 83 (obtained for minval = 0) start: 82 .. 102 last peak: 45.626 last sigma: 5.65959 lcuts[0] = 62.6048 lcuts[1] = 102.222
[10:54:20.361] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C1_V0
[10:54:20.361] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 76 (obtained for minval = 0) start: 76 .. 97 last peak: 37.941 last sigma: 5.9521 lcuts[0] = 55.7973 lcuts[1] = 97.462
[10:54:20.362] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C2_V0
[10:54:20.362] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 79 (obtained for minval = 0) start: 79 .. 98 last peak: 43.4752 last sigma: 5.52715 lcuts[0] = 60.0567 lcuts[1] = 98.7468
[10:54:20.362] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C3_V0
[10:54:20.363] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 83 (obtained for minval = 0) start: 83 .. 106 last peak: 42.9298 last sigma: 6.30943 lcuts[0] = 61.8581 lcuts[1] = 106.024
[10:54:20.363] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C4_V0
[10:54:20.363] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 83 (obtained for minval = 0) start: 83 .. 106 last peak: 40.4513 last sigma: 6.62315 lcuts[0] = 60.3207 lcuts[1] = 106.683
[10:54:20.364] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C5_V0
[10:54:20.364] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 89 (obtained for minval = 0) start: 89 .. 110 last peak: 51.5203 last sigma: 5.86438 lcuts[0] = 69.1135 lcuts[1] = 110.164
[10:54:20.365] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C6_V0
[10:54:20.365] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 74 (obtained for minval = 0) start: 73 .. 92 last peak: 39.122 last sigma: 5.3511 lcuts[0] = 55.1753 lcuts[1] = 92.633
[10:54:20.365] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C7_V0
[10:54:20.366] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 81 (obtained for minval = 0) start: 80 .. 98 last peak: 47.6979 last sigma: 5.06301 lcuts[0] = 62.8869 lcuts[1] = 98.328
[10:54:20.366] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C8_V0
[10:54:20.366] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 78 (obtained for minval = 0) start: 78 .. 97 last peak: 42.4472 last sigma: 5.47172 lcuts[0] = 58.8624 lcuts[1] = 97.1645
[10:54:20.367] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C9_V0
[10:54:20.367] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 83 (obtained for minval = 0) start: 83 .. 103 last peak: 47.938 last sigma: 5.51928 lcuts[0] = 64.4959 lcuts[1] = 103.131
[10:54:20.367] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C10_V0
[10:54:20.368] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 79 (obtained for minval = 0) start: 79 .. 97 last peak: 48.1537 last sigma: 4.88754 lcuts[0] = 62.8164 lcuts[1] = 97.0291
[10:54:20.368] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C11_V0
[10:54:20.368] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 78 (obtained for minval = 0) start: 78 .. 96 last peak: 44.1475 last sigma: 5.23724 lcuts[0] = 59.8592 lcuts[1] = 96.5199
[10:54:20.369] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C12_V0
[10:54:20.369] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 82 (obtained for minval = 0) start: 82 .. 104 last peak: 41.3859 last sigma: 6.28205 lcuts[0] = 60.2321 lcuts[1] = 104.206
[10:54:20.370] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C13_V0
[10:54:20.370] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 79 (obtained for minval = 0) start: 76 .. 94 last peak: 41.1875 last sigma: 5.37803 lcuts[0] = 57.3216 lcuts[1] = 94.9678
[10:54:20.370] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C14_V0
[10:54:20.371] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 79 (obtained for minval = 0) start: 79 .. 100 last peak: 40.8871 last sigma: 5.91251 lcuts[0] = 58.6246 lcuts[1] = 100.012
[10:54:20.371] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C15_V0
[10:54:20.371] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 85 (obtained for minval = 0) start: 85 .. 107 last peak: 44.5783 last sigma: 6.282 lcuts[0] = 63.4242 lcuts[1] = 107.398
[10:54:20.373] INFO: PixTestBBMap::doTest() done, duration: 130 seconds
[10:54:20.373] INFO: number of dead bumps (per ROC): 1 1 1 0 0 1 1 2 0 0 0 0 0 1 0 3
[10:54:20.373] INFO: separation cut (per ROC): 84 77 80 84 84 90 75 82 79 84 80 79 83 80 80 86
[10:54:20.373] DEBUG: <PixTestBBMap.cc/~PixTestBBMap:L97> PixTestBBMap dtor
[10:54:20.446] DEBUG: <PixTestScurves.cc/setParameter:L92> set fOutputFilename =
[10:54:20.447] INFO: ######################################################################
[10:54:20.447] INFO: PixTestScurves::fullTest() ntrig = 50
[10:54:20.447] INFO: ######################################################################
[10:54:20.447] INFO: ----------------------------------------------------------------------
[10:54:20.447] INFO: PixTestScurves::scurves(Vcal), ntrig = 50
[10:54:20.447] INFO: ----------------------------------------------------------------------
[10:54:20.447] INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 0 .. 149 (10) hits flags = 16 (plus default)
[10:54:20.457] INFO: dacScan step from 0 .. 9
[10:54:20.457] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:54:54.513] INFO: Test took 34056ms.
[10:54:54.581] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:54:54.582] INFO: dacScan step from 10 .. 19
[10:54:54.582] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:55:28.852] INFO: Test took 34270ms.
[10:55:28.917] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:55:28.917] INFO: dacScan step from 20 .. 29
[10:55:28.917] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:56:03.070] INFO: Test took 34153ms.
[10:56:03.136] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:56:03.136] INFO: dacScan step from 30 .. 39
[10:56:03.137] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:56:37.365] INFO: Test took 34228ms.
[10:56:37.432] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:56:37.432] INFO: dacScan step from 40 .. 49
[10:56:37.433] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:57:11.738] INFO: Test took 34305ms.
[10:57:11.806] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:57:11.806] INFO: dacScan step from 50 .. 59
[10:57:11.806] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:57:46.042] INFO: Test took 34236ms.
[10:57:46.113] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:57:46.113] INFO: dacScan step from 60 .. 69
[10:57:46.113] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:58:20.326] INFO: Test took 34213ms.
[10:58:20.398] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:58:20.398] INFO: dacScan step from 70 .. 79
[10:58:20.398] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:58:55.039] ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 1 Number of ROCs (6) != Token Chain Length (8)
[10:58:55.039] WARNING: Channel 1 ROC 7: Readback start marker after 15 readouts!
[10:58:55.624] INFO: Test took 35226ms.
[10:58:55.762] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:58:55.766] INFO: dacScan step from 80 .. 89
[10:58:55.767] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:59:30.924] ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 1 Number of ROCs (16) != Token Chain Length (8)
[10:59:30.924] ERROR: <datapipe.cc/CheckEventID:L420> Channel 1 Event ID mismatch: local ID (81) != TBM ID (82)
[10:59:30.924] WARNING: Channel 1 ROC 1: Readback start marker after 15 readouts!
[10:59:30.924] WARNING: Channel 1 ROC 2: Readback start marker after 15 readouts!
[10:59:30.924] WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[10:59:30.924] WARNING: Channel 1 ROC 4: Readback start marker after 15 readouts!
[10:59:30.924] WARNING: Channel 1 ROC 5: Readback start marker after 15 readouts!
[10:59:30.924] WARNING: Channel 1 ROC 6: Readback start marker after 15 readouts!
[10:59:30.924] WARNING: Channel 1 ROC 7: Readback start marker after 15 readouts!
[10:59:37.168] INFO: Test took 41401ms.
[10:59:37.493] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:59:37.508] INFO: dacScan step from 90 .. 99
[10:59:37.508] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:00:10.556] ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 1 Number of ROCs (6) != Token Chain Length (8)
[11:00:10.556] WARNING: Channel 1 ROC 7: Readback start marker after 15 readouts!
[11:00:26.373] INFO: Test took 48865ms.
[11:00:26.866] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:00:26.890] INFO: dacScan step from 100 .. 109
[11:00:26.890] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:00:57.809] ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 1 Number of ROCs (16) != Token Chain Length (8)
[11:00:57.809] ERROR: <datapipe.cc/CheckEventID:L420> Channel 1 Event ID mismatch: local ID (86) != TBM ID (87)
[11:00:57.809] WARNING: Channel 1 ROC 1: Readback start marker after 15 readouts!
[11:00:57.809] WARNING: Channel 1 ROC 2: Readback start marker after 15 readouts!
[11:00:57.809] WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[11:00:57.809] WARNING: Channel 1 ROC 4: Readback start marker after 15 readouts!
[11:00:57.809] WARNING: Channel 1 ROC 5: Readback start marker after 15 readouts!
[11:00:57.809] WARNING: Channel 1 ROC 6: Readback start marker after 15 readouts!
[11:00:57.809] WARNING: Channel 1 ROC 7: Readback start marker after 15 readouts!
[11:01:18.738] ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 1 Number of ROCs (6) != Token Chain Length (8)
[11:01:18.738] WARNING: Channel 1 ROC 7: Readback start marker after 15 readouts!
[11:01:21.596] INFO: Test took 54706ms.
[11:01:22.162] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:01:22.192] INFO: dacScan step from 110 .. 119
[11:01:22.192] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:01:52.266] ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 1 Number of ROCs (6) != Token Chain Length (8)
[11:01:52.266] WARNING: Channel 1 ROC 7: Readback start marker after 15 readouts!
[11:02:13.979] ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 1 Number of ROCs (6) != Token Chain Length (8)
[11:02:13.979] WARNING: Channel 1 ROC 7: Readback start marker after 15 readouts!
[11:02:19.168] INFO: Test took 56976ms.
[11:02:19.733] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:02:19.764] INFO: dacScan step from 120 .. 129
[11:02:19.764] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:02:49.933] ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 1 Number of ROCs (6) != Token Chain Length (8)
[11:02:49.933] WARNING: Channel 1 ROC 7: Readback start marker after 15 readouts!
[11:03:11.935] ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 1 Number of ROCs (6) != Token Chain Length (8)
[11:03:11.935] WARNING: Channel 1 ROC 7: Readback start marker after 15 readouts!
[11:03:17.460] INFO: Test took 57696ms.
[11:03:18.024] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:03:18.055] INFO: dacScan step from 130 .. 139
[11:03:18.055] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:04:10.323] ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 1 Number of ROCs (6) != Token Chain Length (8)
[11:04:10.323] WARNING: Channel 1 ROC 7: Readback start marker after 15 readouts!
[11:04:16.106] INFO: Test took 58051ms.
[11:04:16.669] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:04:16.699] INFO: dacScan step from 140 .. 149
[11:04:16.699] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:04:46.733] ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 1 Number of ROCs (6) != Token Chain Length (8)
[11:04:46.733] WARNING: Channel 1 ROC 7: Readback start marker after 15 readouts!
[11:05:08.352] ERROR: <datapipe.cc/CheckEventID:L420> Channel 1 Event ID mismatch: local ID (8) != TBM ID (16)
[11:05:08.352] ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 1 Number of ROCs (7) != Token Chain Length (8)
[11:05:08.352] ERROR: <datapipe.cc/CheckEventID:L420> Channel 1 Event ID mismatch: local ID (17) != TBM ID (9)
[11:05:13.602] INFO: Test took 56903ms.
[11:05:14.166] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:05:14.197] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[11:05:14.197] INFO: dumping ASCII scurve output file: SCurveData
[11:05:15.442] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[11:05:15.442] INFO: dumping ASCII scurve output file: SCurveData
[11:05:16.720] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[11:05:16.720] INFO: dumping ASCII scurve output file: SCurveData
[11:05:17.986] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[11:05:17.986] INFO: dumping ASCII scurve output file: SCurveData
[11:05:19.234] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[11:05:19.234] INFO: dumping ASCII scurve output file: SCurveData
[11:05:20.473] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[11:05:20.473] INFO: dumping ASCII scurve output file: SCurveData
[11:05:21.707] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[11:05:21.707] INFO: dumping ASCII scurve output file: SCurveData
[11:05:22.994] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[11:05:22.994] INFO: dumping ASCII scurve output file: SCurveData
[11:05:24.242] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[11:05:24.242] INFO: dumping ASCII scurve output file: SCurveData
[11:05:25.492] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[11:05:25.492] INFO: dumping ASCII scurve output file: SCurveData
[11:05:26.731] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[11:05:26.731] INFO: dumping ASCII scurve output file: SCurveData
[11:05:27.974] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[11:05:27.974] INFO: dumping ASCII scurve output file: SCurveData
[11:05:29.208] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[11:05:29.208] INFO: dumping ASCII scurve output file: SCurveData
[11:05:30.451] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[11:05:30.451] INFO: dumping ASCII scurve output file: SCurveData
[11:05:31.715] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[11:05:31.715] INFO: dumping ASCII scurve output file: SCurveData
[11:05:32.957] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[11:05:32.957] INFO: dumping ASCII scurve output file: SCurveData
[11:05:34.181] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 626081792
[11:05:34.227] INFO: PixTestScurves::scurves() done
[11:05:34.227] INFO: Vcal mean: 91.81 80.64 81.41 91.80 99.41 102.37 78.25 89.21 87.09 94.92 96.83 96.12 84.05 79.49 87.97 103.68
[11:05:34.227] INFO: Vcal RMS: 6.33 4.26 4.15 5.74 9.08 6.03 4.26 6.59 6.60 5.79 6.34 5.97 4.86 5.26 5.57 8.42
[11:05:34.227] INFO: PixTestScurves::fullTest() done, duration: 673 seconds
[11:05:34.227] DEBUG: <PixTestScurves.cc/~PixTestScurves:L141> PixTestScurves dtor
[11:05:34.289] INFO: ######################################################################
[11:05:34.289] INFO: PixTestTrim::doTest()
[11:05:34.289] INFO: ######################################################################
[11:05:34.291] INFO: ----------------------------------------------------------------------
[11:05:34.291] INFO: PixTestTrim::trimTest() ntrig = 10, vcal = 35
[11:05:34.291] INFO: ----------------------------------------------------------------------
[11:05:34.358] INFO: ---> VthrComp thr map (minimal VthrComp)
[11:05:34.358] INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 5 dacrange: 0 .. 159 (20) hits flags = 16 (plus default)
[11:05:34.367] INFO: dacScan step from 0 .. 19
[11:05:34.367] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:05:46.956] INFO: Test took 12589ms.
[11:05:46.979] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:05:46.979] INFO: dacScan step from 20 .. 39
[11:05:46.979] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:05:59.583] INFO: Test took 12604ms.
[11:05:59.609] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:05:59.609] INFO: dacScan step from 40 .. 59
[11:05:59.610] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:06:12.178] INFO: Test took 12568ms.
[11:06:12.204] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:06:12.204] INFO: dacScan step from 60 .. 79
[11:06:12.204] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:06:24.741] INFO: Test took 12537ms.
[11:06:24.767] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:06:24.767] INFO: dacScan step from 80 .. 99
[11:06:24.767] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:06:37.787] INFO: Test took 13020ms.
[11:06:37.850] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:06:37.858] INFO: dacScan step from 100 .. 119
[11:06:37.858] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:06:53.381] INFO: Test took 15522ms.
[11:06:53.541] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:06:53.577] INFO: dacScan step from 120 .. 139
[11:06:53.577] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:07:09.852] INFO: Test took 16275ms.
[11:07:09.986] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:07:10.014] INFO: dacScan step from 140 .. 159
[11:07:10.014] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:07:22.944] INFO: Test took 12930ms.
[11:07:22.994] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:07:22.001] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[11:07:24.208] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[11:07:25.339] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[11:07:26.477] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[11:07:27.636] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[11:07:28.750] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[11:07:29.943] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[11:07:31.042] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[11:07:32.210] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[11:07:33.341] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[11:07:34.532] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[11:07:35.711] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[11:07:36.892] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[11:07:38.068] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[11:07:39.224] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[11:07:40.365] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[11:07:41.568] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 626331648
[11:07:41.569] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 93.1868 minThrLimit = 93.1192 minThrNLimit = 113.694 -> result = 93.1868 -> 93
[11:07:41.570] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 82.6612 minThrLimit = 82.6578 minThrNLimit = 102.107 -> result = 82.6612 -> 82
[11:07:41.570] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 84.69 minThrLimit = 84.6846 minThrNLimit = 106.531 -> result = 84.69 -> 84
[11:07:41.570] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 93.6035 minThrLimit = 93.5991 minThrNLimit = 114.045 -> result = 93.6035 -> 93
[11:07:41.571] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 91.2914 minThrLimit = 91.1769 minThrNLimit = 105.882 -> result = 91.2914 -> 91
[11:07:41.571] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 101.214 minThrLimit = 101.207 minThrNLimit = 121.885 -> result = 101.214 -> 101
[11:07:41.571] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 80.797 minThrLimit = 80.7753 minThrNLimit = 100.536 -> result = 80.797 -> 80
[11:07:41.572] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 91.0448 minThrLimit = 91.0105 minThrNLimit = 112.505 -> result = 91.0448 -> 91
[11:07:41.572] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 86.9732 minThrLimit = 86.8668 minThrNLimit = 106.075 -> result = 86.9732 -> 86
[11:07:41.572] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 97.04 minThrLimit = 97.0384 minThrNLimit = 118.153 -> result = 97.04 -> 97
[11:07:41.573] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 95.7258 minThrLimit = 95.6451 minThrNLimit = 115.314 -> result = 95.7258 -> 95
[11:07:41.573] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 96.3062 minThrLimit = 96.2966 minThrNLimit = 116.816 -> result = 96.3062 -> 96
[11:07:41.573] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 89.4665 minThrLimit = 89.4052 minThrNLimit = 112.534 -> result = 89.4665 -> 89
[11:07:41.574] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 84.76 minThrLimit = 84.7528 minThrNLimit = 108.387 -> result = 84.76 -> 84
[11:07:41.574] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 89.5697 minThrLimit = 89.5573 minThrNLimit = 107.753 -> result = 89.5697 -> 89
[11:07:41.574] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 97.7554 minThrLimit = 97.7038 minThrNLimit = 119.789 -> result = 97.7554 -> 97
[11:07:41.574] INFO: ROC 0 VthrComp = 93
[11:07:41.574] INFO: ROC 1 VthrComp = 82
[11:07:41.575] INFO: ROC 2 VthrComp = 84
[11:07:41.575] INFO: ROC 3 VthrComp = 93
[11:07:41.575] INFO: ROC 4 VthrComp = 91
[11:07:41.575] INFO: ROC 5 VthrComp = 101
[11:07:41.575] INFO: ROC 6 VthrComp = 80
[11:07:41.576] INFO: ROC 7 VthrComp = 91
[11:07:41.576] INFO: ROC 8 VthrComp = 86
[11:07:41.576] INFO: ROC 9 VthrComp = 97
[11:07:41.576] INFO: ROC 10 VthrComp = 95
[11:07:41.576] INFO: ROC 11 VthrComp = 96
[11:07:41.577] INFO: ROC 12 VthrComp = 89
[11:07:41.577] INFO: ROC 13 VthrComp = 84
[11:07:41.577] INFO: ROC 14 VthrComp = 89
[11:07:41.577] INFO: ROC 15 VthrComp = 97
[11:07:41.577] INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[11:07:41.577] INFO: ---> dac: vcal name: TrimThr1 ntrig: 5 dacrange: 0 .. 159 (20) hits flags = 16 (plus default)
[11:07:41.587] INFO: dacScan step from 0 .. 19
[11:07:41.587] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:07:53.916] INFO: Test took 12329ms.
[11:07:53.938] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:07:53.938] INFO: dacScan step from 20 .. 39
[11:07:53.938] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:08:06.563] INFO: Test took 12625ms.
[11:08:06.598] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:08:06.601] INFO: dacScan step from 40 .. 59
[11:08:06.601] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:08:21.961] INFO: Test took 15360ms.
[11:08:22.110] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:08:22.151] INFO: dacScan step from 60 .. 79
[11:08:22.151] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:08:39.166] INFO: Test took 17015ms.
[11:08:39.332] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:08:39.385] INFO: dacScan step from 80 .. 99
[11:08:39.386] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:08:56.333] INFO: Test took 16947ms.
[11:08:56.500] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:08:56.552] INFO: dacScan step from 100 .. 119
[11:08:56.552] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:09:13.715] INFO: Test took 17163ms.
[11:09:13.880] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:09:13.933] INFO: dacScan step from 120 .. 139
[11:09:13.933] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:09:32.512] INFO: Test took 18579ms.
[11:09:32.680] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:09:32.733] INFO: dacScan step from 140 .. 159
[11:09:32.733] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:09:49.632] INFO: Test took 16898ms.
[11:09:49.796] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:09:49.850] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[11:09:51.234] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[11:09:52.611] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[11:09:53.979] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[11:09:55.380] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[11:09:56.822] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[11:09:58.246] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[11:09:59.635] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[11:10:01.032] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[11:10:02.418] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[11:10:03.803] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[11:10:05.197] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[11:10:06.599] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[11:10:07.963] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[11:10:09.324] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[11:10:10.721] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[11:10:12.127] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 626331648
[11:10:12.129] INFO: roc 0 with ID = 0 has maximal Vcal 60.9971 for pixel 24/71 mean/min/max = 46.2495/31.3971/61.1019
[11:10:12.129] INFO: roc 1 with ID = 1 has maximal Vcal 57.8005 for pixel 18/79 mean/min/max = 45.4087/32.8686/57.9489
[11:10:12.129] INFO: roc 2 with ID = 2 has maximal Vcal 56.4361 for pixel 7/48 mean/min/max = 44.9784/33.116/56.8407
[11:10:12.129] INFO: roc 3 with ID = 3 has maximal Vcal 59.5362 for pixel 0/0 mean/min/max = 45.8577/32.1764/59.539
[11:10:12.130] INFO: roc 4 with ID = 4 has maximal Vcal 67.1651 for pixel 23/79 mean/min/max = 49.2655/31.206/67.3251
[11:10:12.130] INFO: roc 5 with ID = 5 has maximal Vcal 63.3681 for pixel 0/5 mean/min/max = 47.5734/31.7383/63.4086
[11:10:12.130] INFO: roc 6 with ID = 6 has maximal Vcal 57.6154 for pixel 0/0 mean/min/max = 45.4975/33.128/57.867
[11:10:12.131] INFO: roc 7 with ID = 7 has maximal Vcal 60.5742 for pixel 6/33 mean/min/max = 46.1548/31.6188/60.6908
[11:10:12.131] INFO: roc 8 with ID = 8 has maximal Vcal 61.8805 for pixel 21/2 mean/min/max = 47.1887/32.494/61.8834
[11:10:12.131] INFO: roc 9 with ID = 9 has maximal Vcal 59.8637 for pixel 22/78 mean/min/max = 45.6129/31.3166/59.9093
[11:10:12.132] INFO: roc 10 with ID = 10 has maximal Vcal 60.7722 for pixel 0/11 mean/min/max = 46.273/31.2299/61.3161
[11:10:12.132] INFO: roc 11 with ID = 11 has maximal Vcal 60.7456 for pixel 12/0 mean/min/max = 46.0542/31.1523/60.9561
[11:10:12.132] INFO: roc 12 with ID = 12 has maximal Vcal 58.0552 for pixel 17/2 mean/min/max = 45.359/32.6122/58.1058
[11:10:12.133] INFO: roc 13 with ID = 13 has maximal Vcal 58.689 for pixel 12/11 mean/min/max = 45.3502/31.8448/58.8555
[11:10:12.133] INFO: roc 14 with ID = 14 has maximal Vcal 60.3145 for pixel 8/77 mean/min/max = 46.5419/32.764/60.3198
[11:10:12.133] INFO: roc 15 with ID = 15 has maximal Vcal 64.9828 for pixel 20/74 mean/min/max = 48.338/31.5846/65.0915
[11:10:12.133] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:11:27.358] INFO: Test took 75225ms.
[11:11:28.128] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.4096 < 35 for itrim = 108; old thr = 34.4376 ... break
[11:11:28.152] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.1762 < 35 for itrim = 96; old thr = 34.6728 ... break
[11:11:28.178] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.0609 < 35 for itrim = 100; old thr = 32.62 ... break
[11:11:28.204] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.4159 < 35 for itrim = 116; old thr = 33.4094 ... break
[11:11:28.210] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.0676 < 35 for itrim = 98; old thr = 33.1279 ... break
[11:11:28.232] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.1013 < 35 for itrim = 108; old thr = 34.1279 ... break
[11:11:28.254] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.068 < 35 for itrim = 96; old thr = 32.0528 ... break
[11:11:28.283] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.159 < 35 for itrim = 114; old thr = 34.5821 ... break
[11:11:28.310] DEBUG: <PixTestTrim.cc/trimTest:L309> vtrim: vcal = 35.7569 < 35 for itrim+1 = 113; old thr = 34.8441 ... break
[11:11:28.338] DEBUG: <PixTestTrim.cc/trimTest:L309> vtrim: vcal = 35.945 < 35 for itrim+1 = 110; old thr = 34.24 ... break
[11:11:28.358] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.2139 < 35 for itrim = 107; old thr = 33.4708 ... break
[11:11:28.387] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.257 < 35 for itrim = 110; old thr = 32.9385 ... break
[11:11:28.421] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.1191 < 35 for itrim = 109; old thr = 34.5901 ... break
[11:11:28.458] DEBUG: <PixTestTrim.cc/trimTest:L309> vtrim: vcal = 36.0681 < 35 for itrim+1 = 109; old thr = 34.3942 ... break
[11:11:28.483] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.0698 < 35 for itrim = 113; old thr = 34.3716 ... break
[11:11:28.506] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.0009 < 35 for itrim = 114; old thr = 33.7738 ... break
[11:11:28.571] INFO: ---> dac: vcal name: TrimThr2 ntrig: 10 dacrange: 0 .. 199 (20) hits flags = 16 (plus default)
[11:11:28.580] INFO: dacScan step from 0 .. 19
[11:11:28.580] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:11:47.162] INFO: Test took 18582ms.
[11:11:47.212] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:11:47.215] INFO: dacScan step from 20 .. 39
[11:11:47.215] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:12:10.044] INFO: Test took 22829ms.
[11:12:10.272] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:12:10.310] INFO: dacScan step from 40 .. 59
[11:12:10.310] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:12:37.839] INFO: Test took 27529ms.
[11:12:38.124] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:12:38.178] INFO: dacScan step from 60 .. 79
[11:12:38.178] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:13:05.593] INFO: Test took 27415ms.
[11:13:05.881] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:13:05.935] INFO: dacScan step from 80 .. 99
[11:13:05.935] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:13:33.417] INFO: Test took 27482ms.
[11:13:33.698] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:13:33.751] INFO: dacScan step from 100 .. 119
[11:13:33.751] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:14:01.335] INFO: Test took 27584ms.
[11:14:01.620] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:14:01.675] INFO: dacScan step from 120 .. 139
[11:14:01.675] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:14:30.716] INFO: Test took 29041ms.
[11:14:30.997] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:14:31.051] INFO: dacScan step from 140 .. 159
[11:14:31.051] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:14:58.002] INFO: Test took 27951ms.
[11:14:59.280] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:14:59.334] INFO: dacScan step from 160 .. 179
[11:14:59.334] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:15:27.221] INFO: Test took 27887ms.
[11:15:27.500] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:15:27.555] INFO: dacScan step from 180 .. 199
[11:15:27.555] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:15:55.052] INFO: Test took 27497ms.
[11:15:55.331] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:15:55.387] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[11:15:56.765] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[11:15:58.143] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[11:15:59.494] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[11:16:00.897] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[11:16:02.330] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[11:16:03.743] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[11:16:05.118] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[11:16:06.500] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[11:16:07.900] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[11:16:09.307] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[11:16:10.740] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[11:16:12.178] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[11:16:13.565] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[11:16:14.921] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[11:16:16.360] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[11:16:17.810] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 626364416
[11:16:17.812] INFO: ---> TrimStepCorr4 extremal thresholds: 0.007824 .. 255.000000
[11:16:17.874] INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 4 dacrange: 0 .. 255 (20) hits flags = 16 (plus default)
[11:16:17.883] INFO: dacScan step from 0 .. 19
[11:16:17.883] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:16:29.267] INFO: Test took 11384ms.
[11:16:29.288] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:16:29.289] INFO: dacScan step from 20 .. 39
[11:16:29.289] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:16:41.391] INFO: Test took 12102ms.
[11:16:41.473] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:16:41.490] INFO: dacScan step from 40 .. 59
[11:16:41.491] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:16:55.934] INFO: Test took 14443ms.
[11:16:56.083] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:16:56.140] INFO: dacScan step from 60 .. 79
[11:16:56.140] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:17:11.074] INFO: Test took 14934ms.
[11:17:11.218] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:17:11.276] INFO: dacScan step from 80 .. 99
[11:17:11.276] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:17:26.206] INFO: Test took 14930ms.
[11:17:26.348] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:17:26.404] INFO: dacScan step from 100 .. 119
[11:17:26.404] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:17:41.435] INFO: Test took 15031ms.
[11:17:41.580] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:17:41.634] INFO: dacScan step from 120 .. 139
[11:17:41.634] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:17:58.155] INFO: Test took 16521ms.
[11:17:58.299] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:17:58.355] INFO: dacScan step from 140 .. 159
[11:17:58.355] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:18:13.603] INFO: Test took 15248ms.
[11:18:13.745] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:18:13.802] INFO: dacScan step from 160 .. 179
[11:18:13.803] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:18:28.969] INFO: Test took 15166ms.
[11:18:29.113] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:18:29.169] INFO: dacScan step from 180 .. 199
[11:18:29.169] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:18:45.178] INFO: Test took 16009ms.
[11:18:45.324] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:18:45.381] INFO: dacScan step from 200 .. 219
[11:18:45.381] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:19:00.418] INFO: Test took 15037ms.
[11:19:00.559] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:19:00.616] INFO: dacScan step from 220 .. 239
[11:19:00.616] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:19:15.414] INFO: Test took 14798ms.
[11:19:15.557] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:19:15.611] INFO: dacScan step from 240 .. 255
[11:19:15.611] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:19:27.911] INFO: Test took 12300ms.
[11:19:28.028] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:19:28.074] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[11:19:29.774] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[11:19:31.465] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[11:19:33.157] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[11:19:34.874] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[11:19:36.616] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[11:19:38.331] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[11:19:40.031] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[11:19:41.744] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[11:19:43.467] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[11:19:45.178] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[11:19:46.902] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[11:19:48.624] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[11:19:50.328] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[11:19:52.019] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[11:19:53.748] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[11:19:55.490] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 626364416
[11:19:55.557] INFO: ---> TrimStepCorr2 extremal thresholds: 1.009350 .. 86.406331
[11:19:55.621] INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 4 dacrange: 1 .. 96 (20) hits flags = 16 (plus default)
[11:19:55.630] INFO: dacScan step from 1 .. 20
[11:19:55.630] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:20:07.044] INFO: Test took 11414ms.
[11:20:07.067] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:20:07.067] INFO: dacScan step from 21 .. 40
[11:20:07.067] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:20:19.252] INFO: Test took 12185ms.
[11:20:19.337] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:20:19.357] INFO: dacScan step from 41 .. 60
[11:20:19.358] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:20:34.031] INFO: Test took 14673ms.
[11:20:34.177] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:20:34.233] INFO: dacScan step from 61 .. 80
[11:20:34.233] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:20:48.770] INFO: Test took 14537ms.
[11:20:48.925] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:20:48.979] INFO: dacScan step from 81 .. 96
[11:20:48.979] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:21:01.383] INFO: Test took 12404ms.
[11:21:01.497] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:21:01.541] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[11:21:02.672] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[11:21:03.804] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[11:21:04.940] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[11:21:06.079] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[11:21:07.220] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[11:21:08.356] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[11:21:09.480] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[11:21:10.613] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[11:21:11.744] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[11:21:12.875] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[11:21:14.010] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[11:21:15.141] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[11:21:16.268] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[11:21:17.400] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[11:21:18.534] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[11:21:19.681] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 626487296
[11:21:19.750] INFO: ---> TrimStepCorr1a extremal thresholds: 5.340360 .. 64.591113
[11:21:19.814] INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 4 dacrange: 5 .. 74 (20) hits flags = 16 (plus default)
[11:21:19.823] INFO: dacScan step from 5 .. 24
[11:21:19.824] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:21:31.261] INFO: Test took 11437ms.
[11:21:31.284] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:21:31.284] INFO: dacScan step from 25 .. 44
[11:21:31.284] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:21:44.371] INFO: Test took 13087ms.
[11:21:44.480] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:21:44.512] INFO: dacScan step from 45 .. 64
[11:21:44.512] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:21:59.287] INFO: Test took 14775ms.
[11:21:59.435] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:21:59.493] INFO: dacScan step from 65 .. 74
[11:21:59.493] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:22:08.231] INFO: Test took 8738ms.
[11:22:08.303] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:22:08.333] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[11:22:09.336] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[11:22:10.338] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[11:22:11.338] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[11:22:12.339] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[11:22:13.346] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[11:22:14.351] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[11:22:15.359] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[11:22:16.360] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[11:22:17.359] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[11:22:18.349] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[11:22:19.338] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[11:22:20.331] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[11:22:21.319] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[11:22:22.312] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[11:22:23.302] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[11:22:24.298] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 626487296
[11:22:24.366] INFO: ---> TrimStepCorr1b extremal thresholds: 1.485391 .. 64.591113
[11:22:24.429] INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 4 dacrange: 1 .. 74 (20) hits flags = 16 (plus default)
[11:22:24.438] INFO: dacScan step from 1 .. 20
[11:22:24.438] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:22:35.797] INFO: Test took 11359ms.
[11:22:35.820] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:22:35.820] INFO: dacScan step from 21 .. 40
[11:22:35.820] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:22:48.138] INFO: Test took 12318ms.
[11:22:48.220] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:22:48.241] INFO: dacScan step from 41 .. 60
[11:22:48.241] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:23:03.081] INFO: Test took 14840ms.
[11:23:03.230] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:23:03.287] INFO: dacScan step from 61 .. 74
[11:23:03.287] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:23:14.499] INFO: Test took 11212ms.
[11:23:14.603] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:23:14.646] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[11:23:15.648] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[11:23:16.652] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[11:23:17.662] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[11:23:18.682] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[11:23:19.705] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[11:23:20.722] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[11:23:21.720] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[11:23:22.725] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[11:23:23.725] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[11:23:24.727] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[11:23:25.725] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[11:23:26.729] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[11:23:27.729] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[11:23:28.734] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[11:23:29.735] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[11:23:30.736] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 626491392
[11:23:30.805] INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[11:23:30.805] INFO: ---> dac: vcal name: TrimThrFinal ntrig: 10 dacrange: 15 .. 55 (20) hits flags = 16 (plus default)
[11:23:30.814] INFO: dacScan step from 15 .. 34
[11:23:30.814] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:23:49.155] INFO: Test took 18341ms.
[11:23:49.225] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:23:49.235] INFO: dacScan step from 35 .. 54
[11:23:49.235] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:24:15.877] INFO: Test took 26642ms.
[11:24:16.172] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:24:16.226] INFO: dacScan step from 55 .. 55
[11:24:16.226] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:24:19.989] INFO: Test took 3763ms.
[11:24:20.006] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:24:20.009] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[11:24:20.761] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[11:24:21.515] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[11:24:22.265] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[11:24:23.005] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[11:24:23.733] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[11:24:24.466] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[11:24:25.201] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[11:24:25.935] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[11:24:26.668] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[11:24:27.402] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[11:24:28.137] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[11:24:28.870] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[11:24:29.607] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[11:24:30.343] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[11:24:31.078] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[11:24:31.811] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 626491392
[11:24:31.868] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//dacParameters35_C0.dat
[11:24:31.869] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//dacParameters35_C1.dat
[11:24:31.869] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//dacParameters35_C2.dat
[11:24:31.869] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//dacParameters35_C3.dat
[11:24:31.869] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//dacParameters35_C4.dat
[11:24:31.869] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//dacParameters35_C5.dat
[11:24:31.869] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//dacParameters35_C6.dat
[11:24:31.869] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//dacParameters35_C7.dat
[11:24:31.869] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//dacParameters35_C8.dat
[11:24:31.869] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//dacParameters35_C9.dat
[11:24:31.869] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//dacParameters35_C10.dat
[11:24:31.869] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//dacParameters35_C11.dat
[11:24:31.869] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//dacParameters35_C12.dat
[11:24:31.870] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//dacParameters35_C13.dat
[11:24:31.870] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//dacParameters35_C14.dat
[11:24:31.870] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//dacParameters35_C15.dat
[11:24:31.870] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//trimParameters35_C0.dat
[11:24:31.875] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//trimParameters35_C1.dat
[11:24:31.882] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//trimParameters35_C2.dat
[11:24:31.888] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//trimParameters35_C3.dat
[11:24:31.893] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//trimParameters35_C4.dat
[11:24:31.899] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//trimParameters35_C5.dat
[11:24:31.904] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//trimParameters35_C6.dat
[11:24:31.910] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//trimParameters35_C7.dat
[11:24:31.915] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//trimParameters35_C8.dat
[11:24:31.921] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//trimParameters35_C9.dat
[11:24:31.927] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//trimParameters35_C10.dat
[11:24:31.932] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//trimParameters35_C11.dat
[11:24:31.938] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//trimParameters35_C12.dat
[11:24:31.943] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//trimParameters35_C13.dat
[11:24:31.949] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//trimParameters35_C14.dat
[11:24:31.954] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//trimParameters35_C15.dat
[11:24:31.960] INFO: PixTestTrim::trimTest() done
[11:24:31.960] INFO: vtrim: 108 96 100 116 98 108 96 114 113 110 107 110 109 109 113 114
[11:24:31.960] INFO: vthrcomp: 93 82 84 93 91 101 80 91 86 97 95 96 89 84 89 97
[11:24:31.960] INFO: vcal mean: 34.99 35.04 35.07 35.06 35.07 35.01 35.03 35.03 35.06 35.02 35.01 35.08 35.06 35.00 35.06 34.97
[11:24:31.960] INFO: vcal RMS: 1.22 1.05 1.01 1.12 1.36 1.19 1.17 1.56 1.80 1.33 1.12 1.15 1.01 1.40 1.17 1.93
[11:24:31.960] INFO: bits mean: 9.66 9.84 10.16 10.05 8.97 9.33 9.68 9.98 9.56 9.55 9.37 10.02 9.64 10.05 9.93 9.39
[11:24:31.960] INFO: bits RMS: 2.68 2.48 2.33 2.41 2.69 2.69 2.52 2.51 2.55 2.83 2.83 2.54 2.57 2.41 2.36 2.56
[11:24:31.969] INFO: ----------------------------------------------------------------------
[11:24:31.969] INFO: PixTestTrim::trimBitTest() ntrig = 10, vtrims = 254 126 63 32
[11:24:31.969] INFO: ----------------------------------------------------------------------
[11:24:31.974] DEBUG: <PixTestTrim.cc/trimBitTest:L518> trimBitTest determine threshold map without trims
[11:24:31.974] INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 10 dacrange: 0 .. 199 (20) hits flags = 16 (plus default)
[11:24:31.983] INFO: dacScan step from 0 .. 19
[11:24:31.983] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:24:50.079] INFO: Test took 18096ms.
[11:24:50.119] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:24:50.119] INFO: dacScan step from 20 .. 39
[11:24:50.120] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:25:08.658] INFO: Test took 18538ms.
[11:25:08.697] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:25:08.697] INFO: dacScan step from 40 .. 59
[11:25:08.698] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:25:27.150] INFO: Test took 18452ms.
[11:25:27.188] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:25:27.188] INFO: dacScan step from 60 .. 79
[11:25:27.188] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:25:45.628] INFO: Test took 18440ms.
[11:25:45.667] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:25:45.667] INFO: dacScan step from 80 .. 99
[11:25:45.667] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:26:04.365] INFO: Test took 18698ms.
[11:26:04.414] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:26:04.416] INFO: dacScan step from 100 .. 119
[11:26:04.416] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:26:25.642] INFO: Test took 21226ms.
[11:26:25.809] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:26:25.828] INFO: dacScan step from 120 .. 139
[11:26:25.828] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:26:52.647] INFO: Test took 26819ms.
[11:26:52.921] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:26:52.980] INFO: dacScan step from 140 .. 159
[11:26:52.980] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:27:20.490] INFO: Test took 27509ms.
[11:27:20.766] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:27:20.821] INFO: dacScan step from 160 .. 179
[11:27:20.821] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:27:48.407] INFO: Test took 27586ms.
[11:27:48.681] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:27:48.737] INFO: dacScan step from 180 .. 199
[11:27:48.737] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:28:17.360] INFO: Test took 28623ms.
[11:28:17.634] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:28:17.687] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[11:28:19.085] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[11:28:20.498] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[11:28:21.936] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[11:28:23.354] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[11:28:24.728] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[11:28:26.084] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[11:28:27.495] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[11:28:28.899] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[11:28:30.299] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[11:28:31.687] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[11:28:33.059] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[11:28:34.435] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[11:28:35.831] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[11:28:37.234] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[11:28:38.636] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[11:28:40.003] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 626507776
[11:28:40.003] DEBUG: <PixTestTrim.cc/trimBitTest:L533> trimBitTest initDUT with trim bits = 14
[11:28:40.079] DEBUG: <PixTestTrim.cc/trimBitTest:L539> trimBitTest threshold map with trim = 14
[11:28:40.079] INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 10 dacrange: 0 .. 199 (20) hits flags = 16 (plus default)
[11:28:40.091] INFO: dacScan step from 0 .. 19
[11:28:40.091] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:28:58.245] INFO: Test took 18154ms.
[11:28:58.283] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:28:58.283] INFO: dacScan step from 20 .. 39
[11:28:58.283] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:29:16.329] INFO: Test took 18046ms.
[11:29:16.366] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:29:16.366] INFO: dacScan step from 40 .. 59
[11:29:16.366] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:29:34.748] INFO: Test took 18382ms.
[11:29:34.785] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:29:34.785] INFO: dacScan step from 60 .. 79
[11:29:34.786] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:29:53.223] INFO: Test took 18437ms.
[11:29:53.263] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:29:53.263] INFO: dacScan step from 80 .. 99
[11:29:53.263] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:30:12.402] INFO: Test took 19139ms.
[11:30:12.492] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:30:12.500] INFO: dacScan step from 100 .. 119
[11:30:12.500] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:30:35.618] INFO: Test took 23118ms.
[11:30:35.863] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:30:35.897] INFO: dacScan step from 120 .. 139
[11:30:35.898] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:31:04.570] INFO: Test took 28671ms.
[11:31:04.851] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:31:04.903] INFO: dacScan step from 140 .. 159
[11:31:04.903] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:31:32.446] INFO: Test took 27543ms.
[11:31:32.722] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:31:32.777] INFO: dacScan step from 160 .. 179
[11:31:32.777] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:32:00.412] INFO: Test took 27635ms.
[11:32:00.694] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:32:00.754] INFO: dacScan step from 180 .. 199
[11:32:00.754] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:32:29.393] INFO: Test took 28639ms.
[11:32:29.666] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:32:29.721] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[11:32:31.129] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[11:32:32.553] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[11:32:34.006] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[11:32:35.450] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[11:32:36.882] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[11:32:38.309] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[11:32:39.746] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[11:32:41.158] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[11:32:42.563] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[11:32:43.959] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[11:32:45.356] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[11:32:46.762] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[11:32:48.167] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[11:32:49.580] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[11:32:50.988] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[11:32:52.376] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 626507776
[11:32:52.377] DEBUG: <PixTestTrim.cc/trimBitTest:L533> trimBitTest initDUT with trim bits = 13
[11:32:52.447] DEBUG: <PixTestTrim.cc/trimBitTest:L539> trimBitTest threshold map with trim = 13
[11:32:52.447] INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 10 dacrange: 0 .. 195 (20) hits flags = 16 (plus default)
[11:32:52.456] INFO: dacScan step from 0 .. 19
[11:32:52.456] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:33:10.634] INFO: Test took 18178ms.
[11:33:10.670] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:33:10.670] INFO: dacScan step from 20 .. 39
[11:33:10.670] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:33:29.080] INFO: Test took 18410ms.
[11:33:29.120] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:33:29.120] INFO: dacScan step from 40 .. 59
[11:33:29.120] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:33:47.605] INFO: Test took 18485ms.
[11:33:47.645] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:33:47.645] INFO: dacScan step from 60 .. 79
[11:33:47.645] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:34:05.647] INFO: Test took 18002ms.
[11:34:05.684] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:34:05.684] INFO: dacScan step from 80 .. 99
[11:34:05.684] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:34:24.828] INFO: Test took 19144ms.
[11:34:24.916] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:34:24.924] INFO: dacScan step from 100 .. 119
[11:34:24.925] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:34:48.479] INFO: Test took 23554ms.
[11:34:48.709] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:34:48.740] INFO: dacScan step from 120 .. 139
[11:34:48.740] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:35:17.576] INFO: Test took 28836ms.
[11:35:17.858] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:35:17.909] INFO: dacScan step from 140 .. 159
[11:35:17.909] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:35:45.786] INFO: Test took 27877ms.
[11:35:46.065] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:35:46.120] INFO: dacScan step from 160 .. 179
[11:35:46.120] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:36:13.701] INFO: Test took 27581ms.
[11:36:13.974] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:36:14.040] INFO: dacScan step from 180 .. 195
[11:36:14.040] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:36:37.320] INFO: Test took 23280ms.
[11:36:37.547] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:36:37.596] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[11:36:38.984] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[11:36:40.380] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[11:36:41.790] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[11:36:43.180] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[11:36:44.553] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[11:36:45.914] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[11:36:47.310] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[11:36:48.696] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[11:36:50.092] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[11:36:51.474] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[11:36:52.849] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[11:36:54.233] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[11:36:55.624] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[11:36:57.010] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[11:36:58.418] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[11:36:59.780] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 626507776
[11:36:59.781] DEBUG: <PixTestTrim.cc/trimBitTest:L533> trimBitTest initDUT with trim bits = 11
[11:36:59.845] DEBUG: <PixTestTrim.cc/trimBitTest:L539> trimBitTest threshold map with trim = 11
[11:36:59.845] INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 10 dacrange: 0 .. 181 (20) hits flags = 16 (plus default)
[11:36:59.854] INFO: dacScan step from 0 .. 19
[11:36:59.854] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:37:17.913] INFO: Test took 18059ms.
[11:37:17.949] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:37:17.949] INFO: dacScan step from 20 .. 39
[11:37:17.949] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:37:36.479] INFO: Test took 18530ms.
[11:37:36.518] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:37:36.519] INFO: dacScan step from 40 .. 59
[11:37:36.519] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:37:54.973] INFO: Test took 18454ms.
[11:37:55.012] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:37:55.012] INFO: dacScan step from 60 .. 79
[11:37:55.012] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:38:13.590] INFO: Test took 18578ms.
[11:38:13.627] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:38:13.627] INFO: dacScan step from 80 .. 99
[11:38:13.627] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:38:32.830] INFO: Test took 19203ms.
[11:38:32.921] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:38:32.929] INFO: dacScan step from 100 .. 119
[11:38:32.929] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:38:56.579] INFO: Test took 23650ms.
[11:38:56.811] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:38:56.842] INFO: dacScan step from 120 .. 139
[11:38:56.842] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:39:25.463] INFO: Test took 28621ms.
[11:39:25.743] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:39:25.798] INFO: dacScan step from 140 .. 159
[11:39:25.798] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:39:53.352] INFO: Test took 27554ms.
[11:39:53.631] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:39:53.687] INFO: dacScan step from 160 .. 179
[11:39:53.687] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:40:21.178] INFO: Test took 27491ms.
[11:40:21.451] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:40:21.503] INFO: dacScan step from 180 .. 181
[11:40:21.503] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:40:26.471] INFO: Test took 4968ms.
[11:40:26.502] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:40:26.510] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[11:40:27.000] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[11:40:29.554] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[11:40:31.160] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[11:40:33.033] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[11:40:34.803] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[11:40:36.463] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[11:40:38.264] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[11:40:39.818] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[11:40:41.164] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[11:40:42.502] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[11:40:43.842] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[11:40:45.183] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[11:40:46.527] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[11:40:47.887] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[11:40:49.233] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[11:40:50.554] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 626507776
[11:40:50.555] DEBUG: <PixTestTrim.cc/trimBitTest:L533> trimBitTest initDUT with trim bits = 7
[11:40:50.618] DEBUG: <PixTestTrim.cc/trimBitTest:L539> trimBitTest threshold map with trim = 7
[11:40:50.618] INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 10 dacrange: 0 .. 166 (20) hits flags = 16 (plus default)
[11:40:50.627] INFO: dacScan step from 0 .. 19
[11:40:50.627] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:41:09.161] INFO: Test took 18534ms.
[11:41:09.197] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:41:09.197] INFO: dacScan step from 20 .. 39
[11:41:09.197] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:41:27.720] INFO: Test took 18523ms.
[11:41:27.756] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:41:27.756] INFO: dacScan step from 40 .. 59
[11:41:27.756] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:41:46.166] INFO: Test took 18410ms.
[11:41:46.204] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:41:46.205] INFO: dacScan step from 60 .. 79
[11:41:46.205] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:42:04.654] INFO: Test took 18449ms.
[11:42:04.692] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:42:04.692] INFO: dacScan step from 80 .. 99
[11:42:04.692] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:42:23.819] INFO: Test took 19127ms.
[11:42:23.911] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:42:23.920] INFO: dacScan step from 100 .. 119
[11:42:23.921] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:42:47.458] INFO: Test took 23537ms.
[11:42:47.687] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:42:47.717] INFO: dacScan step from 120 .. 139
[11:42:47.717] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:43:16.284] INFO: Test took 28566ms.
[11:43:16.562] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:43:16.616] INFO: dacScan step from 140 .. 159
[11:43:16.617] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:43:44.254] INFO: Test took 27637ms.
[11:43:44.533] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:43:44.585] INFO: dacScan step from 160 .. 166
[11:43:44.585] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:43:55.787] INFO: Test took 11201ms.
[11:43:55.883] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:43:55.906] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[11:43:57.186] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[11:43:58.469] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[11:43:59.727] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[11:44:00.975] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[11:44:02.204] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[11:44:03.417] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[11:44:04.687] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[11:44:05.945] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[11:44:07.198] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[11:44:08.460] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[11:44:09.892] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[11:44:11.141] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[11:44:12.397] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[11:44:13.666] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[11:44:14.922] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[11:44:16.142] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 626507776
[11:44:16.143] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 0 step 0: thr difference mean: 9.20832, thr difference RMS: 1.53544
[11:44:16.143] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 1 step 0: thr difference mean: 9.75402, thr difference RMS: 1.09289
[11:44:16.143] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 2 step 0: thr difference mean: 9.67192, thr difference RMS: 1.12913
[11:44:16.143] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 3 step 0: thr difference mean: 8.70571, thr difference RMS: 1.55209
[11:44:16.143] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 4 step 0: thr difference mean: 11.1767, thr difference RMS: 2.04472
[11:44:16.144] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 5 step 0: thr difference mean: 11.9942, thr difference RMS: 1.04935
[11:44:16.144] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 6 step 0: thr difference mean: 9.55033, thr difference RMS: 0.963046
[11:44:16.144] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 7 step 0: thr difference mean: 9.10018, thr difference RMS: 1.49183
[11:44:16.144] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 8 step 0: thr difference mean: 9.02624, thr difference RMS: 1.36568
[11:44:16.144] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 9 step 0: thr difference mean: 8.93801, thr difference RMS: 1.33076
[11:44:16.144] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 10 step 0: thr difference mean: 10.152, thr difference RMS: 1.52584
[11:44:16.144] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 11 step 0: thr difference mean: 10.6217, thr difference RMS: 1.59683
[11:44:16.145] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 12 step 0: thr difference mean: 8.61269, thr difference RMS: 1.15598
[11:44:16.145] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 13 step 0: thr difference mean: 9.56263, thr difference RMS: 1.09283
[11:44:16.145] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 14 step 0: thr difference mean: 8.84377, thr difference RMS: 1.49723
[11:44:16.145] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 15 step 0: thr difference mean: 11.5712, thr difference RMS: 1.38869
[11:44:16.145] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 0 step 1: thr difference mean: 9.30942, thr difference RMS: 1.52212
[11:44:16.145] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 1 step 1: thr difference mean: 9.90147, thr difference RMS: 1.09371
[11:44:16.146] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 2 step 1: thr difference mean: 9.71095, thr difference RMS: 1.08654
[11:44:16.146] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 3 step 1: thr difference mean: 8.81472, thr difference RMS: 1.55081
[11:44:16.146] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 4 step 1: thr difference mean: 11.3715, thr difference RMS: 2.26621
[11:44:16.146] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 5 step 1: thr difference mean: 12.1526, thr difference RMS: 1.02449
[11:44:16.146] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 6 step 1: thr difference mean: 9.57852, thr difference RMS: 0.937743
[11:44:16.146] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 7 step 1: thr difference mean: 9.19499, thr difference RMS: 1.48266
[11:44:16.147] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 8 step 1: thr difference mean: 9.00336, thr difference RMS: 1.34001
[11:44:16.147] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 9 step 1: thr difference mean: 8.86765, thr difference RMS: 1.34131
[11:44:16.147] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 10 step 1: thr difference mean: 10.1413, thr difference RMS: 1.5122
[11:44:16.147] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 11 step 1: thr difference mean: 10.801, thr difference RMS: 1.60199
[11:44:16.147] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 12 step 1: thr difference mean: 8.58406, thr difference RMS: 1.15511
[11:44:16.147] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 13 step 1: thr difference mean: 9.59078, thr difference RMS: 1.07185
[11:44:16.147] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 14 step 1: thr difference mean: 9.01202, thr difference RMS: 1.4874
[11:44:16.148] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 15 step 1: thr difference mean: 11.6624, thr difference RMS: 1.36931
[11:44:16.148] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 0 step 2: thr difference mean: 9.49933, thr difference RMS: 1.53381
[11:44:16.148] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 1 step 2: thr difference mean: 10.1875, thr difference RMS: 1.11362
[11:44:16.148] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 2 step 2: thr difference mean: 9.86543, thr difference RMS: 1.05959
[11:44:16.148] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 3 step 2: thr difference mean: 8.94995, thr difference RMS: 1.52052
[11:44:16.148] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 4 step 2: thr difference mean: 11.5832, thr difference RMS: 2.56134
[11:44:16.149] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 5 step 2: thr difference mean: 12.4068, thr difference RMS: 1.02916
[11:44:16.149] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 6 step 2: thr difference mean: 9.74494, thr difference RMS: 0.936951
[11:44:16.149] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 7 step 2: thr difference mean: 9.38427, thr difference RMS: 1.47534
[11:44:16.149] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 8 step 2: thr difference mean: 9.1711, thr difference RMS: 1.34105
[11:44:16.149] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 9 step 2: thr difference mean: 8.93022, thr difference RMS: 1.34061
[11:44:16.149] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 10 step 2: thr difference mean: 10.1466, thr difference RMS: 1.54603
[11:44:16.149] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 11 step 2: thr difference mean: 10.9389, thr difference RMS: 1.6464
[11:44:16.150] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 12 step 2: thr difference mean: 8.84824, thr difference RMS: 1.14269
[11:44:16.150] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 13 step 2: thr difference mean: 9.75308, thr difference RMS: 1.86029
[11:44:16.150] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 14 step 2: thr difference mean: 9.10475, thr difference RMS: 1.49734
[11:44:16.150] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 15 step 2: thr difference mean: 11.7682, thr difference RMS: 1.37727
[11:44:16.150] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 0 step 3: thr difference mean: 9.67081, thr difference RMS: 1.51096
[11:44:16.150] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 1 step 3: thr difference mean: 10.1819, thr difference RMS: 1.08758
[11:44:16.150] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 2 step 3: thr difference mean: 9.97387, thr difference RMS: 1.10005
[11:44:16.151] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 3 step 3: thr difference mean: 9.00166, thr difference RMS: 1.5458
[11:44:16.151] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 4 step 3: thr difference mean: 11.6678, thr difference RMS: 2.68242
[11:44:16.151] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 5 step 3: thr difference mean: 12.5235, thr difference RMS: 1.03523
[11:44:16.151] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 6 step 3: thr difference mean: 9.79888, thr difference RMS: 0.934711
[11:44:16.151] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 7 step 3: thr difference mean: 9.41687, thr difference RMS: 1.46409
[11:44:16.151] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 8 step 3: thr difference mean: 9.23759, thr difference RMS: 1.32971
[11:44:16.152] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 9 step 3: thr difference mean: 9.01472, thr difference RMS: 1.35134
[11:44:16.152] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 10 step 3: thr difference mean: 10.108, thr difference RMS: 1.54589
[11:44:16.152] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 11 step 3: thr difference mean: 11.043, thr difference RMS: 1.63363
[11:44:16.152] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 12 step 3: thr difference mean: 8.89829, thr difference RMS: 1.13601
[11:44:16.152] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 13 step 3: thr difference mean: 9.74963, thr difference RMS: 1.89292
[11:44:16.152] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 14 step 3: thr difference mean: 9.2449, thr difference RMS: 1.49397
[11:44:16.152] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 15 step 3: thr difference mean: 11.8517, thr difference RMS: 1.38939
[11:44:16.267] INFO: PixTestTrim::trimBitTest() done
[11:44:16.269] INFO: PixTestTrim::doTest() done, duration: 2321 seconds
[11:44:16.269] DEBUG: <PixTestTrim.cc/~PixTestTrim:L104> PixTestTrim dtor
[11:44:16.847] DEBUG: <PixTest.cc/setTestParameter:L569> setting ntrig to new value 10
[11:44:16.847] DEBUG: <PixTestPhOptimization.cc/setParameter:L37> setting fParNtrig ->10<- from sval = 10
[11:44:16.847] DEBUG: <PixTestPhOptimization.cc/setParameter:L42> setting fSafetyMarginLow ->20<- from sval = 20
[11:44:16.847] DEBUG: <PixTestPhOptimization.cc/setParameter:L48> setting fVcalMax ->100<- from sval = 100
[11:44:16.847] DEBUG: <PixTestPhOptimization.cc/setParameter:L53> setting fQuantMax ->0.98<- from sval = 0.98
[11:44:16.848] INFO: ######################################################################
[11:44:16.848] INFO: PixTestPhOptimization::doTest() Ntrig = 10
[11:44:16.848] INFO: ######################################################################
[11:44:16.849] DEBUG: <PixTest.cc/efficiencyMaps:L328> attempt #0
[11:44:20.528] INFO: Test took 3680ms.
[11:44:20.547] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:44:20.547] DEBUG: <PixTest.cc/efficiencyMaps:L339> eff result size = 66531
[11:44:20.547] DEBUG: <PixTest.cc/efficiencyMaps:L344> Create hists PixelAlive_C0 .. PixelAlive_C15
[11:44:20.550] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [0, 51, 4] has eff 0/10
[11:44:20.550] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [0, 51, 4]
[11:44:20.550] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [4, 0, 69] has eff 0/10
[11:44:20.550] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [4, 0, 69]
[11:44:20.550] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [4, 6, 75] has eff 0/10
[11:44:20.550] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [4, 6, 75]
[11:44:20.551] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [5, 42, 76] has eff 0/10
[11:44:20.551] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [5, 42, 76]
[11:44:20.551] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [6, 1, 79] has eff 0/10
[11:44:20.551] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [6, 1, 79]
[11:44:20.551] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [7, 48, 0] has eff 0/10
[11:44:20.551] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [7, 48, 0]
[11:44:20.551] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [7, 49, 0] has eff 0/10
[11:44:20.551] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [7, 49, 0]
[11:44:20.551] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [7, 50, 0] has eff 0/10
[11:44:20.551] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [7, 50, 0]
[11:44:20.551] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [7, 51, 0] has eff 0/10
[11:44:20.551] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [7, 51, 0]
[11:44:20.551] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [8, 0, 0] has eff 0/10
[11:44:20.551] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [8, 0, 0]
[11:44:20.551] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [8, 1, 0] has eff 0/10
[11:44:20.551] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [8, 1, 0]
[11:44:20.551] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [8, 2, 0] has eff 0/10
[11:44:20.551] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [8, 2, 0]
[11:44:20.551] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [8, 3, 0] has eff 0/10
[11:44:20.551] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [8, 3, 0]
[11:44:20.551] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [8, 0, 1] has eff 0/10
[11:44:20.551] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [8, 0, 1]
[11:44:20.551] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [8, 2, 1] has eff 0/10
[11:44:20.551] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [8, 2, 1]
[11:44:20.551] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [8, 28, 23] has eff 0/10
[11:44:20.551] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [8, 28, 23]
[11:44:20.551] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [9, 50, 79] has eff 0/10
[11:44:20.551] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [9, 50, 79]
[11:44:20.551] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [9, 51, 79] has eff 0/10
[11:44:20.551] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [9, 51, 79]
[11:44:20.552] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [10, 2, 75] has eff 7/10
[11:44:20.552] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [10, 2, 75]
[11:44:20.552] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [13, 30, 7] has eff 0/10
[11:44:20.552] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [13, 30, 7]
[11:44:20.552] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [13, 31, 7] has eff 0/10
[11:44:20.552] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [13, 31, 7]
[11:44:20.552] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [13, 51, 79] has eff 0/10
[11:44:20.552] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [13, 51, 79]
[11:44:20.552] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [14, 42, 23] has eff 7/10
[11:44:20.552] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [14, 42, 23]
[11:44:20.552] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [15, 43, 0] has eff 0/10
[11:44:20.552] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [15, 43, 0]
[11:44:20.552] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [15, 47, 0] has eff 0/10
[11:44:20.552] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [15, 47, 0]
[11:44:20.552] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [15, 48, 0] has eff 0/10
[11:44:20.552] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [15, 48, 0]
[11:44:20.552] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [15, 49, 0] has eff 0/10
[11:44:20.552] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [15, 49, 0]
[11:44:20.552] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [15, 50, 0] has eff 0/10
[11:44:20.552] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [15, 50, 0]
[11:44:20.552] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [15, 51, 0] has eff 0/10
[11:44:20.552] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [15, 51, 0]
[11:44:20.552] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [15, 50, 1] has eff 0/10
[11:44:20.552] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [15, 50, 1]
[11:44:20.552] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [15, 51, 1] has eff 0/10
[11:44:20.552] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [15, 51, 1]
[11:44:20.557] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L239> Number of bad pixels found: 31
[11:44:20.557] DEBUG: <PixTestPhOptimization.cc/doTest:L124> **********Ph range will be optimised on the whole ROC***********
[11:44:20.557] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L276> ROC type is newer than digv2
[11:44:20.557] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L277> ROC type is psi46digv21respin
[11:44:20.746] DEBUG: <PixTest.cc/phMaps:L264> attempt #0
[11:44:24.483] INFO: Test took 3736ms.
[11:44:24.545] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:44:24.546] DEBUG: <PixTest.cc/phMaps:L275> eff result size = 66531
[11:44:24.546] DEBUG: <PixTest.cc/phMaps:L282> Create hists maxphmap_C0 .. maxphmap_C15
[11:44:24.549] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 201.782
[11:44:24.549] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,7] phvalue 201
[11:44:24.549] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 209.215
[11:44:24.550] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [6 ,15] phvalue 209
[11:44:24.550] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 228.314
[11:44:24.550] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,5] phvalue 229
[11:44:24.550] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 229.03
[11:44:24.550] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [4 ,5] phvalue 230
[11:44:24.550] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 212.395
[11:44:24.550] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [5 ,5] phvalue 212
[11:44:24.550] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 197.7
[11:44:24.550] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [4 ,5] phvalue 198
[11:44:24.550] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 204.097
[11:44:24.550] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,5] phvalue 204
[11:44:24.550] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 207.549
[11:44:24.550] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,5] phvalue 207
[11:44:24.550] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 219.944
[11:44:24.550] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [4 ,6] phvalue 220
[11:44:24.551] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 211.101
[11:44:24.551] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [4 ,5] phvalue 212
[11:44:24.551] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 218.089
[11:44:24.551] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,5] phvalue 218
[11:44:24.551] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 215.968
[11:44:24.551] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,9] phvalue 215
[11:44:24.551] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 217.129
[11:44:24.551] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,6] phvalue 217
[11:44:24.551] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 227.06
[11:44:24.551] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,6] phvalue 228
[11:44:24.551] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 213.749
[11:44:24.551] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [4 ,8] phvalue 214
[11:44:24.551] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 210.395
[11:44:24.551] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,5] phvalue 211
[11:44:24.551] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L427> ROC type is newer than digv2
[11:44:24.551] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L428> ROC type is psi46digv21respin
[11:44:24.551] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L450> init_phScale=150, flag_minPh = 0, minph = 0
[11:44:24.560] DEBUG: <PixTest.cc/phMaps:L264> attempt #0
[11:44:28.284] INFO: Test took 3724ms.
[11:44:28.347] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:44:28.347] DEBUG: <PixTest.cc/phMaps:L275> eff result size = 66531
[11:44:28.347] DEBUG: <PixTest.cc/phMaps:L282> Create hists minphmap_C0 .. minphmap_C15
[11:44:28.350] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L457> result size 0
[11:44:28.351] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L484> done. init_phScale=155, flag_minPh = 1, minph = 89minph_roc = 14
[11:44:28.351] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 81.471
[11:44:28.351] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [6 ,60] phvalue 82
[11:44:28.351] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 93.3826
[11:44:28.351] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,13] phvalue 94
[11:44:28.351] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 106.961
[11:44:28.351] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [8 ,24] phvalue 107
[11:44:28.351] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 101.931
[11:44:28.351] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [16 ,26] phvalue 102
[11:44:28.351] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 91.8398
[11:44:28.351] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,13] phvalue 92
[11:44:28.351] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 72.8738
[11:44:28.351] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,50] phvalue 73
[11:44:28.351] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 95.5461
[11:44:28.351] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [8 ,12] phvalue 96
[11:44:28.352] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 86.9168
[11:44:28.352] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [8 ,31] phvalue 87
[11:44:28.352] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 109.229
[11:44:28.352] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,13] phvalue 110
[11:44:28.352] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 101.107
[11:44:28.352] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,7] phvalue 101
[11:44:28.352] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 96.0145
[11:44:28.352] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [5 ,67] phvalue 97
[11:44:28.352] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 97.0635
[11:44:28.352] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [4 ,12] phvalue 98
[11:44:28.352] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 104.394
[11:44:28.352] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [5 ,68] phvalue 104
[11:44:28.352] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 122.682
[11:44:28.352] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [20 ,68] phvalue 122
[11:44:28.352] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 93.2871
[11:44:28.352] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [6 ,25] phvalue 93
[11:44:28.353] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 96.0061
[11:44:28.353] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,60] phvalue 97
[11:44:28.356] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 6, 60, 0 0
[11:44:28.356] INFO: The DUT currently contains the following objects:
[11:44:28.356] INFO: 2 TBM Cores tbm08c (2 ON)
[11:44:28.356] INFO: TBM Core alpha (0): 7 registers set
[11:44:28.356] INFO: TBM Core beta (1): 7 registers set
[11:44:28.356] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[11:44:28.356] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:28.356] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:28.356] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:28.356] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:28.356] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:28.356] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:28.356] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:28.356] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:28.356] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:28.356] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:28.356] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:28.356] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:28.356] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:28.356] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:28.356] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:28.356] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:29.446] INFO: Test took 1090ms.
[11:44:29.447] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[11:44:29.447] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 13, 1 1
[11:44:29.447] INFO: The DUT currently contains the following objects:
[11:44:29.447] INFO: 2 TBM Cores tbm08c (2 ON)
[11:44:29.447] INFO: TBM Core alpha (0): 7 registers set
[11:44:29.447] INFO: TBM Core beta (1): 7 registers set
[11:44:29.447] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[11:44:29.447] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:29.447] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:29.447] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:29.447] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:29.447] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:29.447] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:29.447] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:29.447] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:29.447] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:29.447] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:29.447] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:29.447] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:29.447] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:29.447] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:29.447] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:29.447] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:30.538] INFO: Test took 1091ms.
[11:44:30.539] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[11:44:30.539] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 8, 24, 2 2
[11:44:30.539] INFO: The DUT currently contains the following objects:
[11:44:30.539] INFO: 2 TBM Cores tbm08c (2 ON)
[11:44:30.539] INFO: TBM Core alpha (0): 7 registers set
[11:44:30.539] INFO: TBM Core beta (1): 7 registers set
[11:44:30.539] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[11:44:30.539] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:30.539] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:30.539] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:30.539] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:30.539] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:30.539] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:30.539] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:30.539] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:30.539] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:30.539] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:30.539] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:30.540] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:30.540] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:30.540] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:30.540] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:30.540] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:31.632] INFO: Test took 1092ms.
[11:44:31.633] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[11:44:31.633] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 16, 26, 3 3
[11:44:31.633] INFO: The DUT currently contains the following objects:
[11:44:31.633] INFO: 2 TBM Cores tbm08c (2 ON)
[11:44:31.633] INFO: TBM Core alpha (0): 7 registers set
[11:44:31.633] INFO: TBM Core beta (1): 7 registers set
[11:44:31.633] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[11:44:31.633] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:31.633] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:31.633] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:31.633] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:31.633] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:31.634] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:31.634] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:31.634] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:31.634] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:31.634] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:31.634] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:31.634] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:31.634] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:31.634] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:31.634] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:31.634] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:32.726] INFO: Test took 1092ms.
[11:44:32.726] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[11:44:32.727] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 13, 4 4
[11:44:32.727] INFO: The DUT currently contains the following objects:
[11:44:32.727] INFO: 2 TBM Cores tbm08c (2 ON)
[11:44:32.727] INFO: TBM Core alpha (0): 7 registers set
[11:44:32.727] INFO: TBM Core beta (1): 7 registers set
[11:44:32.727] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[11:44:32.727] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:32.727] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:32.727] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:32.727] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:32.727] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:32.727] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:32.727] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:32.727] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:32.727] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:32.727] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:32.727] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:32.727] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:32.727] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:32.727] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:32.727] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:32.727] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:33.819] INFO: Test took 1092ms.
[11:44:33.820] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[11:44:33.820] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 50, 5 5
[11:44:33.820] INFO: The DUT currently contains the following objects:
[11:44:33.820] INFO: 2 TBM Cores tbm08c (2 ON)
[11:44:33.820] INFO: TBM Core alpha (0): 7 registers set
[11:44:33.820] INFO: TBM Core beta (1): 7 registers set
[11:44:33.820] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[11:44:33.820] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:33.820] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:33.820] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:33.820] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:33.821] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:33.821] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:33.821] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:33.821] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:33.821] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:33.821] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:33.821] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:33.821] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:33.821] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:33.821] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:33.821] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:33.821] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:34.913] INFO: Test took 1092ms.
[11:44:34.914] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[11:44:34.914] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 8, 12, 6 6
[11:44:34.914] INFO: The DUT currently contains the following objects:
[11:44:34.914] INFO: 2 TBM Cores tbm08c (2 ON)
[11:44:34.914] INFO: TBM Core alpha (0): 7 registers set
[11:44:34.914] INFO: TBM Core beta (1): 7 registers set
[11:44:34.914] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[11:44:34.914] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:34.914] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:34.914] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:34.914] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:34.914] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:34.914] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:34.914] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:34.914] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:34.914] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:34.914] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:34.914] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:34.914] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:34.914] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:34.914] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:34.914] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:34.914] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:36.006] INFO: Test took 1092ms.
[11:44:36.007] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[11:44:36.007] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 8, 31, 7 7
[11:44:36.008] INFO: The DUT currently contains the following objects:
[11:44:36.008] INFO: 2 TBM Cores tbm08c (2 ON)
[11:44:36.008] INFO: TBM Core alpha (0): 7 registers set
[11:44:36.008] INFO: TBM Core beta (1): 7 registers set
[11:44:36.008] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[11:44:36.008] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:36.008] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:36.008] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:36.008] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:36.008] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:36.008] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:36.008] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:36.008] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:36.008] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:36.008] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:36.008] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:36.008] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:36.008] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:36.008] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:36.008] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:36.008] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:37.098] INFO: Test took 1090ms.
[11:44:37.099] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[11:44:37.099] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 13, 8 8
[11:44:37.099] INFO: The DUT currently contains the following objects:
[11:44:37.099] INFO: 2 TBM Cores tbm08c (2 ON)
[11:44:37.099] INFO: TBM Core alpha (0): 7 registers set
[11:44:37.099] INFO: TBM Core beta (1): 7 registers set
[11:44:37.099] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[11:44:37.099] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:37.099] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:37.099] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:37.099] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:37.099] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:37.099] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:37.099] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:37.099] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:37.099] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:37.099] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:37.100] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:37.100] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:37.100] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:37.100] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:37.100] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:37.100] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:38.190] INFO: Test took 1090ms.
[11:44:38.191] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[11:44:38.191] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 7, 9 9
[11:44:38.191] INFO: The DUT currently contains the following objects:
[11:44:38.191] INFO: 2 TBM Cores tbm08c (2 ON)
[11:44:38.191] INFO: TBM Core alpha (0): 7 registers set
[11:44:38.191] INFO: TBM Core beta (1): 7 registers set
[11:44:38.192] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[11:44:38.192] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:38.192] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:38.192] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:38.192] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:38.192] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:38.192] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:38.192] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:38.192] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:38.192] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:38.192] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:38.192] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:38.192] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:38.192] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:38.192] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:38.192] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:38.192] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:39.282] INFO: Test took 1090ms.
[11:44:39.283] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[11:44:39.283] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 5, 67, 10 10
[11:44:39.283] INFO: The DUT currently contains the following objects:
[11:44:39.283] INFO: 2 TBM Cores tbm08c (2 ON)
[11:44:39.283] INFO: TBM Core alpha (0): 7 registers set
[11:44:39.283] INFO: TBM Core beta (1): 7 registers set
[11:44:39.283] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[11:44:39.283] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:39.283] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:39.283] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:39.283] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:39.283] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:39.283] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:39.283] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:39.283] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:39.283] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:39.283] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:39.283] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:39.283] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:39.283] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:39.283] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:39.283] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:39.283] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:40.377] INFO: Test took 1094ms.
[11:44:40.377] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[11:44:40.378] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 4, 12, 11 11
[11:44:40.378] INFO: The DUT currently contains the following objects:
[11:44:40.378] INFO: 2 TBM Cores tbm08c (2 ON)
[11:44:40.378] INFO: TBM Core alpha (0): 7 registers set
[11:44:40.378] INFO: TBM Core beta (1): 7 registers set
[11:44:40.378] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[11:44:40.378] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:40.378] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:40.378] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:40.378] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:40.378] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:40.378] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:40.378] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:40.378] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:40.378] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:40.378] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:40.378] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:40.378] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:40.378] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:40.378] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:40.378] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:40.378] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:41.470] INFO: Test took 1092ms.
[11:44:41.471] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[11:44:41.471] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 5, 68, 12 12
[11:44:41.471] INFO: The DUT currently contains the following objects:
[11:44:41.471] INFO: 2 TBM Cores tbm08c (2 ON)
[11:44:41.471] INFO: TBM Core alpha (0): 7 registers set
[11:44:41.471] INFO: TBM Core beta (1): 7 registers set
[11:44:41.471] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[11:44:41.471] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:41.471] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:41.471] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:41.471] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:41.471] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:41.471] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:41.471] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:41.471] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:41.471] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:41.471] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:41.471] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:41.471] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:41.471] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:41.471] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:41.471] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:41.471] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:42.564] INFO: Test took 1093ms.
[11:44:42.565] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[11:44:42.565] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 20, 68, 13 13
[11:44:42.565] INFO: The DUT currently contains the following objects:
[11:44:42.565] INFO: 2 TBM Cores tbm08c (2 ON)
[11:44:42.565] INFO: TBM Core alpha (0): 7 registers set
[11:44:42.565] INFO: TBM Core beta (1): 7 registers set
[11:44:42.565] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[11:44:42.565] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:42.565] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:42.565] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:42.565] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:42.566] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:42.566] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:42.566] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:42.566] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:42.566] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:42.566] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:42.566] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:42.566] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:42.566] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:42.566] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:42.566] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:42.566] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:43.659] INFO: Test took 1093ms.
[11:44:43.659] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[11:44:43.660] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 6, 25, 14 14
[11:44:43.660] INFO: The DUT currently contains the following objects:
[11:44:43.660] INFO: 2 TBM Cores tbm08c (2 ON)
[11:44:43.660] INFO: TBM Core alpha (0): 7 registers set
[11:44:43.660] INFO: TBM Core beta (1): 7 registers set
[11:44:43.660] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[11:44:43.660] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:43.660] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:43.660] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:43.660] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:43.660] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:43.660] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:43.660] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:43.660] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:43.660] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:43.660] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:43.660] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:43.660] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:43.660] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:43.660] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:43.660] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:43.660] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:44.752] INFO: Test took 1092ms.
[11:44:44.753] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[11:44:44.753] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 60, 15 15
[11:44:44.753] INFO: The DUT currently contains the following objects:
[11:44:44.753] INFO: 2 TBM Cores tbm08c (2 ON)
[11:44:44.753] INFO: TBM Core alpha (0): 7 registers set
[11:44:44.753] INFO: TBM Core beta (1): 7 registers set
[11:44:44.753] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[11:44:44.753] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:44.753] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:44.753] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:44.753] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:44.753] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:44.753] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:44.753] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:44.753] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:44.753] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:44.753] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:44.753] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:44.753] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:44.753] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:44.753] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:44.753] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:44.753] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:44:45.847] INFO: Test took 1094ms.
[11:44:45.848] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[11:44:45.848] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 29 on ROC0
[11:44:45.848] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 31 on ROC1
[11:44:45.848] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 32 on ROC2
[11:44:45.848] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 31 on ROC3
[11:44:45.848] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 27 on ROC4
[11:44:45.848] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 33 on ROC5
[11:44:45.848] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 31 on ROC6
[11:44:45.848] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 30 on ROC7
[11:44:45.848] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 29 on ROC8
[11:44:45.848] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 31 on ROC9
[11:44:45.848] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 31 on ROC10
[11:44:45.848] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 31 on ROC11
[11:44:45.848] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 33 on ROC12
[11:44:45.848] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 32 on ROC13
[11:44:45.848] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 28 on ROC14
[11:44:45.848] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 30 on ROC15
[11:44:45.852] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:47:40.410] INFO: Test took 174558ms.
[11:47:41.964] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:50:34.253] INFO: Test took 172289ms.
[11:50:35.857] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[11:50:35.858] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip0
[11:50:35.858] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[11:50:35.858] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip1
[11:50:35.858] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[11:50:35.858] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip2
[11:50:35.858] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[11:50:35.859] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip3
[11:50:35.859] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[11:50:35.859] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip4
[11:50:35.859] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[11:50:35.859] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip5
[11:50:35.859] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[11:50:35.860] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip6
[11:50:35.860] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[11:50:35.860] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip7
[11:50:35.860] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[11:50:35.860] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip8
[11:50:35.860] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[11:50:35.861] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip9
[11:50:35.861] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[11:50:35.861] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip10
[11:50:35.861] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[11:50:35.862] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip11
[11:50:35.862] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[11:50:35.862] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip12
[11:50:35.862] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[11:50:35.862] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip13
[11:50:35.862] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[11:50:35.863] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip14
[11:50:35.863] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[11:50:35.863] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip15
[11:50:35.863] INFO: safety margin for low PH: adding 0, margin is now 20
[11:50:35.868] INFO: safety margin for low PH: adding 0, margin is now 20
[11:50:35.874] INFO: safety margin for low PH: adding 1, margin is now 21
[11:50:35.879] INFO: safety margin for low PH: adding 2, margin is now 22
[11:50:35.885] INFO: safety margin for low PH: adding 0, margin is now 20
[11:50:35.890] INFO: safety margin for low PH: adding 1, margin is now 21
[11:50:35.896] INFO: safety margin for low PH: adding 2, margin is now 22
[11:50:35.901] INFO: safety margin for low PH: adding 3, margin is now 23
[11:50:35.906] INFO: safety margin for low PH: adding 4, margin is now 24
[11:50:35.912] INFO: safety margin for low PH: adding 5, margin is now 25
[11:50:35.917] INFO: safety margin for low PH: adding 6, margin is now 26
[11:50:35.923] INFO: safety margin for low PH: adding 7, margin is now 27
[11:50:35.928] INFO: safety margin for low PH: adding 0, margin is now 20
[11:50:35.934] INFO: safety margin for low PH: adding 0, margin is now 20
[11:50:35.939] INFO: safety margin for low PH: adding 0, margin is now 20
[11:50:35.945] INFO: safety margin for low PH: adding 1, margin is now 21
[11:50:35.950] INFO: safety margin for low PH: adding 2, margin is now 22
[11:50:35.955] INFO: safety margin for low PH: adding 3, margin is now 23
[11:50:35.961] INFO: safety margin for low PH: adding 4, margin is now 24
[11:50:35.966] INFO: safety margin for low PH: adding 5, margin is now 25
[11:50:35.972] INFO: safety margin for low PH: adding 6, margin is now 26
[11:50:35.977] INFO: safety margin for low PH: adding 7, margin is now 27
[11:50:35.982] INFO: safety margin for low PH: adding 0, margin is now 20
[11:50:35.988] INFO: safety margin for low PH: adding 0, margin is now 20
[11:50:35.993] INFO: safety margin for low PH: adding 0, margin is now 20
[11:50:35.999] INFO: safety margin for low PH: adding 0, margin is now 20
[11:50:36.004] INFO: safety margin for low PH: adding 0, margin is now 20
[11:50:36.010] INFO: safety margin for low PH: adding 1, margin is now 21
[11:50:36.015] INFO: safety margin for low PH: adding 2, margin is now 22
[11:50:36.020] INFO: safety margin for low PH: adding 3, margin is now 23
[11:50:36.026] INFO: safety margin for low PH: adding 4, margin is now 24
[11:50:36.031] INFO: safety margin for low PH: adding 0, margin is now 20
[11:50:36.037] INFO: safety margin for low PH: adding 0, margin is now 20
[11:50:36.042] INFO: safety margin for low PH: adding 0, margin is now 20
[11:50:36.048] INFO: safety margin for low PH: adding 0, margin is now 20
[11:50:36.053] INFO: safety margin for low PH: adding 0, margin is now 20
[11:50:36.059] DEBUG: <PixTestPhOptimization.cc/doTest:L172> optimisation done
[11:50:36.107] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//dacParameters35_C0.dat
[11:50:36.108] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//dacParameters35_C1.dat
[11:50:36.108] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//dacParameters35_C2.dat
[11:50:36.108] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//dacParameters35_C3.dat
[11:50:36.108] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//dacParameters35_C4.dat
[11:50:36.108] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//dacParameters35_C5.dat
[11:50:36.108] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//dacParameters35_C6.dat
[11:50:36.108] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//dacParameters35_C7.dat
[11:50:36.108] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//dacParameters35_C8.dat
[11:50:36.108] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//dacParameters35_C9.dat
[11:50:36.109] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//dacParameters35_C10.dat
[11:50:36.109] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//dacParameters35_C11.dat
[11:50:36.109] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//dacParameters35_C12.dat
[11:50:36.109] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//dacParameters35_C13.dat
[11:50:36.109] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//dacParameters35_C14.dat
[11:50:36.109] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//dacParameters35_C15.dat
[11:50:39.814] INFO: Test took 3700ms.
[11:50:43.766] INFO: Test took 3672ms.
[11:50:47.768] INFO: Test took 3720ms.
[11:50:48.055] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:50:48.957] INFO: Test took 902ms.
[11:50:48.960] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:50:50.051] INFO: Test took 1091ms.
[11:50:50.055] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:50:51.145] INFO: Test took 1090ms.
[11:50:51.148] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:50:52.238] INFO: Test took 1090ms.
[11:50:52.241] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:50:53.333] INFO: Test took 1092ms.
[11:50:53.336] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:50:54.435] INFO: Test took 1099ms.
[11:50:54.438] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:50:55.528] INFO: Test took 1090ms.
[11:50:55.530] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:50:56.623] INFO: Test took 1093ms.
[11:50:56.626] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:50:57.717] INFO: Test took 1091ms.
[11:50:57.721] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:50:58.813] INFO: Test took 1092ms.
[11:50:58.816] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:50:59.908] INFO: Test took 1092ms.
[11:50:59.911] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:51:01.002] INFO: Test took 1091ms.
[11:51:01.006] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:51:02.097] INFO: Test took 1091ms.
[11:51:02.100] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:51:03.192] INFO: Test took 1092ms.
[11:51:03.196] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:51:04.287] INFO: Test took 1091ms.
[11:51:04.290] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:51:05.382] INFO: Test took 1092ms.
[11:51:05.385] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:51:06.477] INFO: Test took 1092ms.
[11:51:06.480] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:51:07.572] INFO: Test took 1092ms.
[11:51:07.575] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:51:08.667] INFO: Test took 1092ms.
[11:51:08.670] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:51:09.762] INFO: Test took 1092ms.
[11:51:09.765] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:51:10.858] INFO: Test took 1093ms.
[11:51:10.861] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:51:11.952] INFO: Test took 1091ms.
[11:51:11.956] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:51:13.048] INFO: Test took 1092ms.
[11:51:13.051] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:51:14.142] INFO: Test took 1091ms.
[11:51:14.145] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:51:15.235] INFO: Test took 1090ms.
[11:51:15.238] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:51:16.329] INFO: Test took 1091ms.
[11:51:16.332] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:51:17.423] INFO: Test took 1091ms.
[11:51:17.426] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:51:18.517] INFO: Test took 1091ms.
[11:51:18.520] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:51:19.612] INFO: Test took 1092ms.
[11:51:19.617] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:51:20.707] INFO: Test took 1091ms.
[11:51:20.710] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:51:21.800] INFO: Test took 1090ms.
[11:51:21.803] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:51:22.895] INFO: Test took 1092ms.
[11:51:23.481] INFO: PixTestPhOptimization::doTest() done, duration: 426 seconds
[11:51:23.481] INFO: PH scale (per ROC): 79 80 92 94 75 78 82 80 79 79 80 82 82 80 79 70
[11:51:23.481] INFO: PH offset (per ROC): 169 157 144 146 162 176 152 163 144 153 157 154 146 132 160 160
[11:51:23.626] DEBUG: <PixTestGainPedestal.cc/setParameter:L83> PixTestGainPedestal::PixTest() fVcalStep = 10
[11:51:23.627] INFO: ######################################################################
[11:51:23.627] INFO: PixTestGainPedestal::fullTest() ntrig = 10
[11:51:23.627] INFO: ######################################################################
[11:51:23.627] DEBUG: <PixTestGainPedestal.cc/measure:L192> using FLAGS = 16
[11:51:23.639] INFO: scanning low vcal = 10
[11:51:26.952] INFO: Test took 3313ms.
[11:51:26.956] INFO: scanning low vcal = 20
[11:51:30.276] INFO: Test took 3320ms.
[11:51:30.281] INFO: scanning low vcal = 30
[11:51:33.630] INFO: Test took 3349ms.
[11:51:33.640] INFO: scanning low vcal = 40
[11:51:37.371] INFO: Test took 3731ms.
[11:51:37.430] INFO: scanning low vcal = 50
[11:51:41.189] INFO: Test took 3758ms.
[11:51:41.250] INFO: scanning low vcal = 60
[11:51:45.023] INFO: Test took 3773ms.
[11:51:45.082] INFO: scanning low vcal = 70
[11:51:48.846] INFO: Test took 3764ms.
[11:51:48.906] INFO: scanning low vcal = 80
[11:51:52.667] INFO: Test took 3761ms.
[11:51:52.724] INFO: scanning low vcal = 90
[11:51:56.483] INFO: Test took 3759ms.
[11:51:56.544] INFO: scanning low vcal = 100
[11:52:00.312] INFO: Test took 3768ms.
[11:52:00.373] INFO: scanning low vcal = 110
[11:52:04.133] INFO: Test took 3760ms.
[11:52:04.191] INFO: scanning low vcal = 120
[11:52:07.979] INFO: Test took 3788ms.
[11:52:08.038] INFO: scanning low vcal = 130
[11:52:11.911] INFO: Test took 3873ms.
[11:52:11.974] INFO: scanning low vcal = 140
[11:52:15.841] INFO: Test took 3867ms.
[11:52:15.901] INFO: scanning low vcal = 150
[11:52:19.662] INFO: Test took 3761ms.
[11:52:19.722] INFO: scanning low vcal = 160
[11:52:23.479] INFO: Test took 3757ms.
[11:52:23.538] INFO: scanning low vcal = 170
[11:52:27.292] INFO: Test took 3754ms.
[11:52:27.360] INFO: scanning low vcal = 180
[11:52:31.116] INFO: Test took 3756ms.
[11:52:31.180] INFO: scanning low vcal = 190
[11:52:34.947] INFO: Test took 3767ms.
[11:52:35.006] INFO: scanning low vcal = 200
[11:52:38.769] INFO: Test took 3763ms.
[11:52:38.828] INFO: scanning low vcal = 210
[11:52:42.609] INFO: Test took 3781ms.
[11:52:42.668] INFO: scanning low vcal = 220
[11:52:46.425] INFO: Test took 3757ms.
[11:52:46.488] INFO: scanning low vcal = 230
[11:52:50.278] INFO: Test took 3790ms.
[11:52:50.340] INFO: scanning low vcal = 240
[11:52:54.114] INFO: Test took 3774ms.
[11:52:54.177] INFO: scanning low vcal = 250
[11:52:57.939] INFO: Test took 3762ms.
[11:52:58.005] INFO: scanning high vcal = 30 (= 210 in low range)
[11:53:01.765] INFO: Test took 3760ms.
[11:53:01.828] INFO: scanning high vcal = 50 (= 350 in low range)
[11:53:05.568] INFO: Test took 3740ms.
[11:53:05.630] INFO: scanning high vcal = 70 (= 490 in low range)
[11:53:09.381] INFO: Test took 3751ms.
[11:53:09.440] INFO: scanning high vcal = 90 (= 630 in low range)
[11:53:13.199] INFO: Test took 3759ms.
[11:53:13.256] INFO: scanning high vcal = 200 (= 1400 in low range)
[11:53:17.012] INFO: Test took 3756ms.
[11:53:17.553] INFO: PixTestGainPedestal::measure() done
[11:53:17.555] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C0
[11:53:17.555] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C1
[11:53:17.555] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C2
[11:53:17.556] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C3
[11:53:17.556] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C4
[11:53:17.556] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C5
[11:53:17.556] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C6
[11:53:17.556] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C7
[11:53:17.556] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C8
[11:53:17.557] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C9
[11:53:17.557] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C10
[11:53:17.557] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C11
[11:53:17.557] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C12
[11:53:17.557] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C13
[11:53:17.557] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C14
[11:53:17.557] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C15
[11:53:46.621] INFO: PixTestGainPedestal::fit() done
[11:53:46.621] INFO: non-linearity mean: 0.958 0.957 0.956 0.958 0.962 0.961 0.954 0.951 0.952 0.960 0.959 0.953 0.955 0.950 0.957 0.959
[11:53:46.621] INFO: non-linearity RMS: 0.006 0.005 0.004 0.005 0.006 0.005 0.005 0.006 0.006 0.005 0.005 0.006 0.005 0.006 0.005 0.006
[11:53:46.621] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//phCalibrationFitErr35_C0.dat
[11:53:46.639] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//phCalibrationFitErr35_C1.dat
[11:53:46.656] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//phCalibrationFitErr35_C2.dat
[11:53:46.673] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//phCalibrationFitErr35_C3.dat
[11:53:46.690] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//phCalibrationFitErr35_C4.dat
[11:53:46.707] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//phCalibrationFitErr35_C5.dat
[11:53:46.724] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//phCalibrationFitErr35_C6.dat
[11:53:46.741] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//phCalibrationFitErr35_C7.dat
[11:53:46.758] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//phCalibrationFitErr35_C8.dat
[11:53:46.775] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//phCalibrationFitErr35_C9.dat
[11:53:46.792] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//phCalibrationFitErr35_C10.dat
[11:53:46.809] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//phCalibrationFitErr35_C11.dat
[11:53:46.826] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//phCalibrationFitErr35_C12.dat
[11:53:46.843] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//phCalibrationFitErr35_C13.dat
[11:53:46.860] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//phCalibrationFitErr35_C14.dat
[11:53:46.876] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//002_Fulltest_m20//phCalibrationFitErr35_C15.dat
[11:53:46.893] INFO: PixTestGainPedestal::doTest() done, duration: 143 seconds
[11:53:46.893] DEBUG: <PixTestGainPedestal.cc/~PixTestGainPedestal:L125> PixTestGainPedestal dtor
[11:53:46.899] DEBUG: <PixTestFullTest.cc/~PixTestFullTest:L78> PixTestFullTest dtor
[11:53:46.899] INFO: enter test to run
[11:53:46.899] INFO: test: q no parameter change
[11:53:46.899] DEBUG: <PixMonitor.cc/dumpSummaries:L34> PixMonitor::dumpSummaries
[11:53:47.018] QUIET: Connection to board 107 closed.
[11:53:47.020] INFO: pXar: this is the end, my friend
[11:53:47.020] DEBUG: <PixSetup.cc/~PixSetup:L68> PixSetup free fPxarMemory