[10:12:55.521] INFO: *** Welcome to pxar ***
[10:12:55.521] INFO: *** Today: 2015/07/27
[10:12:55.521] INFO: readRocDacs: /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//dacParameters_C0.dat .. /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//dacParameters_C15.dat
[10:12:55.522] INFO: readTbmDacs: /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//tbmParameters_C0a.dat .. /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//tbmParameters_C0b.dat
[10:12:55.522] INFO: readMaskFile: /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//defaultMaskFile.dat
[10:12:55.522] INFO: readTrimFile: /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//trimParameters_C0.dat .. /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//trimParameters_C15.dat
[10:12:55.583] INFO: clk: 4
[10:12:55.583] INFO: ctr: 4
[10:12:55.583] INFO: sda: 19
[10:12:55.583] INFO: tin: 9
[10:12:55.583] INFO: level: 15
[10:12:55.583] INFO: triggerdelay: 0
[10:12:55.583] QUIET: Instanciating API for pxar v2.2.5+67~g3b1c276
[10:12:55.583] INFO: Log level: DEBUG
[10:12:55.593] INFO: Found DTB DTB_WV86BD
[10:12:55.603] QUIET: Connection to board DTB_WV86BD opened.
[10:12:55.606] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 111
HW version: DTB1.2
FW version: 4.2
SW version: 4.2
USB id: DTB_WV86BD
MAC address: 40D85511806F
Hostname: pixelDTB111
Comment:
------------------------------------------------------
[10:12:55.609] INFO: RPC call hashes of host and DTB match: 447413373
[10:12:57.135] INFO: DUT info:
[10:12:57.135] INFO: The DUT currently contains the following objects:
[10:12:57.135] INFO: 2 TBM Cores tbm08c (2 ON)
[10:12:57.135] INFO: TBM Core alpha (0): 7 registers set
[10:12:57.135] INFO: TBM Core beta (1): 7 registers set
[10:12:57.135] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[10:12:57.135] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[10:12:57.135] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[10:12:57.135] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[10:12:57.135] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[10:12:57.135] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[10:12:57.135] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[10:12:57.135] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[10:12:57.135] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[10:12:57.135] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[10:12:57.135] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[10:12:57.136] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[10:12:57.136] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[10:12:57.136] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[10:12:57.136] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[10:12:57.136] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[10:12:57.136] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->BB<-
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L107> dumpall: checkbox(0)
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L107> dumpproblematic: checkbox(0)
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 5
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L107> vcals: 250
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->BB2<-
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L107> vcals: 222
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L107> plwidth: 35
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L107> pix: 11,20
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L107> targetia: 24
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->BB3<-
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L107> dumpall: checkbox(0)
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L107> dumpproblematic: checkbox(0)
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 5
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L107> vcals: 250
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Cmd<-
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->DacDacScan<-
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L107> phmap: checkbox
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L107> dac1: caldel
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L107> dac1lo: 0
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L107> dac1hi: 255
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L107> dac2: vthrcomp
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L107> dac2lo: 0
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L107> dac2hi: 255
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L107> pix: 11,20
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->DacScan<-
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L107> phmap: checkbox(1)
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L107> allpixels: checkbox(0)
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L107> unmasked: checkbox(0)
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L107> dac: vcal
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L107> daclo: 0
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L107> dachi: 255
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L107> pix: 11,20
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->GainPedestal<-
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L107> showfits: checkbox(0)
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L107> extended: checkbox(0)
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L107> dumphists: checkbox(0)
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L107> vcalstep: 10
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L107> measure: button
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L107> fit: button
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L107> save: button
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->HighRate<-
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L107> pix: 11,20
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L107> maskhotpixels: button
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L107> savemaskfile: checkbox(0)
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L107> maskfilename: default
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L107> caldelscan: button
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L107> xpixelalive: button
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 50
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L107> vcal: 200
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L107> xnoisemaps: button
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L107> daclo: 0
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L107> dachi: 100
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L107> dacs/step: 20
[10:12:57.136] DEBUG: <PixTestParameters.cc/dump:L107> rundaq: button
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> trgfrequency(khz): 20
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> runseconds: 2
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> triggerdelay: 20
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> delaytbm: checkbox
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> filltree: checkbox
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->IV<-
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> port: /dev/FIXME
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> voltagestart: 0
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> voltagestop: 600
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> voltagestep: 5
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> delay: 1
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> compliance(ua): 100
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->PhOptimization<-
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> safetymarginlow: 20
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> saturationvcal: 100
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> quantilesaturation: 0.98
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->PixelAlive<-
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> vcal: 200
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> alivetest: button
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> masktest: button
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> addressdecodingtest: button
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Pretest<-
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> programroc: button
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> targetia: 24
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> setvana: button
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> iterations: 100
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> settimings: button
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> findworkingpixel: button
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> setvthrcompcaldel: button
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> pix: 11,20
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> vcal: 250
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> deltavthrcomp: 50
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> fraccaldel: 0.5
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 5
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> savedacs: button
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Readback<-
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> calibratevd: button
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> calibrateva: button
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> calibrateia: button
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> readbackvbg: button
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> getcalibratedvbg: button
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> usecalvd: checkbox(1)
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> usecalva: checkbox(0)
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> setvana: button
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Scurves<-
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> adjustvcal: checkbox(1)
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> dumpall: checkbox(0)
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> dumpproblematic: checkbox(0)
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> dumpoutputfile: checkbox(0)
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 50
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> dac: VthrComp
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> daclo: 0
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> dachi: 200
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> dacs/step: 10
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> scurves: button
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Timing<-
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> fastscan: checkbox(0)
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> targetclk: 4
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> clocksdascan: button
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> phasescan: button
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> levelscan: button
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> tbmphasescan: button
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> rocdelayscan: button
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> timingtest: button
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> saveparameters: button
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Trim<-
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> trim: button
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> vcal: 35
[10:12:57.137] DEBUG: <PixTestParameters.cc/dump:L107> trimbits: button
[10:12:57.138] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Xray<-
[10:12:57.138] DEBUG: <PixTestParameters.cc/dump:L107> maskhotpixels: button
[10:12:57.138] DEBUG: <PixTestParameters.cc/dump:L107> savemaskfile: checkbox(0)
[10:12:57.138] DEBUG: <PixTestParameters.cc/dump:L107> maskfilename: default
[10:12:57.138] DEBUG: <PixTestParameters.cc/dump:L107> source: Ag
[10:12:57.138] DEBUG: <PixTestParameters.cc/dump:L107> phrun: button
[10:12:57.138] DEBUG: <PixTestParameters.cc/dump:L107> runseconds: 100
[10:12:57.138] DEBUG: <PixTestParameters.cc/dump:L107> trgfrequency(khz): 100
[10:12:57.138] DEBUG: <PixTestParameters.cc/dump:L107> ratescan: button
[10:12:57.138] DEBUG: <PixTestParameters.cc/dump:L107> vthrcompmin: 10
[10:12:57.138] DEBUG: <PixTestParameters.cc/dump:L107> vthrcompmax: 80
[10:12:57.138] DEBUG: <PixTestParameters.cc/dump:L107> stepseconds: 5
[10:12:57.138] DEBUG: <PixTestParameters.cc/dump:L107> delaytbm: checkbox
[10:12:57.138] DEBUG: <PixTestParameters.cc/dump:L107> filltree: checkbox
[10:12:57.138] DEBUG: <PixSetup.cc/init:L81> PixSetup init start; getCurrentRSS() = 33902592
[10:12:57.138] DEBUG: <PixSetup.cc/init:L87> fPixTestParameters = 0x279a810
[10:12:57.138] DEBUG: <PixSetup.cc/init:L88> fConfigParameters = 0x26c39c0
[10:12:57.138] DEBUG: <PixSetup.cc/init:L89> fPxarMemory = 0x7fe86dd94010
[10:12:57.138] DEBUG: <PixSetup.cc/init:L90> fPxarMemHi = 0x7fe873fff510
[10:12:57.138] DEBUG: <PixSetup.cc/init:L106> PixSetup init done; getCurrentRSS() = 33964032 fPxarMemory = 0x7fe86dd94010
[10:12:57.138] DEBUG: <PixTestFactory.cc/PixTestFactory:L52> PixTestFactory::PixTestFactory()
[10:12:57.539] INFO: enter 'restricted' command line mode
[10:12:57.539] INFO: enter test to run
[10:12:57.539] INFO: test: Pretest no parameter change
[10:12:57.539] INFO: running: pretest
[10:12:57.544] INFO: ######################################################################
[10:12:57.544] INFO: PixTestPretest::doTest()
[10:12:57.544] INFO: ######################################################################
[10:12:57.546] INFO: ----------------------------------------------------------------------
[10:12:57.546] INFO: PixTestPretest::programROC()
[10:12:57.546] INFO: ----------------------------------------------------------------------
[10:13:15.567] INFO: PixTestPretest::programROC() done: ROCs are all programmable
[10:13:15.567] INFO: IA differences per ROC: 17.7 17.7 19.3 17.7 17.7 18.5 17.7 16.9 16.1 18.5 19.3 17.7 17.7 20.9 18.5 20.1
[10:13:15.639] INFO: ----------------------------------------------------------------------
[10:13:15.639] INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[10:13:15.639] INFO: ----------------------------------------------------------------------
[10:13:15.742] DEBUG: <PixTestPretest.cc/setVana:L254> offset current from other 15 ROCs is 67.7812 mA
[10:13:15.844] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 0 iter 0 Vana 78 Ia 22.2188 mA
[10:13:15.945] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 1 Vana 89 Ia 24.6187 mA
[10:13:16.046] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 2 Vana 86 Ia 23.8187 mA
[10:13:16.147] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 3 Vana 87 Ia 24.6187 mA
[10:13:16.247] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 4 Vana 84 Ia 23.8187 mA
[10:13:16.348] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 5 Vana 85 Ia 23.8187 mA
[10:13:16.449] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 6 Vana 86 Ia 23.8187 mA
[10:13:16.550] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 7 Vana 87 Ia 24.6187 mA
[10:13:16.650] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 8 Vana 84 Ia 23.8187 mA
[10:13:16.751] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 9 Vana 85 Ia 23.8187 mA
[10:13:16.851] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 10 Vana 86 Ia 23.8187 mA
[10:13:16.952] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 11 Vana 87 Ia 24.6187 mA
[10:13:17.054] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 1 iter 0 Vana 78 Ia 21.4188 mA
[10:13:17.155] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 1 Vana 94 Ia 25.4188 mA
[10:13:17.256] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 2 Vana 87 Ia 24.6187 mA
[10:13:17.356] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 3 Vana 84 Ia 23.8187 mA
[10:13:17.457] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 4 Vana 85 Ia 23.8187 mA
[10:13:17.558] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 5 Vana 86 Ia 23.8187 mA
[10:13:17.659] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 6 Vana 87 Ia 24.6187 mA
[10:13:17.759] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 7 Vana 84 Ia 23.8187 mA
[10:13:17.860] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 8 Vana 85 Ia 23.8187 mA
[10:13:17.961] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 9 Vana 86 Ia 23.8187 mA
[10:13:18.062] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 10 Vana 87 Ia 23.8187 mA
[10:13:18.163] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 11 Vana 88 Ia 24.6187 mA
[10:13:18.264] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 2 iter 0 Vana 78 Ia 23.0188 mA
[10:13:18.365] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 2 iter 1 Vana 84 Ia 24.6187 mA
[10:13:18.466] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 2 iter 2 Vana 81 Ia 24.6187 mA
[10:13:18.566] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 2 iter 3 Vana 78 Ia 23.8187 mA
[10:13:18.667] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 2 iter 4 Vana 79 Ia 23.8187 mA
[10:13:18.768] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 2 iter 5 Vana 80 Ia 23.8187 mA
[10:13:18.868] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 2 iter 6 Vana 81 Ia 24.6187 mA
[10:13:18.970] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 2 iter 7 Vana 78 Ia 23.8187 mA
[10:13:19.071] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 2 iter 8 Vana 79 Ia 23.8187 mA
[10:13:19.172] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 2 iter 9 Vana 80 Ia 23.8187 mA
[10:13:19.272] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 2 iter 10 Vana 81 Ia 24.6187 mA
[10:13:19.373] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 2 iter 11 Vana 78 Ia 23.8187 mA
[10:13:19.475] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 3 iter 0 Vana 78 Ia 21.4188 mA
[10:13:19.575] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 1 Vana 94 Ia 25.4188 mA
[10:13:19.676] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 2 Vana 87 Ia 23.8187 mA
[10:13:19.776] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 3 Vana 88 Ia 23.8187 mA
[10:13:19.877] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 4 Vana 89 Ia 23.8187 mA
[10:13:19.978] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 5 Vana 90 Ia 24.6187 mA
[10:13:20.079] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 6 Vana 87 Ia 23.8187 mA
[10:13:20.181] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 7 Vana 88 Ia 23.8187 mA
[10:13:20.281] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 8 Vana 89 Ia 24.6187 mA
[10:13:20.382] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 9 Vana 86 Ia 23.8187 mA
[10:13:20.483] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 10 Vana 87 Ia 23.8187 mA
[10:13:20.584] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 11 Vana 88 Ia 23.8187 mA
[10:13:20.685] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 4 iter 0 Vana 78 Ia 21.4188 mA
[10:13:20.786] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 4 iter 1 Vana 94 Ia 25.4188 mA
[10:13:20.886] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 4 iter 2 Vana 87 Ia 23.8187 mA
[10:13:20.987] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 4 iter 3 Vana 88 Ia 23.8187 mA
[10:13:21.088] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 4 iter 4 Vana 89 Ia 24.6187 mA
[10:13:21.189] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 4 iter 5 Vana 86 Ia 23.8187 mA
[10:13:21.289] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 4 iter 6 Vana 87 Ia 23.8187 mA
[10:13:21.390] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 4 iter 7 Vana 88 Ia 23.8187 mA
[10:13:21.491] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 4 iter 8 Vana 89 Ia 23.8187 mA
[10:13:21.592] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 4 iter 9 Vana 90 Ia 23.8187 mA
[10:13:21.693] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 4 iter 10 Vana 91 Ia 24.6187 mA
[10:13:21.794] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 4 iter 11 Vana 88 Ia 23.8187 mA
[10:13:21.895] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 5 iter 0 Vana 78 Ia 23.0188 mA
[10:13:21.996] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 1 Vana 84 Ia 23.8187 mA
[10:13:22.096] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 2 Vana 85 Ia 24.6187 mA
[10:13:22.197] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 3 Vana 82 Ia 23.8187 mA
[10:13:22.297] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 4 Vana 83 Ia 23.8187 mA
[10:13:22.398] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 5 Vana 84 Ia 23.8187 mA
[10:13:22.499] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 6 Vana 85 Ia 24.6187 mA
[10:13:22.600] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 7 Vana 82 Ia 23.8187 mA
[10:13:22.701] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 8 Vana 83 Ia 23.8187 mA
[10:13:22.801] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 9 Vana 84 Ia 24.6187 mA
[10:13:22.902] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 10 Vana 81 Ia 23.8187 mA
[10:13:23.003] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 11 Vana 82 Ia 23.8187 mA
[10:13:23.104] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 6 iter 0 Vana 78 Ia 22.2188 mA
[10:13:23.205] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 1 Vana 89 Ia 24.6187 mA
[10:13:23.306] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 2 Vana 86 Ia 23.8187 mA
[10:13:23.407] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 3 Vana 87 Ia 23.8187 mA
[10:13:23.508] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 4 Vana 88 Ia 23.8187 mA
[10:13:23.608] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 5 Vana 89 Ia 24.6187 mA
[10:13:23.709] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 6 Vana 86 Ia 23.8187 mA
[10:13:23.810] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 7 Vana 87 Ia 23.8187 mA
[10:13:23.911] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 8 Vana 88 Ia 23.8187 mA
[10:13:24.012] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 9 Vana 89 Ia 24.6187 mA
[10:13:24.112] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 10 Vana 86 Ia 23.8187 mA
[10:13:24.213] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 11 Vana 87 Ia 23.8187 mA
[10:13:24.314] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 7 iter 0 Vana 78 Ia 20.6188 mA
[10:13:24.415] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 7 iter 1 Vana 98 Ia 25.4188 mA
[10:13:24.516] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 7 iter 2 Vana 91 Ia 23.8187 mA
[10:13:24.617] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 7 iter 3 Vana 92 Ia 23.8187 mA
[10:13:24.717] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 7 iter 4 Vana 93 Ia 23.8187 mA
[10:13:24.818] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 7 iter 5 Vana 94 Ia 23.8187 mA
[10:13:24.918] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 7 iter 6 Vana 95 Ia 23.8187 mA
[10:13:25.019] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 7 iter 7 Vana 96 Ia 24.6187 mA
[10:13:25.120] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 7 iter 8 Vana 93 Ia 23.8187 mA
[10:13:25.220] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 7 iter 9 Vana 94 Ia 23.8187 mA
[10:13:25.321] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 7 iter 10 Vana 95 Ia 23.8187 mA
[10:13:25.422] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 7 iter 11 Vana 96 Ia 24.6187 mA
[10:13:25.523] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 8 iter 0 Vana 78 Ia 19.8187 mA
[10:13:25.624] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 8 iter 1 Vana 103 Ia 24.6187 mA
[10:13:25.724] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 8 iter 2 Vana 100 Ia 23.8187 mA
[10:13:25.825] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 8 iter 3 Vana 101 Ia 24.6187 mA
[10:13:25.926] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 8 iter 4 Vana 98 Ia 23.8187 mA
[10:13:26.027] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 8 iter 5 Vana 99 Ia 23.8187 mA
[10:13:26.127] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 8 iter 6 Vana 100 Ia 23.8187 mA
[10:13:26.228] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 8 iter 7 Vana 101 Ia 23.8187 mA
[10:13:26.329] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 8 iter 8 Vana 102 Ia 24.6187 mA
[10:13:26.430] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 8 iter 9 Vana 99 Ia 23.8187 mA
[10:13:26.531] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 8 iter 10 Vana 100 Ia 23.8187 mA
[10:13:26.632] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 8 iter 11 Vana 101 Ia 24.6187 mA
[10:13:26.734] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 9 iter 0 Vana 78 Ia 23.0188 mA
[10:13:26.835] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 9 iter 1 Vana 84 Ia 24.6187 mA
[10:13:26.935] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 9 iter 2 Vana 81 Ia 23.8187 mA
[10:13:27.036] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 9 iter 3 Vana 82 Ia 23.8187 mA
[10:13:27.137] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 9 iter 4 Vana 83 Ia 23.8187 mA
[10:13:27.238] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 9 iter 5 Vana 84 Ia 24.6187 mA
[10:13:27.339] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 9 iter 6 Vana 81 Ia 23.8187 mA
[10:13:27.439] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 9 iter 7 Vana 82 Ia 23.8187 mA
[10:13:27.540] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 9 iter 8 Vana 83 Ia 23.8187 mA
[10:13:27.642] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 9 iter 9 Vana 84 Ia 24.6187 mA
[10:13:27.742] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 9 iter 10 Vana 81 Ia 23.8187 mA
[10:13:27.843] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 9 iter 11 Vana 82 Ia 23.8187 mA
[10:13:27.945] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 10 iter 0 Vana 78 Ia 23.0188 mA
[10:13:28.046] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 1 Vana 84 Ia 24.6187 mA
[10:13:28.146] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 2 Vana 81 Ia 23.8187 mA
[10:13:28.247] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 3 Vana 82 Ia 23.8187 mA
[10:13:28.347] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 4 Vana 83 Ia 23.8187 mA
[10:13:28.448] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 5 Vana 84 Ia 23.8187 mA
[10:13:28.549] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 6 Vana 85 Ia 24.6187 mA
[10:13:28.650] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 7 Vana 82 Ia 23.8187 mA
[10:13:28.750] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 8 Vana 83 Ia 23.8187 mA
[10:13:28.851] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 9 Vana 84 Ia 23.8187 mA
[10:13:28.952] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 10 Vana 85 Ia 24.6187 mA
[10:13:29.053] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 11 Vana 82 Ia 23.8187 mA
[10:13:29.155] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 11 iter 0 Vana 78 Ia 21.4188 mA
[10:13:29.256] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter 1 Vana 94 Ia 24.6187 mA
[10:13:29.356] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter 2 Vana 91 Ia 24.6187 mA
[10:13:29.457] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter 3 Vana 88 Ia 23.8187 mA
[10:13:29.558] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter 4 Vana 89 Ia 23.8187 mA
[10:13:29.659] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter 5 Vana 90 Ia 24.6187 mA
[10:13:29.760] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter 6 Vana 87 Ia 23.8187 mA
[10:13:29.861] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter 7 Vana 88 Ia 23.8187 mA
[10:13:29.961] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter 8 Vana 89 Ia 23.8187 mA
[10:13:30.062] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter 9 Vana 90 Ia 23.8187 mA
[10:13:30.163] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter 10 Vana 91 Ia 24.6187 mA
[10:13:30.264] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter 11 Vana 88 Ia 23.8187 mA
[10:13:30.366] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 12 iter 0 Vana 78 Ia 21.4188 mA
[10:13:30.467] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter 1 Vana 94 Ia 25.4188 mA
[10:13:30.568] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter 2 Vana 87 Ia 23.8187 mA
[10:13:30.668] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter 3 Vana 88 Ia 23.8187 mA
[10:13:30.769] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter 4 Vana 89 Ia 23.8187 mA
[10:13:30.869] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter 5 Vana 90 Ia 23.8187 mA
[10:13:30.970] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter 6 Vana 91 Ia 24.6187 mA
[10:13:31.071] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter 7 Vana 88 Ia 23.8187 mA
[10:13:31.172] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter 8 Vana 89 Ia 23.8187 mA
[10:13:31.273] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter 9 Vana 90 Ia 24.6187 mA
[10:13:31.374] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter 10 Vana 87 Ia 23.8187 mA
[10:13:31.475] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter 11 Vana 88 Ia 23.8187 mA
[10:13:31.577] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 13 iter 0 Vana 78 Ia 24.6187 mA
[10:13:31.677] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 1 Vana 75 Ia 23.8187 mA
[10:13:31.778] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 2 Vana 76 Ia 23.8187 mA
[10:13:31.879] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 3 Vana 77 Ia 23.8187 mA
[10:13:31.979] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 4 Vana 78 Ia 24.6187 mA
[10:13:32.080] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 5 Vana 75 Ia 23.8187 mA
[10:13:32.181] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 6 Vana 76 Ia 23.8187 mA
[10:13:32.282] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 7 Vana 77 Ia 23.8187 mA
[10:13:32.382] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 8 Vana 78 Ia 24.6187 mA
[10:13:32.483] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 9 Vana 75 Ia 23.8187 mA
[10:13:32.583] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 10 Vana 76 Ia 23.8187 mA
[10:13:32.684] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 11 Vana 77 Ia 24.6187 mA
[10:13:32.786] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 14 iter 0 Vana 78 Ia 22.2188 mA
[10:13:32.886] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 1 Vana 89 Ia 25.4188 mA
[10:13:32.987] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 2 Vana 82 Ia 23.8187 mA
[10:13:33.088] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 3 Vana 83 Ia 23.8187 mA
[10:13:33.189] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 4 Vana 84 Ia 23.8187 mA
[10:13:33.290] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 5 Vana 85 Ia 24.6187 mA
[10:13:33.390] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 6 Vana 82 Ia 23.8187 mA
[10:13:33.491] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 7 Vana 83 Ia 23.8187 mA
[10:13:33.592] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 8 Vana 84 Ia 23.8187 mA
[10:13:33.692] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 9 Vana 85 Ia 23.8187 mA
[10:13:33.793] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 10 Vana 86 Ia 24.6187 mA
[10:13:33.893] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 11 Vana 83 Ia 23.8187 mA
[10:13:33.995] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 15 iter 0 Vana 78 Ia 23.0188 mA
[10:13:34.096] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 1 Vana 84 Ia 25.4188 mA
[10:13:34.197] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 2 Vana 77 Ia 23.0188 mA
[10:13:34.297] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 3 Vana 83 Ia 25.4188 mA
[10:13:34.398] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 4 Vana 76 Ia 23.0188 mA
[10:13:34.499] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 5 Vana 82 Ia 24.6187 mA
[10:13:34.599] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 6 Vana 79 Ia 23.8187 mA
[10:13:34.700] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 7 Vana 80 Ia 24.6187 mA
[10:13:34.800] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 8 Vana 77 Ia 23.0188 mA
[10:13:34.901] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 9 Vana 83 Ia 24.6187 mA
[10:13:34.002] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 10 Vana 80 Ia 24.6187 mA
[10:13:35.103] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 11 Vana 77 Ia 23.8187 mA
[10:13:35.148] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 0 Vana 87
[10:13:35.149] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 1 Vana 88
[10:13:35.149] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 2 Vana 78
[10:13:35.149] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 3 Vana 88
[10:13:35.149] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 4 Vana 88
[10:13:35.150] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 5 Vana 82
[10:13:35.150] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 6 Vana 87
[10:13:35.150] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 7 Vana 96
[10:13:35.150] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 8 Vana 101
[10:13:35.150] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 9 Vana 82
[10:13:35.150] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 10 Vana 82
[10:13:35.151] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 11 Vana 88
[10:13:35.151] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 12 Vana 88
[10:13:35.151] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 13 Vana 77
[10:13:35.151] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 14 Vana 83
[10:13:35.151] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 15 Vana 77
[10:13:35.254] INFO: PixTestPretest::setVana() done, Module Ia 394.7 mA = 24.6687 mA/ROC
[10:13:35.256] INFO: ----------------------------------------------------------------------
[10:13:35.256] INFO: PixTestPreTest::setTimings()
[10:13:35.256] INFO: ----------------------------------------------------------------------
[10:13:35.256] DEBUG: <PixTestPretest.cc/setTimings:L392> Testing Timing: Attempt #1
[10:13:36.221] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:13:36.221] INFO: Decoding statistics:
[10:13:36.221] INFO: General information:
[10:13:36.221] INFO: 16bit words read: 120
[10:13:36.221] INFO: valid events total: 10
[10:13:36.221] INFO: empty events: 10
[10:13:36.221] INFO: valid events with pixels: 0
[10:13:36.221] INFO: valid pixel hits: 0
[10:13:36.221] INFO: Event errors: 0
[10:13:36.221] INFO: start marker: 0
[10:13:36.221] INFO: stop marker: 0
[10:13:36.221] INFO: overflow: 0
[10:13:36.221] INFO: invalid 5bit words: 0
[10:13:36.221] INFO: invalid XOR eye diagram: 0
[10:13:36.221] INFO: TBM errors: 0
[10:13:36.221] INFO: flawed TBM headers: 0
[10:13:36.221] INFO: flawed TBM trailers: 0
[10:13:36.221] INFO: event ID mismatches: 0
[10:13:36.221] INFO: ROC errors: 0
[10:13:36.221] INFO: missing ROC header(s): 0
[10:13:36.221] INFO: misplaced readback start: 0
[10:13:36.221] INFO: Pixel decoding errors: 0
[10:13:36.221] INFO: pixel data incomplete: 0
[10:13:36.221] INFO: pixel address: 0
[10:13:36.221] INFO: pulse height fill bit: 0
[10:13:36.222] INFO: buffer corruption: 0
[10:13:36.222] INFO: ----------------------------------------------------------------------
[10:13:36.222] INFO: Default timings are good. No timing scan needed.
[10:13:36.222] INFO: ----------------------------------------------------------------------
[10:13:36.222] INFO: Test took 966 ms.
[10:13:36.222] INFO: PixTestPretest::setTimings() done.
[10:13:36.414] INFO: ----------------------------------------------------------------------
[10:13:36.414] INFO: PixTestPretest::findWorkingPixel()
[10:13:36.414] INFO: ----------------------------------------------------------------------
[10:13:43.741] INFO: Test took 7325ms.
[10:13:43.981] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C0 OK, with vthrComp = 111 and Delta(CalDel) = 63
[10:13:43.984] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C1 OK, with vthrComp = 101 and Delta(CalDel) = 61
[10:13:43.986] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C2 OK, with vthrComp = 87 and Delta(CalDel) = 60
[10:13:43.988] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C3 OK, with vthrComp = 98 and Delta(CalDel) = 59
[10:13:43.991] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C4 OK, with vthrComp = 64 and Delta(CalDel) = 62
[10:13:43.993] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C5 OK, with vthrComp = 113 and Delta(CalDel) = 63
[10:13:43.996] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C6 OK, with vthrComp = 111 and Delta(CalDel) = 58
[10:13:43.998] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C7 OK, with vthrComp = 79 and Delta(CalDel) = 58
[10:13:43.000] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C8 OK, with vthrComp = 111 and Delta(CalDel) = 62
[10:13:44.003] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C9 OK, with vthrComp = 95 and Delta(CalDel) = 60
[10:13:44.005] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C10 OK, with vthrComp = 111 and Delta(CalDel) = 59
[10:13:44.007] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C11 OK, with vthrComp = 99 and Delta(CalDel) = 59
[10:13:44.010] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C12 OK, with vthrComp = 106 and Delta(CalDel) = 62
[10:13:44.012] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C13 OK, with vthrComp = 110 and Delta(CalDel) = 58
[10:13:44.014] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C14 OK, with vthrComp = 85 and Delta(CalDel) = 64
[10:13:44.017] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C15 OK, with vthrComp = 100 and Delta(CalDel) = 61
[10:13:44.040] INFO: Found working pixel in all ROCs: col/row = 12/22
[10:13:44.089] INFO: ----------------------------------------------------------------------
[10:13:44.089] INFO: PixTestPretest::setVthrCompCalDel()
[10:13:44.089] INFO: ----------------------------------------------------------------------
[10:13:51.404] INFO: Test took 7310ms.
[10:13:51.466] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 134 +/- 31
[10:13:51.637] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 142 +/- 30.5
[10:13:51.640] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 126 +/- 30
[10:13:51.642] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 131 +/- 29.5
[10:13:51.644] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 145 +/- 30.5
[10:13:51.646] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 134 +/- 32
[10:13:51.649] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 123 +/- 29.5
[10:13:51.651] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 131 +/- 30
[10:13:51.653] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 130 +/- 31
[10:13:51.656] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 119 +/- 28.5
[10:13:51.658] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 122 +/- 29.5
[10:13:51.660] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 126 +/- 30.5
[10:13:51.663] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 137 +/- 30.5
[10:13:51.665] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 131 +/- 29
[10:13:51.667] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 144 +/- 31.5
[10:13:51.669] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 129 +/- 29.5
[10:13:51.721] INFO: PixTestPretest::setVthrCompCalDel() done
[10:13:51.721] INFO: CalDel: 134 142 126 131 145 134 123 131 130 119 122 126 137 131 144 129
[10:13:51.721] INFO: VthrComp: 52 51 51 51 51 56 53 51 55 51 51 51 51 51 51 51
[10:13:51.724] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//dacParameters_C0.dat
[10:13:51.725] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//dacParameters_C1.dat
[10:13:51.725] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//dacParameters_C2.dat
[10:13:51.725] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//dacParameters_C3.dat
[10:13:51.725] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//dacParameters_C4.dat
[10:13:51.725] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//dacParameters_C5.dat
[10:13:51.725] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//dacParameters_C6.dat
[10:13:51.725] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//dacParameters_C7.dat
[10:13:51.725] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//dacParameters_C8.dat
[10:13:51.725] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//dacParameters_C9.dat
[10:13:51.725] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//dacParameters_C10.dat
[10:13:51.725] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//dacParameters_C11.dat
[10:13:51.726] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//dacParameters_C12.dat
[10:13:51.726] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//dacParameters_C13.dat
[10:13:51.726] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//dacParameters_C14.dat
[10:13:51.726] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//dacParameters_C15.dat
[10:13:51.726] INFO: PixTestPretest::doTest() done, duration: 54 seconds
[10:13:51.726] DEBUG: <PixTestPretest.cc/~PixTestPretest:L134> PixTestPretest dtor
[10:13:51.799] INFO: enter test to run
[10:13:51.799] INFO: test: Fulltest no parameter change
[10:13:51.799] INFO: running: fulltest
[10:13:51.799] DEBUG: <PixTestFullTest.cc/init:L49> PixTestFullTest::init()
[10:13:51.799] DEBUG: <PixTestFullTest.cc/PixTestFullTest:L20> PixTestFullTest ctor(PixSetup &a, string, TGTab *)
[10:13:51.799] INFO: ######################################################################
[10:13:51.799] INFO: PixTestFullTest::doTest()
[10:13:51.799] INFO: ######################################################################
[10:13:51.799] DEBUG: <PixTestAlive.cc/init:L77> PixTestAlive::init()
[10:13:51.799] DEBUG: <PixTestAlive.cc/PixTestAlive:L21> PixTestAlive ctor(PixSetup &a, string, TGTab *)
[10:13:51.801] INFO: ######################################################################
[10:13:51.801] INFO: PixTestAlive::doTest()
[10:13:51.801] INFO: ######################################################################
[10:13:51.803] INFO: ----------------------------------------------------------------------
[10:13:51.803] 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:13:51.803] INFO: ----------------------------------------------------------------------
[10:13:51.805] DEBUG: <PixTest.cc/efficiencyMaps:L328> attempt #0
[10:13:55.522] INFO: Test took 3717ms.
[10:13:55.542] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:13:55.542] DEBUG: <PixTest.cc/efficiencyMaps:L339> eff result size = 66556
[10:13:55.542] DEBUG: <PixTest.cc/efficiencyMaps:L344> Create hists PixelAlive_C0 .. PixelAlive_C15
[10:13:55.782] INFO: PixTestAlive::aliveTest() done
[10:13:55.782] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 1 0 0 0 0 1 0 0 0 2
[10:13:55.782] DEBUG: <PixTestAlive.cc/aliveTest:L188> number of red-efficiency pixels: 0 0 0 0 0 0 1 0 0 0 0 1 0 0 0 3
[10:13:55.784] INFO: ----------------------------------------------------------------------
[10:13:55.784] 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:13:55.784] INFO: ----------------------------------------------------------------------
[10:13:55.786] DEBUG: <PixTest.cc/efficiencyMaps:L328> attempt #0
[10:13:58.447] INFO: Test took 2661ms.
[10:13:58.449] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:13:58.449] DEBUG: <PixTest.cc/efficiencyMaps:L339> eff result size = 0
[10:13:58.449] DEBUG: <PixTest.cc/efficiencyMaps:L344> Create hists MaskTest_C0 .. MaskTest_C15
[10:13:58.450] INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[10:13:58.689] INFO: PixTestAlive::maskTest() done
[10:13:58.689] 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:13:58.691] INFO: ----------------------------------------------------------------------
[10:13:58.691] 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:13:58.691] INFO: ----------------------------------------------------------------------
[10:13:58.693] DEBUG: <PixTest.cc/efficiencyMaps:L328> attempt #0
[10:14:02.413] INFO: Test took 3720ms.
[10:14:02.432] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:14:02.432] DEBUG: <PixTest.cc/efficiencyMaps:L339> eff result size = 66556
[10:14:02.432] DEBUG: <PixTest.cc/efficiencyMaps:L344> Create hists AddressDecodingTest_C0 .. AddressDecodingTest_C15
[10:14:02.675] INFO: PixTestAlive::addressDecodingTest() done
[10:14:02.675] 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:14:02.675] INFO: PixTestAlive::doTest() done, duration: 10 seconds
[10:14:02.675] DEBUG: <PixTestAlive.cc/~PixTestAlive:L109> PixTestAlive dtor
[10:14:02.680] DEBUG: <PixTestBBMap.cc/init:L79> PixTestBBMap::init()
[10:14:02.680] DEBUG: <PixTestBBMap.cc/PixTestBBMap:L27> PixTestBBMap ctor(PixSetup &a, string, TGTab *)
[10:14:02.682] INFO: ######################################################################
[10:14:02.682] INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[10:14:02.682] INFO: ######################################################################
[10:14:02.686] INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (30) hits flags = 2 (plus default)
[10:14:02.698] INFO: dacScan step from 0 .. 29
[10:14:02.698] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:14:20.612] INFO: Test took 17914ms.
[10:14:20.645] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:14:20.645] INFO: dacScan step from 30 .. 59
[10:14:20.645] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:14:39.568] INFO: Test took 18922ms.
[10:14:39.673] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:14:39.688] INFO: dacScan step from 60 .. 89
[10:14:39.688] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:15:03.513] INFO: Test took 23825ms.
[10:15:03.765] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:15:03.846] INFO: dacScan step from 90 .. 119
[10:15:03.846] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:15:28.449] INFO: Test took 24603ms.
[10:15:28.714] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:15:28.803] INFO: dacScan step from 120 .. 149
[10:15:28.804] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:15:52.403] INFO: Test took 23599ms.
[10:15:52.666] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:15:52.719] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[10:15:54.749] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[10:15:56.079] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[10:15:57.405] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[10:15:58.743] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[10:16:00.231] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[10:16:01.558] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[10:16:02.974] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[10:16:04.260] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[10:16:05.620] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[10:16:06.952] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[10:16:08.283] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[10:16:09.590] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[10:16:11.026] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[10:16:12.386] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[10:16:13.722] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[10:16:15.005] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 270618624
[10:16:15.052] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C0_V0
[10:16:15.053] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 101 (obtained for minval = 0) start: 101 .. 123 last peak: 61.328 last sigma: 6.24218 lcuts[0] = 80.0545 lcuts[1] = 123.75
[10:16:15.053] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C1_V0
[10:16:15.053] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 103 (obtained for minval = 0) start: 103 .. 126 last peak: 61.6967 last sigma: 6.47385 lcuts[0] = 81.1183 lcuts[1] = 126.435
[10:16:15.054] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C2_V0
[10:16:15.054] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 92 (obtained for minval = 0) start: 92 .. 112 last peak: 55.938 last sigma: 5.69807 lcuts[0] = 73.0322 lcuts[1] = 112.919
[10:16:15.054] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C3_V0
[10:16:15.055] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 93 (obtained for minval = 0) start: 93 .. 114 last peak: 53.5034 last sigma: 6.08473 lcuts[0] = 71.7576 lcuts[1] = 114.351
[10:16:15.055] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C4_V0
[10:16:15.056] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 76 (obtained for minval = 0) start: 76 .. 93 last peak: 43.9135 last sigma: 5.00047 lcuts[0] = 58.9149 lcuts[1] = 93.9182
[10:16:15.056] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C5_V0
[10:16:15.056] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 112 (obtained for minval = 0) start: 112 .. 136 last peak: 68.1201 last sigma: 6.82855 lcuts[0] = 88.6058 lcuts[1] = 136.406
[10:16:15.057] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C6_V0
[10:16:15.057] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 96 (obtained for minval = 0) start: 96 .. 118 last peak: 56.5447 last sigma: 6.15354 lcuts[0] = 75.0053 lcuts[1] = 118.08
[10:16:15.057] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C7_V0
[10:16:15.058] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 87 (obtained for minval = 0) start: 87 .. 106 last peak: 52.7438 last sigma: 5.35531 lcuts[0] = 68.8097 lcuts[1] = 106.297
[10:16:15.058] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C8_V0
[10:16:15.059] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 109 (obtained for minval = 0) start: 109 .. 135 last peak: 62.2336 last sigma: 7.31463 lcuts[0] = 84.1775 lcuts[1] = 135.38
[10:16:15.059] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C9_V0
[10:16:15.059] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 100 (obtained for minval = 0) start: 100 .. 122 last peak: 59.7447 last sigma: 6.31333 lcuts[0] = 78.6847 lcuts[1] = 122.878
[10:16:15.060] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C10_V0
[10:16:15.060] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 101 (obtained for minval = 0) start: 101 .. 125 last peak: 58.4447 last sigma: 6.69557 lcuts[0] = 78.5314 lcuts[1] = 125.4
[10:16:15.060] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C11_V0
[10:16:15.061] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 97 (obtained for minval = 0) start: 97 .. 118 last peak: 57.6882 last sigma: 6.11073 lcuts[0] = 76.0204 lcuts[1] = 118.795
[10:16:15.061] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C12_V0
[10:16:15.061] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 110 (obtained for minval = 0) start: 110 .. 134 last peak: 64.803 last sigma: 6.97253 lcuts[0] = 85.7206 lcuts[1] = 134.528
[10:16:15.062] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C13_V0
[10:16:15.062] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 109 (obtained for minval = 0) start: 109 .. 133 last peak: 65.7691 last sigma: 6.7824 lcuts[0] = 86.1163 lcuts[1] = 133.593
[10:16:15.062] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C14_V0
[10:16:15.063] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 102 (obtained for minval = 0) start: 102 .. 124 last peak: 60.5623 last sigma: 6.42624 lcuts[0] = 79.841 lcuts[1] = 124.825
[10:16:15.063] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C15_V0
[10:16:15.063] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 88 (obtained for minval = 0) start: 88 .. 108 last peak: 51.9399 last sigma: 5.6786 lcuts[0] = 68.9757 lcuts[1] = 108.726
[10:16:15.065] INFO: PixTestBBMap::doTest() done, duration: 132 seconds
[10:16:15.065] INFO: number of dead bumps (per ROC): 2 3 1 0 1 0 2 1 1 0 0 1 0 1 3 2
[10:16:15.065] INFO: separation cut (per ROC): 102 104 93 94 77 113 97 88 110 101 102 98 111 110 103 89
[10:16:15.065] DEBUG: <PixTestBBMap.cc/~PixTestBBMap:L97> PixTestBBMap dtor
[10:16:15.136] DEBUG: <PixTestScurves.cc/setParameter:L92> set fOutputFilename =
[10:16:15.138] INFO: ######################################################################
[10:16:15.138] INFO: PixTestScurves::fullTest() ntrig = 50
[10:16:15.138] INFO: ######################################################################
[10:16:15.139] INFO: ----------------------------------------------------------------------
[10:16:15.139] INFO: PixTestScurves::scurves(Vcal), ntrig = 50
[10:16:15.139] INFO: ----------------------------------------------------------------------
[10:16:15.139] INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 0 .. 149 (10) hits flags = 16 (plus default)
[10:16:15.152] INFO: dacScan step from 0 .. 9
[10:16:15.152] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
























[10:16:49.461] INFO: Test took 34309ms.
[10:16:49.529] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:16:49.529] INFO: dacScan step from 10 .. 19
[10:16:49.529] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:17:24.107] INFO: Test took 34578ms.
[10:17:24.173] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:17:24.173] INFO: dacScan step from 20 .. 29
[10:17:24.173] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0








[10:17:58.595] INFO: Test took 34422ms.
[10:17:58.664] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:17:58.664] INFO: dacScan step from 30 .. 39
[10:17:58.664] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:18:33.132] INFO: Test took 34468ms.
[10:18:33.198] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:18:33.199] INFO: dacScan step from 40 .. 49
[10:18:33.199] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0


[10:19:07.614] INFO: Test took 34415ms.
[10:19:07.682] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:19:07.682] INFO: dacScan step from 50 .. 59
[10:19:07.683] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0


[10:19:42.173] INFO: Test took 34490ms.
[10:19:42.253] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:19:42.254] INFO: dacScan step from 60 .. 69
[10:19:42.254] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:20:16.561] INFO: Test took 34307ms.
[10:20:16.631] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:20:16.631] INFO: dacScan step from 70 .. 79
[10:20:16.631] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0









[10:20:51.282] INFO: Test took 34651ms.
[10:20:51.357] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:20:51.358] INFO: dacScan step from 80 .. 89
[10:20:51.358] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0



















[10:21:27.488] DEBUG: <PixTest.cc/dacScan:L1518> attempt #1







[10:22:03.808] INFO: Test took 36320ms.
[10:22:03.978] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:22:03.983] INFO: dacScan step from 90 .. 99
[10:22:03.983] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0







[10:22:45.434] INFO: Test took 41451ms.
[10:22:45.764] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:22:45.778] INFO: dacScan step from 100 .. 109
[10:22:45.778] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0













[10:23:35.014] INFO: Test took 49236ms.
[10:23:35.492] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:23:35.515] INFO: dacScan step from 110 .. 119
[10:23:35.515] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0




[10:24:30.199] INFO: Test took 54684ms.
[10:24:30.789] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:24:30.820] INFO: dacScan step from 120 .. 129
[10:24:30.820] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0











[10:25:29.081] INFO: Test took 58261ms.
[10:25:29.676] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:25:29.709] INFO: dacScan step from 130 .. 139
[10:25:29.709] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0




[10:26:29.020] INFO: Test took 59310ms.
[10:26:29.600] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:26:29.632] INFO: dacScan step from 140 .. 149
[10:26:29.632] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0






















[10:27:26.755] INFO: Test took 57123ms.
[10:27:27.322] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:27:27.355] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[10:27:27.356] INFO: dumping ASCII scurve output file: SCurveData
[10:27:28.631] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[10:27:28.631] INFO: dumping ASCII scurve output file: SCurveData
[10:27:29.939] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[10:27:29.939] INFO: dumping ASCII scurve output file: SCurveData
[10:27:31.230] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[10:27:31.230] INFO: dumping ASCII scurve output file: SCurveData
[10:27:32.502] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[10:27:32.502] INFO: dumping ASCII scurve output file: SCurveData
[10:27:33.780] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[10:27:33.780] INFO: dumping ASCII scurve output file: SCurveData
[10:27:34.983] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[10:27:34.983] INFO: dumping ASCII scurve output file: SCurveData
[10:27:36.237] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[10:27:36.237] INFO: dumping ASCII scurve output file: SCurveData
[10:27:37.489] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[10:27:37.489] INFO: dumping ASCII scurve output file: SCurveData
[10:27:38.698] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[10:27:38.698] INFO: dumping ASCII scurve output file: SCurveData
[10:27:39.918] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[10:27:39.918] INFO: dumping ASCII scurve output file: SCurveData
[10:27:41.141] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[10:27:41.141] INFO: dumping ASCII scurve output file: SCurveData
[10:27:42.370] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[10:27:42.370] INFO: dumping ASCII scurve output file: SCurveData
[10:27:43.591] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[10:27:43.591] INFO: dumping ASCII scurve output file: SCurveData
[10:27:44.825] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[10:27:44.825] INFO: dumping ASCII scurve output file: SCurveData
[10:27:46.052] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[10:27:46.052] INFO: dumping ASCII scurve output file: SCurveData
[10:27:47.297] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 620101632
[10:27:47.343] INFO: PixTestScurves::scurves() done
[10:27:47.343] INFO: Vcal mean: 108.99 100.87 91.93 90.49 91.42 118.23 101.39 86.82 110.73 104.94 106.14 101.92 107.16 97.64 99.99 91.45
[10:27:47.343] INFO: Vcal RMS: 5.55 6.01 6.09 5.50 6.38 6.26 6.23 4.99 6.23 6.01 5.87 6.77 5.76 6.00 6.00 6.20
[10:27:47.344] INFO: PixTestScurves::fullTest() done, duration: 692 seconds
[10:27:47.344] DEBUG: <PixTestScurves.cc/~PixTestScurves:L141> PixTestScurves dtor
[10:27:47.408] INFO: ######################################################################
[10:27:47.408] INFO: PixTestTrim::doTest()
[10:27:47.408] INFO: ######################################################################
[10:27:47.409] INFO: ----------------------------------------------------------------------
[10:27:47.409] INFO: PixTestTrim::trimTest() ntrig = 10, vcal = 35
[10:27:47.409] INFO: ----------------------------------------------------------------------
[10:27:47.479] INFO: ---> VthrComp thr map (minimal VthrComp)
[10:27:47.479] INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 5 dacrange: 0 .. 159 (20) hits flags = 16 (plus default)
[10:27:47.489] INFO: dacScan step from 0 .. 19
[10:27:47.489] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:28:00.062] INFO: Test took 12573ms.
[10:28:00.085] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:28:00.085] INFO: dacScan step from 20 .. 39
[10:28:00.085] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:28:12.745] INFO: Test took 12660ms.
[10:28:12.770] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:28:12.770] INFO: dacScan step from 40 .. 59
[10:28:12.770] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:28:25.352] INFO: Test took 12582ms.
[10:28:25.376] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:28:25.376] INFO: dacScan step from 60 .. 79
[10:28:25.376] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:28:37.957] INFO: Test took 12581ms.
[10:28:37.982] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:28:37.982] INFO: dacScan step from 80 .. 99
[10:28:37.982] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:28:50.701] INFO: Test took 12719ms.
[10:28:50.741] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:28:50.744] INFO: dacScan step from 100 .. 119
[10:28:50.744] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:29:04.917] INFO: Test took 14173ms.
[10:29:05.044] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:29:05.067] INFO: dacScan step from 120 .. 139
[10:29:05.068] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:29:22.057] INFO: Test took 16989ms.
[10:29:22.220] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:29:22.257] INFO: dacScan step from 140 .. 159
[10:29:22.257] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:29:36.214] INFO: Test took 13957ms.
[10:29:36.301] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:29:36.315] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[10:29:37.561] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[10:29:38.742] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[10:29:39.883] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[10:29:41.066] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[10:29:42.139] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[10:29:43.337] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[10:29:44.502] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[10:29:45.655] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[10:29:46.844] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[10:29:48.048] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[10:29:49.257] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[10:29:50.453] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[10:29:51.770] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[10:29:52.001] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[10:29:54.177] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[10:29:55.344] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 620212224
[10:29:55.346] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 104.683 minThrLimit = 104.574 minThrNLimit = 129.466 -> result = 104.683 -> 104
[10:29:55.346] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 99.7818 minThrLimit = 99.7533 minThrNLimit = 119.247 -> result = 99.7818 -> 99
[10:29:55.347] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 91.5407 minThrLimit = 91.5126 minThrNLimit = 111.131 -> result = 91.5407 -> 91
[10:29:55.347] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 95.5832 minThrLimit = 95.574 minThrNLimit = 118.312 -> result = 95.5832 -> 95
[10:29:55.347] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 82.3824 minThrLimit = 82.3762 minThrNLimit = 99.224 -> result = 82.3824 -> 82
[10:29:55.348] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 109.989 minThrLimit = 109.856 minThrNLimit = 134.481 -> result = 109.989 -> 109
[10:29:55.348] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 99.583 minThrLimit = 99.5448 minThrNLimit = 118.844 -> result = 99.583 -> 99
[10:29:55.349] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 90.3737 minThrLimit = 90.3517 minThrNLimit = 112.667 -> result = 90.3737 -> 90
[10:29:55.349] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 106.269 minThrLimit = 106.029 minThrNLimit = 129.614 -> result = 106.269 -> 106
[10:29:55.349] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 101.269 minThrLimit = 101.244 minThrNLimit = 123.515 -> result = 101.269 -> 101
[10:29:55.350] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 101.915 minThrLimit = 101.866 minThrNLimit = 124.011 -> result = 101.915 -> 101
[10:29:55.350] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 97.6785 minThrLimit = 97.6563 minThrNLimit = 117.946 -> result = 97.6785 -> 97
[10:29:55.350] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 103.68 minThrLimit = 103.555 minThrNLimit = 127.317 -> result = 103.68 -> 103
[10:29:55.351] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 100.907 minThrLimit = 100.906 minThrNLimit = 128.568 -> result = 100.907 -> 100
[10:29:55.351] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 99.3252 minThrLimit = 99.3098 minThrNLimit = 120.691 -> result = 99.3252 -> 99
[10:29:55.351] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 93.7723 minThrLimit = 93.7502 minThrNLimit = 115.14 -> result = 93.7723 -> 93
[10:29:55.351] INFO: ROC 0 VthrComp = 104
[10:29:55.352] INFO: ROC 1 VthrComp = 99
[10:29:55.352] INFO: ROC 2 VthrComp = 91
[10:29:55.352] INFO: ROC 3 VthrComp = 95
[10:29:55.353] INFO: ROC 4 VthrComp = 82
[10:29:55.353] INFO: ROC 5 VthrComp = 109
[10:29:55.353] INFO: ROC 6 VthrComp = 99
[10:29:55.353] INFO: ROC 7 VthrComp = 90
[10:29:55.354] INFO: ROC 8 VthrComp = 106
[10:29:55.354] INFO: ROC 9 VthrComp = 101
[10:29:55.354] INFO: ROC 10 VthrComp = 101
[10:29:55.358] INFO: ROC 11 VthrComp = 97
[10:29:55.359] INFO: ROC 12 VthrComp = 103
[10:29:55.359] INFO: ROC 13 VthrComp = 100
[10:29:55.359] INFO: ROC 14 VthrComp = 99
[10:29:55.359] INFO: ROC 15 VthrComp = 93
[10:29:55.360] INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[10:29:55.360] INFO: ---> dac: vcal name: TrimThr1 ntrig: 5 dacrange: 0 .. 159 (20) hits flags = 16 (plus default)
[10:29:55.383] INFO: dacScan step from 0 .. 19
[10:29:55.384] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:30:08.008] INFO: Test took 12624ms.
[10:30:08.031] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:30:08.031] INFO: dacScan step from 20 .. 39
[10:30:08.031] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:30:20.723] INFO: Test took 12692ms.
[10:30:20.754] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:30:20.756] INFO: dacScan step from 40 .. 59
[10:30:20.756] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0


[10:30:35.873] INFO: Test took 15117ms.
[10:30:36.016] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:30:36.052] INFO: dacScan step from 60 .. 79
[10:30:36.052] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:30:53.210] INFO: Test took 17158ms.
[10:30:53.383] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:30:53.445] INFO: dacScan step from 80 .. 99
[10:30:53.446] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:31:10.516] INFO: Test took 17070ms.
[10:31:10.686] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:31:10.748] INFO: dacScan step from 100 .. 119
[10:31:10.748] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:31:27.389] INFO: Test took 16641ms.
[10:31:27.557] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:31:27.619] INFO: dacScan step from 120 .. 139
[10:31:27.619] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:31:45.903] INFO: Test took 18284ms.
[10:31:46.072] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:31:46.135] INFO: dacScan step from 140 .. 159
[10:31:46.135] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:32:03.472] INFO: Test took 17337ms.
[10:32:03.640] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:32:03.703] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[10:32:05.109] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[10:32:06.491] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[10:32:07.868] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[10:32:09.246] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[10:32:10.689] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[10:32:12.109] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[10:32:13.508] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[10:32:14.880] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[10:32:16.301] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[10:32:17.688] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[10:32:19.101] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[10:32:20.515] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[10:32:21.895] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[10:32:23.264] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[10:32:24.660] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[10:32:26.044] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 620212224
[10:32:26.046] INFO: roc 0 with ID = 0 has maximal Vcal 64.7049 for pixel 14/29 mean/min/max = 49.3161/33.7633/64.8688
[10:32:26.046] INFO: roc 1 with ID = 1 has maximal Vcal 61.8807 for pixel 0/13 mean/min/max = 46.6926/31.5017/61.8835
[10:32:26.046] INFO: roc 2 with ID = 2 has maximal Vcal 62.5762 for pixel 1/4 mean/min/max = 47.0527/31.5103/62.5952
[10:32:26.047] INFO: roc 3 with ID = 3 has maximal Vcal 58.4021 for pixel 2/7 mean/min/max = 45.3671/31.9222/58.8119
[10:32:26.047] INFO: roc 4 with ID = 4 has maximal Vcal 66.3083 for pixel 5/1 mean/min/max = 50.2717/34.1005/66.4429
[10:32:26.047] INFO: roc 5 with ID = 5 has maximal Vcal 69.6963 for pixel 23/2 mean/min/max = 52.3492/34.9212/69.7772
[10:32:26.047] INFO: roc 6 with ID = 6 has maximal Vcal 62.3668 for pixel 12/2 mean/min/max = 47.004/31.5857/62.4223
[10:32:26.048] INFO: roc 7 with ID = 7 has maximal Vcal 57.9931 for pixel 17/79 mean/min/max = 45.1858/32.2689/58.1027
[10:32:26.048] INFO: roc 8 with ID = 8 has maximal Vcal 68.5832 for pixel 18/1 mean/min/max = 50.9679/33.1294/68.8063
[10:32:26.049] INFO: roc 9 with ID = 9 has maximal Vcal 64.2814 for pixel 10/35 mean/min/max = 47.9385/31.5442/64.3328
[10:32:26.049] INFO: roc 10 with ID = 10 has maximal Vcal 65.1471 for pixel 51/1 mean/min/max = 48.6306/32.09/65.1711
[10:32:26.050] INFO: roc 11 with ID = 11 has maximal Vcal 64.9972 for pixel 12/7 mean/min/max = 48.38/31.3445/65.4156
[10:32:26.050] INFO: roc 12 with ID = 12 has maximal Vcal 63.5268 for pixel 22/73 mean/min/max = 48.1348/32.5388/63.7309
[10:32:26.050] INFO: roc 13 with ID = 13 has maximal Vcal 61.8597 for pixel 0/78 mean/min/max = 46.9495/31.9867/61.9123
[10:32:26.051] INFO: roc 14 with ID = 14 has maximal Vcal 60.9119 for pixel 25/77 mean/min/max = 46.0831/31.1569/61.0092
[10:32:26.051] INFO: roc 15 with ID = 15 has maximal Vcal 61.4234 for pixel 0/76 mean/min/max = 46.6272/31.7909/61.4635
[10:32:26.052] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.









[10:33:42.140] INFO: Test took 76088ms.
[10:33:42.923] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.0791 < 35 for itrim = 112; old thr = 33.8076 ... break
[10:33:42.948] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.2379 < 35 for itrim = 120; old thr = 32.6104 ... break
[10:33:42.970] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.018 < 35 for itrim = 103; old thr = 34.2519 ... break
[10:33:43.002] DEBUG: <PixTestTrim.cc/trimTest:L309> vtrim: vcal = 36.6533 < 35 for itrim+1 = 112; old thr = 34.3347 ... break
[10:33:43.021] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.1658 < 35 for itrim = 112; old thr = 32.9578 ... break
[10:33:43.042] DEBUG: <PixTestTrim.cc/trimTest:L309> vtrim: vcal = 35.3383 < 35 for itrim+1 = 125; old thr = 34.7797 ... break
[10:33:43.065] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.3406 < 35 for itrim = 115; old thr = 33.9029 ... break
[10:33:43.095] DEBUG: <PixTestTrim.cc/trimTest:L309> vtrim: vcal = 36.1137 < 35 for itrim+1 = 103; old thr = 34.8019 ... break
[10:33:43.121] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.3565 < 35 for itrim = 127; old thr = 34.3979 ... break
[10:33:43.151] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.0408 < 35 for itrim = 130; old thr = 33.8619 ... break
[10:33:43.172] DEBUG: <PixTestTrim.cc/trimTest:L309> vtrim: vcal = 36.9237 < 35 for itrim+1 = 113; old thr = 34.4419 ... break
[10:33:43.204] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.0906 < 35 for itrim = 134; old thr = 34.8611 ... break
[10:33:43.238] DEBUG: <PixTestTrim.cc/trimTest:L309> vtrim: vcal = 35.235 < 35 for itrim+1 = 130; old thr = 34.9498 ... break
[10:33:43.270] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.7005 < 35 for itrim = 113; old thr = 33.5223 ... break
[10:33:43.330] DEBUG: <PixTestTrim.cc/trimTest:L309> vtrim: vcal = 35.5269 < 35 for itrim+1 = 124; old thr = 34.6516 ... break
[10:33:43.355] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.5815 < 35 for itrim = 117; old thr = 33.6828 ... break
[10:33:43.418] INFO: ---> dac: vcal name: TrimThr2 ntrig: 10 dacrange: 0 .. 199 (20) hits flags = 16 (plus default)
[10:33:43.427] INFO: dacScan step from 0 .. 19
[10:33:43.428] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:34:02.012] INFO: Test took 18584ms.
[10:34:02.066] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:34:02.069] INFO: dacScan step from 20 .. 39
[10:34:02.069] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:34:24.864] INFO: Test took 22795ms.
[10:34:25.094] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:34:25.130] INFO: dacScan step from 40 .. 59
[10:34:25.130] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:34:52.590] INFO: Test took 27460ms.
[10:34:52.883] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:34:52.938] INFO: dacScan step from 60 .. 79
[10:34:52.939] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:35:20.614] INFO: Test took 27675ms.
[10:35:20.890] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:35:20.949] INFO: dacScan step from 80 .. 99
[10:35:20.949] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:35:48.529] INFO: Test took 27580ms.
[10:35:48.808] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:35:48.866] INFO: dacScan step from 100 .. 119
[10:35:48.867] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:36:16.424] INFO: Test took 27557ms.
[10:36:16.711] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:36:16.768] INFO: dacScan step from 120 .. 139
[10:36:16.768] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:36:45.987] INFO: Test took 29219ms.
[10:36:46.265] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:36:46.322] INFO: dacScan step from 140 .. 159
[10:36:46.323] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:37:14.111] INFO: Test took 27788ms.
[10:37:14.391] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:37:14.449] INFO: dacScan step from 160 .. 179
[10:37:14.449] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:37:41.520] INFO: Test took 27071ms.
[10:37:41.827] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:37:41.885] INFO: dacScan step from 180 .. 199
[10:37:41.886] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0


[10:38:09.878] INFO: Test took 27991ms.
[10:38:10.164] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:38:10.228] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[10:38:11.625] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[10:38:13.006] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[10:38:14.379] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[10:38:15.746] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[10:38:17.202] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[10:38:18.634] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[10:38:20.022] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[10:38:21.390] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[10:38:22.821] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[10:38:24.205] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[10:38:25.612] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[10:38:27.012] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[10:38:28.386] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[10:38:29.716] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[10:38:31.093] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[10:38:32.468] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 620244992
[10:38:32.470] INFO: ---> TrimStepCorr4 extremal thresholds: 0.000358 .. 255.000000
[10:38:32.533] INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 4 dacrange: 0 .. 255 (20) hits flags = 16 (plus default)
[10:38:32.543] INFO: dacScan step from 0 .. 19
[10:38:32.543] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:38:43.824] INFO: Test took 11281ms.
[10:38:43.846] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:38:43.846] INFO: dacScan step from 20 .. 39
[10:38:43.846] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:38:55.970] INFO: Test took 12124ms.
[10:38:56.055] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:38:56.073] INFO: dacScan step from 40 .. 59
[10:38:56.073] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:39:10.967] INFO: Test took 14894ms.
[10:39:11.120] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:39:11.176] INFO: dacScan step from 60 .. 79
[10:39:11.176] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:39:26.216] INFO: Test took 15040ms.
[10:39:26.360] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:39:26.417] INFO: dacScan step from 80 .. 99
[10:39:26.418] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:39:41.493] INFO: Test took 15075ms.
[10:39:41.637] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:39:41.696] INFO: dacScan step from 100 .. 119
[10:39:41.696] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:39:56.822] INFO: Test took 15126ms.
[10:39:56.973] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:39:57.028] INFO: dacScan step from 120 .. 139
[10:39:57.028] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:40:13.655] INFO: Test took 16627ms.
[10:40:13.799] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:40:13.853] INFO: dacScan step from 140 .. 159
[10:40:13.853] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0









[10:40:29.132] INFO: Test took 15279ms.
[10:40:29.280] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:40:29.334] INFO: dacScan step from 160 .. 179
[10:40:29.334] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:40:44.599] INFO: Test took 15265ms.
[10:40:44.741] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:40:44.795] INFO: dacScan step from 180 .. 199
[10:40:44.796] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:41:00.654] INFO: Test took 15858ms.
[10:41:00.803] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:41:00.858] INFO: dacScan step from 200 .. 219
[10:41:00.858] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:41:15.633] INFO: Test took 14775ms.
[10:41:15.781] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:41:15.849] INFO: dacScan step from 220 .. 239
[10:41:15.850] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:41:30.629] INFO: Test took 14779ms.
[10:41:30.772] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:41:30.828] INFO: dacScan step from 240 .. 255
[10:41:30.828] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0









[10:41:43.085] INFO: Test took 12257ms.
[10:41:43.205] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:41:43.251] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[10:41:45.009] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[10:41:46.743] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[10:41:48.491] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[10:41:50.232] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[10:41:52.055] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[10:41:53.853] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[10:41:55.598] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[10:41:57.358] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[10:41:59.127] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[10:42:00.862] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[10:42:02.585] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[10:42:04.312] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[10:42:06.030] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[10:42:07.813] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[10:42:09.548] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[10:42:11.295] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 620244992
[10:42:11.363] INFO: ---> TrimStepCorr2 extremal thresholds: 13.411364 .. 47.336919
[10:42:11.427] INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 4 dacrange: 3 .. 57 (20) hits flags = 16 (plus default)
[10:42:11.437] INFO: dacScan step from 3 .. 22
[10:42:11.437] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:42:22.831] INFO: Test took 11394ms.
[10:42:22.852] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:42:22.852] INFO: dacScan step from 23 .. 42
[10:42:22.853] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0


[10:42:35.612] INFO: Test took 12759ms.
[10:42:35.732] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:42:35.764] INFO: dacScan step from 43 .. 57
[10:42:35.764] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:42:47.659] INFO: Test took 11894ms.
[10:42:47.769] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:42:47.819] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[10:42:48.690] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[10:42:49.563] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[10:42:50.430] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[10:42:51.305] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[10:42:52.173] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[10:42:53.040] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[10:42:54.056] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[10:42:54.978] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[10:42:55.870] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[10:42:56.757] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[10:42:57.635] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[10:42:58.514] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[10:42:59.397] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[10:43:00.277] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[10:43:01.163] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[10:43:02.046] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 620363776
[10:43:02.112] INFO: ---> TrimStepCorr1a extremal thresholds: 3.500000 .. 63.995226
[10:43:02.175] INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 4 dacrange: 3 .. 73 (20) hits flags = 16 (plus default)
[10:43:02.184] INFO: dacScan step from 3 .. 22
[10:43:02.184] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:43:13.621] INFO: Test took 11437ms.
[10:43:13.645] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:43:13.645] INFO: dacScan step from 23 .. 42
[10:43:13.645] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:43:26.298] INFO: Test took 12653ms.
[10:43:26.396] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:43:26.421] INFO: dacScan step from 43 .. 62
[10:43:26.421] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:43:41.428] INFO: Test took 15007ms.
[10:43:41.645] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:43:41.704] INFO: dacScan step from 63 .. 73
[10:43:41.705] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:43:50.958] INFO: Test took 9252ms.
[10:43:51.039] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:43:51.072] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[10:43:52.065] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[10:43:53.053] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[10:43:54.042] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[10:43:55.028] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[10:43:56.018] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[10:43:57.009] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[10:43:58.003] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[10:43:58.985] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[10:43:59.971] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[10:44:00.964] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[10:44:01.949] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[10:44:02.936] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[10:44:03.918] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[10:44:04.904] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[10:44:05.890] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[10:44:06.877] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 620363776
[10:44:06.944] INFO: ---> TrimStepCorr1b extremal thresholds: 1.074119 .. 63.995226
[10:44:07.007] INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 4 dacrange: 1 .. 73 (20) hits flags = 16 (plus default)
[10:44:07.017] INFO: dacScan step from 1 .. 20
[10:44:07.017] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:44:18.480] INFO: Test took 11463ms.
[10:44:18.501] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:44:18.501] INFO: dacScan step from 21 .. 40
[10:44:18.501] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:44:30.674] INFO: Test took 12173ms.
[10:44:30.774] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:44:30.796] INFO: dacScan step from 41 .. 60
[10:44:30.796] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:44:45.659] INFO: Test took 14863ms.
[10:44:45.823] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:44:45.893] INFO: dacScan step from 61 .. 73
[10:44:45.894] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:44:56.275] INFO: Test took 10378ms.
[10:44:56.370] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:44:56.412] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[10:44:57.404] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[10:44:58.396] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[10:44:59.387] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[10:45:00.375] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[10:45:01.372] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[10:45:02.363] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[10:45:03.350] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[10:45:04.336] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[10:45:05.330] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[10:45:06.317] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[10:45:07.305] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[10:45:08.293] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[10:45:09.279] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[10:45:10.267] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[10:45:11.257] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[10:45:12.247] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 620367872
[10:45:12.319] INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[10:45:12.319] INFO: ---> dac: vcal name: TrimThrFinal ntrig: 10 dacrange: 15 .. 55 (20) hits flags = 16 (plus default)
[10:45:12.333] INFO: dacScan step from 15 .. 34
[10:45:12.333] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:45:31.114] INFO: Test took 18781ms.
[10:45:31.193] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:45:31.208] INFO: dacScan step from 35 .. 54
[10:45:31.208] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:45:57.556] INFO: Test took 26348ms.
[10:45:57.858] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:45:57.922] INFO: dacScan step from 55 .. 55
[10:45:57.922] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:46:01.693] INFO: Test took 3771ms.
[10:46:01.712] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:46:01.716] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[10:46:02.449] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[10:46:03.182] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[10:46:03.915] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[10:46:04.650] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[10:46:05.374] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[10:46:06.102] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[10:46:06.833] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[10:46:07.567] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[10:46:08.296] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[10:46:09.028] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[10:46:09.759] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[10:46:10.489] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[10:46:11.223] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[10:46:11.961] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[10:46:12.693] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[10:46:13.431] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 620367872
[10:46:13.485] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//dacParameters35_C0.dat
[10:46:13.485] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//dacParameters35_C1.dat
[10:46:13.485] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//dacParameters35_C2.dat
[10:46:13.485] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//dacParameters35_C3.dat
[10:46:13.485] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//dacParameters35_C4.dat
[10:46:13.485] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//dacParameters35_C5.dat
[10:46:13.485] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//dacParameters35_C6.dat
[10:46:13.485] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//dacParameters35_C7.dat
[10:46:13.485] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//dacParameters35_C8.dat
[10:46:13.486] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//dacParameters35_C9.dat
[10:46:13.486] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//dacParameters35_C10.dat
[10:46:13.486] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//dacParameters35_C11.dat
[10:46:13.486] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//dacParameters35_C12.dat
[10:46:13.486] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//dacParameters35_C13.dat
[10:46:13.486] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//dacParameters35_C14.dat
[10:46:13.486] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//dacParameters35_C15.dat
[10:46:13.486] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//trimParameters35_C0.dat
[10:46:13.495] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//trimParameters35_C1.dat
[10:46:13.501] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//trimParameters35_C2.dat
[10:46:13.507] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//trimParameters35_C3.dat
[10:46:13.512] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//trimParameters35_C4.dat
[10:46:13.518] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//trimParameters35_C5.dat
[10:46:13.523] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//trimParameters35_C6.dat
[10:46:13.528] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//trimParameters35_C7.dat
[10:46:13.534] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//trimParameters35_C8.dat
[10:46:13.539] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//trimParameters35_C9.dat
[10:46:13.545] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//trimParameters35_C10.dat
[10:46:13.550] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//trimParameters35_C11.dat
[10:46:13.555] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//trimParameters35_C12.dat
[10:46:13.561] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//trimParameters35_C13.dat
[10:46:13.566] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//trimParameters35_C14.dat
[10:46:13.571] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//trimParameters35_C15.dat
[10:46:13.577] INFO: PixTestTrim::trimTest() done
[10:46:13.577] INFO: vtrim: 112 120 103 112 112 125 115 103 127 130 113 134 130 113 124 117
[10:46:13.577] INFO: vthrcomp: 104 99 91 95 82 109 99 90 106 101 101 97 103 100 99 93
[10:46:13.577] INFO: vcal mean: 35.18 35.11 35.05 35.03 35.09 35.10 35.01 34.98 35.07 35.06 35.08 35.05 35.04 35.02 35.05 35.07
[10:46:13.577] INFO: vcal RMS: 1.24 1.19 1.11 1.08 1.36 1.31 1.46 0.97 1.18 1.14 3.59 1.51 1.23 1.00 1.11 1.50
[10:46:13.577] INFO: bits mean: 8.75 9.69 9.59 10.21 9.05 8.41 9.87 9.28 8.82 9.63 8.73 9.69 9.64 9.17 9.90 9.92
[10:46:13.577] INFO: bits RMS: 2.50 2.58 2.59 2.39 2.25 2.31 2.44 2.75 2.44 2.52 2.81 2.49 2.35 2.72 2.58 2.44
[10:46:13.588] INFO: ----------------------------------------------------------------------
[10:46:13.589] INFO: PixTestTrim::trimBitTest() ntrig = 10, vtrims = 254 126 63 32
[10:46:13.589] INFO: ----------------------------------------------------------------------
[10:46:13.596] DEBUG: <PixTestTrim.cc/trimBitTest:L518> trimBitTest determine threshold map without trims
[10:46:13.596] INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 10 dacrange: 0 .. 199 (20) hits flags = 16 (plus default)
[10:46:13.607] INFO: dacScan step from 0 .. 19
[10:46:13.607] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:46:31.762] INFO: Test took 18155ms.
[10:46:31.803] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:46:31.803] INFO: dacScan step from 20 .. 39
[10:46:31.803] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:46:50.476] INFO: Test took 18673ms.
[10:46:50.516] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:46:50.516] INFO: dacScan step from 40 .. 59
[10:46:50.516] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:47:09.148] INFO: Test took 18632ms.
[10:47:09.190] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:47:09.190] INFO: dacScan step from 60 .. 79
[10:47:09.191] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:47:27.864] INFO: Test took 18673ms.
[10:47:27.903] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:47:27.903] INFO: dacScan step from 80 .. 99
[10:47:27.903] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0


[10:47:46.572] INFO: Test took 18669ms.
[10:47:46.613] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:47:46.613] INFO: dacScan step from 100 .. 119
[10:47:46.613] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:48:05.990] INFO: Test took 19377ms.
[10:48:06.082] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:48:06.090] INFO: dacScan step from 120 .. 139
[10:48:06.090] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:48:30.899] INFO: Test took 24809ms.
[10:48:31.129] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:48:31.162] INFO: dacScan step from 140 .. 159
[10:48:31.162] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0


[10:48:57.606] INFO: Test took 26444ms.
[10:48:57.888] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:48:57.945] INFO: dacScan step from 160 .. 179
[10:48:57.946] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0









[10:49:25.960] INFO: Test took 28014ms.
[10:49:26.260] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:49:26.321] INFO: dacScan step from 180 .. 199
[10:49:26.321] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:49:54.320] INFO: Test took 27999ms.
[10:49:54.594] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:49:54.663] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[10:49:56.065] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[10:49:57.478] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[10:49:58.900] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[10:50:00.329] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[10:50:01.779] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[10:50:03.101] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[10:50:04.500] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[10:50:05.929] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[10:50:07.301] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[10:50:08.692] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[10:50:10.076] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[10:50:11.454] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[10:50:12.829] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[10:50:14.234] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[10:50:15.634] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[10:50:17.062] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 620384256
[10:50:17.062] DEBUG: <PixTestTrim.cc/trimBitTest:L533> trimBitTest initDUT with trim bits = 14
[10:50:17.126] DEBUG: <PixTestTrim.cc/trimBitTest:L539> trimBitTest threshold map with trim = 14
[10:50:17.126] INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 10 dacrange: 0 .. 193 (20) hits flags = 16 (plus default)
[10:50:17.140] INFO: dacScan step from 0 .. 19
[10:50:17.140] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:50:35.416] INFO: Test took 18276ms.
[10:50:35.454] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:50:35.454] INFO: dacScan step from 20 .. 39
[10:50:35.454] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:50:53.661] INFO: Test took 18207ms.
[10:50:53.699] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:50:53.699] INFO: dacScan step from 40 .. 59
[10:50:53.699] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0











[10:51:12.347] INFO: Test took 18648ms.
[10:51:12.389] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:12.389] INFO: dacScan step from 60 .. 79
[10:51:12.389] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:51:31.082] INFO: Test took 18693ms.
[10:51:31.124] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:31.124] INFO: dacScan step from 80 .. 99
[10:51:31.124] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0




















[10:51:49.837] INFO: Test took 18713ms.
[10:51:49.890] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:49.891] INFO: dacScan step from 100 .. 119
[10:51:49.891] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0











[10:52:10.931] INFO: Test took 21040ms.
[10:52:11.096] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:52:11.115] INFO: dacScan step from 120 .. 139
[10:52:11.115] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:52:38.022] INFO: Test took 26907ms.
[10:52:38.293] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:52:38.349] INFO: dacScan step from 140 .. 159
[10:52:38.349] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:53:05.841] INFO: Test took 27492ms.
[10:53:06.129] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:53:06.194] INFO: dacScan step from 160 .. 179
[10:53:06.194] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0


















[10:53:34.288] INFO: Test took 28094ms.
[10:53:34.571] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:53:34.632] INFO: dacScan step from 180 .. 193
[10:53:34.632] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:53:55.156] INFO: Test took 20524ms.
[10:53:55.353] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:53:55.398] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[10:53:56.753] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[10:53:58.140] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[10:53:59.540] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[10:54:00.934] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[10:54:02.342] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[10:54:03.667] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[10:54:05.036] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[10:54:06.444] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[10:54:07.797] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[10:54:09.170] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[10:54:10.546] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[10:54:11.945] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[10:54:13.329] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[10:54:14.724] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[10:54:16.112] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[10:54:17.521] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 620384256
[10:54:17.521] DEBUG: <PixTestTrim.cc/trimBitTest:L533> trimBitTest initDUT with trim bits = 13
[10:54:17.586] DEBUG: <PixTestTrim.cc/trimBitTest:L539> trimBitTest threshold map with trim = 13
[10:54:17.587] INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 10 dacrange: 0 .. 179 (20) hits flags = 16 (plus default)
[10:54:17.602] INFO: dacScan step from 0 .. 19
[10:54:17.603] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0




[10:54:36.270] INFO: Test took 18667ms.
[10:54:36.308] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:54:36.308] INFO: dacScan step from 20 .. 39
[10:54:36.309] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:54:54.909] INFO: Test took 18600ms.
[10:54:54.947] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:54:54.947] INFO: dacScan step from 40 .. 59
[10:54:54.948] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:55:13.182] INFO: Test took 18234ms.
[10:55:13.219] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:55:13.219] INFO: dacScan step from 60 .. 79
[10:55:13.219] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:55:31.644] INFO: Test took 18425ms.
[10:55:31.685] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:55:31.685] INFO: dacScan step from 80 .. 99
[10:55:31.685] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:55:50.344] INFO: Test took 18659ms.
[10:55:50.393] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:55:50.394] INFO: dacScan step from 100 .. 119
[10:55:50.394] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:56:11.385] INFO: Test took 20991ms.
[10:56:11.546] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:56:11.563] INFO: dacScan step from 120 .. 139
[10:56:11.563] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0


[10:56:37.868] INFO: Test took 26305ms.
[10:56:38.145] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:56:38.196] INFO: dacScan step from 140 .. 159
[10:56:38.196] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:57:06.122] INFO: Test took 27926ms.
[10:57:06.418] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:57:06.487] INFO: dacScan step from 160 .. 179
[10:57:06.487] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:57:34.299] INFO: Test took 27812ms.
[10:57:34.582] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:57:34.642] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[10:57:35.893] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[10:57:37.169] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[10:57:38.463] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[10:57:39.765] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[10:57:41.062] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[10:57:42.277] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[10:57:43.534] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[10:57:44.831] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[10:57:46.065] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[10:57:47.328] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[10:57:48.584] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[10:57:49.853] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[10:57:51.116] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[10:57:52.400] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[10:57:53.674] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[10:57:54.976] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 620384256
[10:57:54.977] DEBUG: <PixTestTrim.cc/trimBitTest:L533> trimBitTest initDUT with trim bits = 11
[10:57:55.042] DEBUG: <PixTestTrim.cc/trimBitTest:L539> trimBitTest threshold map with trim = 11
[10:57:55.042] INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 10 dacrange: 0 .. 179 (20) hits flags = 16 (plus default)
[10:57:55.058] INFO: dacScan step from 0 .. 19
[10:57:55.058] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:58:13.673] INFO: Test took 18615ms.
[10:58:13.722] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:58:13.722] INFO: dacScan step from 20 .. 39
[10:58:13.722] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0


[10:58:32.342] INFO: Test took 18620ms.
[10:58:32.383] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:58:32.383] INFO: dacScan step from 40 .. 59
[10:58:32.383] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:58:50.913] INFO: Test took 18530ms.
[10:58:50.955] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:58:50.955] INFO: dacScan step from 60 .. 79
[10:58:50.955] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0


[10:59:09.604] INFO: Test took 18649ms.
[10:59:09.643] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:59:09.643] INFO: dacScan step from 80 .. 99
[10:59:09.643] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:59:28.284] INFO: Test took 18641ms.
[10:59:28.333] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:59:28.334] INFO: dacScan step from 100 .. 119
[10:59:28.334] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:59:48.771] INFO: Test took 20437ms.
[10:59:48.937] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:59:48.953] INFO: dacScan step from 120 .. 139
[10:59:48.954] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0


[11:00:15.535] INFO: Test took 26581ms.
[11:00:15.812] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:00:15.859] INFO: dacScan step from 140 .. 159
[11:00:15.859] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:00:43.141] INFO: Test took 27282ms.
[11:00:43.435] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:00:43.497] INFO: dacScan step from 160 .. 179
[11:00:43.497] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:01:11.591] INFO: Test took 28094ms.
[11:01:11.871] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:01:11.931] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[11:01:13.177] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[11:01:14.456] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[11:01:15.755] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[11:01:17.057] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[11:01:18.357] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[11:01:19.575] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[11:01:20.836] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[11:01:22.139] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[11:01:23.370] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[11:01:24.633] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[11:01:25.892] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[11:01:27.165] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[11:01:28.433] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[11:01:29.720] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[11:01:30.002] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[11:01:32.309] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 620384256
[11:01:32.310] DEBUG: <PixTestTrim.cc/trimBitTest:L533> trimBitTest initDUT with trim bits = 7
[11:01:32.373] DEBUG: <PixTestTrim.cc/trimBitTest:L539> trimBitTest threshold map with trim = 7
[11:01:32.373] INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 10 dacrange: 0 .. 180 (20) hits flags = 16 (plus default)
[11:01:32.387] INFO: dacScan step from 0 .. 19
[11:01:32.387] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:01:50.950] INFO: Test took 18563ms.
[11:01:50.990] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:01:50.990] INFO: dacScan step from 20 .. 39
[11:01:50.990] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:02:09.570] INFO: Test took 18580ms.
[11:02:09.608] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:02:09.608] INFO: dacScan step from 40 .. 59
[11:02:09.609] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0


[11:02:28.123] INFO: Test took 18514ms.
[11:02:28.167] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:02:28.167] INFO: dacScan step from 60 .. 79
[11:02:28.167] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:02:46.745] INFO: Test took 18578ms.
[11:02:46.786] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:02:46.786] INFO: dacScan step from 80 .. 99
[11:02:46.786] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:03:05.437] INFO: Test took 18651ms.
[11:03:05.488] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:03:05.489] INFO: dacScan step from 100 .. 119
[11:03:05.489] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0









[11:03:25.817] INFO: Test took 20328ms.
[11:03:25.986] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:03:26.005] INFO: dacScan step from 120 .. 139
[11:03:26.005] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:03:52.931] INFO: Test took 26926ms.
[11:03:53.211] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:03:53.263] INFO: dacScan step from 140 .. 159
[11:03:53.263] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:04:20.608] INFO: Test took 27345ms.
[11:04:20.893] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:04:20.955] INFO: dacScan step from 160 .. 179
[11:04:20.955] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:04:49.267] INFO: Test took 28312ms.
[11:04:49.554] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:04:49.613] INFO: dacScan step from 180 .. 180
[11:04:49.613] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[11:04:53.397] INFO: Test took 3784ms.
[11:04:53.413] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:04:53.416] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[11:04:54.707] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[11:04:56.020] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[11:04:57.366] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[11:04:58.711] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[11:05:00.054] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[11:05:01.301] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[11:05:02.596] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[11:05:03.923] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[11:05:05.179] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[11:05:06.478] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[11:05:07.776] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[11:05:09.091] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[11:05:10.394] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[11:05:11.714] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[11:05:13.024] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[11:05:14.356] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 620384256
[11:05:14.356] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 0 step 0: thr difference mean: 11.7794, thr difference RMS: 1.55802
[11:05:14.357] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 1 step 0: thr difference mean: 10.5557, thr difference RMS: 1.44728
[11:05:14.357] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 2 step 0: thr difference mean: 9.96968, thr difference RMS: 1.66538
[11:05:14.357] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 3 step 0: thr difference mean: 8.6439, thr difference RMS: 1.55962
[11:05:14.357] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 4 step 0: thr difference mean: 10.3186, thr difference RMS: 1.58279
[11:05:14.357] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 5 step 0: thr difference mean: 12.2931, thr difference RMS: 1.73033
[11:05:14.357] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 6 step 0: thr difference mean: 11.3706, thr difference RMS: 1.45707
[11:05:14.358] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 7 step 0: thr difference mean: 8.25779, thr difference RMS: 1.43593
[11:05:14.358] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 8 step 0: thr difference mean: 10.9248, thr difference RMS: 1.22677
[11:05:14.358] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 9 step 0: thr difference mean: 11.415, thr difference RMS: 1.07434
[11:05:14.358] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 10 step 0: thr difference mean: 10.7283, thr difference RMS: 0.952257
[11:05:14.358] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 11 step 0: thr difference mean: 10.8495, thr difference RMS: 1.14968
[11:05:14.359] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 12 step 0: thr difference mean: 11.8442, thr difference RMS: 1.28116
[11:05:14.359] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 13 step 0: thr difference mean: 9.54362, thr difference RMS: 1.4298
[11:05:14.359] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 14 step 0: thr difference mean: 9.68809, thr difference RMS: 1.0766
[11:05:14.359] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 15 step 0: thr difference mean: 9.11638, thr difference RMS: 1.3272
[11:05:14.359] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 0 step 1: thr difference mean: 11.917, thr difference RMS: 1.26989
[11:05:14.359] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 1 step 1: thr difference mean: 10.6383, thr difference RMS: 1.11535
[11:05:14.360] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 2 step 1: thr difference mean: 10.1814, thr difference RMS: 1.43596
[11:05:14.360] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 3 step 1: thr difference mean: 8.7781, thr difference RMS: 1.29192
[11:05:14.360] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 4 step 1: thr difference mean: 10.1728, thr difference RMS: 1.31615
[11:05:14.360] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 5 step 1: thr difference mean: 12.3881, thr difference RMS: 1.33081
[11:05:14.360] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 6 step 1: thr difference mean: 11.3254, thr difference RMS: 0.986293
[11:05:14.361] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 7 step 1: thr difference mean: 8.2113, thr difference RMS: 1.13251
[11:05:14.361] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 8 step 1: thr difference mean: 10.9819, thr difference RMS: 1.22575
[11:05:14.361] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 9 step 1: thr difference mean: 11.505, thr difference RMS: 1.03676
[11:05:14.361] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 10 step 1: thr difference mean: 10.7927, thr difference RMS: 0.955711
[11:05:14.361] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 11 step 1: thr difference mean: 10.8332, thr difference RMS: 1.11359
[11:05:14.361] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 12 step 1: thr difference mean: 11.9368, thr difference RMS: 1.28333
[11:05:14.362] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 13 step 1: thr difference mean: 9.70201, thr difference RMS: 1.43256
[11:05:14.362] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 14 step 1: thr difference mean: 9.63415, thr difference RMS: 1.08382
[11:05:14.362] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 15 step 1: thr difference mean: 9.081, thr difference RMS: 1.31623
[11:05:14.362] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 0 step 2: thr difference mean: 12.1892, thr difference RMS: 1.27066
[11:05:14.362] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 1 step 2: thr difference mean: 10.8202, thr difference RMS: 1.1125
[11:05:14.363] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 2 step 2: thr difference mean: 10.4888, thr difference RMS: 1.44619
[11:05:14.363] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 3 step 2: thr difference mean: 8.91014, thr difference RMS: 1.27738
[11:05:14.363] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 4 step 2: thr difference mean: 10.1435, thr difference RMS: 1.32291
[11:05:14.363] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 5 step 2: thr difference mean: 12.479, thr difference RMS: 1.31582
[11:05:14.363] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 6 step 2: thr difference mean: 11.3525, thr difference RMS: 1.00317
[11:05:14.363] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 7 step 2: thr difference mean: 8.24889, thr difference RMS: 1.12197
[11:05:14.364] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 8 step 2: thr difference mean: 11.2877, thr difference RMS: 1.20234
[11:05:14.364] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 9 step 2: thr difference mean: 11.7185, thr difference RMS: 1.05043
[11:05:14.364] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 10 step 2: thr difference mean: 10.943, thr difference RMS: 0.932299
[11:05:14.364] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 11 step 2: thr difference mean: 10.9358, thr difference RMS: 1.1238
[11:05:14.364] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 12 step 2: thr difference mean: 12.2245, thr difference RMS: 1.25492
[11:05:14.364] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 13 step 2: thr difference mean: 9.79228, thr difference RMS: 1.48618
[11:05:14.365] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 14 step 2: thr difference mean: 9.76472, thr difference RMS: 1.09027
[11:05:14.365] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 15 step 2: thr difference mean: 9.14755, thr difference RMS: 1.3366
[11:05:14.365] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 0 step 3: thr difference mean: 12.3979, thr difference RMS: 1.26241
[11:05:14.365] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 1 step 3: thr difference mean: 10.943, thr difference RMS: 1.11115
[11:05:14.365] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 2 step 3: thr difference mean: 10.7618, thr difference RMS: 1.41564
[11:05:14.366] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 3 step 3: thr difference mean: 9.17574, thr difference RMS: 1.28526
[11:05:14.366] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 4 step 3: thr difference mean: 10.2037, thr difference RMS: 1.30648
[11:05:14.366] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 5 step 3: thr difference mean: 12.5676, thr difference RMS: 1.33108
[11:05:14.366] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 6 step 3: thr difference mean: 11.5147, thr difference RMS: 1.00499
[11:05:14.366] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 7 step 3: thr difference mean: 8.3962, thr difference RMS: 1.11023
[11:05:14.366] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 8 step 3: thr difference mean: 11.3558, thr difference RMS: 1.22199
[11:05:14.367] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 9 step 3: thr difference mean: 11.7603, thr difference RMS: 1.03859
[11:05:14.367] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 10 step 3: thr difference mean: 11.2492, thr difference RMS: 0.941804
[11:05:14.367] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 11 step 3: thr difference mean: 11.0222, thr difference RMS: 1.10395
[11:05:14.367] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 12 step 3: thr difference mean: 12.4213, thr difference RMS: 1.26018
[11:05:14.367] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 13 step 3: thr difference mean: 9.89785, thr difference RMS: 1.47191
[11:05:14.368] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 14 step 3: thr difference mean: 9.84588, thr difference RMS: 1.0956
[11:05:14.368] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 15 step 3: thr difference mean: 9.07948, thr difference RMS: 1.3233
[11:05:14.481] INFO: PixTestTrim::trimBitTest() done
[11:05:14.485] INFO: PixTestTrim::doTest() done, duration: 2247 seconds
[11:05:14.485] DEBUG: <PixTestTrim.cc/~PixTestTrim:L104> PixTestTrim dtor
[11:05:15.073] DEBUG: <PixTest.cc/setTestParameter:L569> setting ntrig to new value 10
[11:05:15.073] DEBUG: <PixTestPhOptimization.cc/setParameter:L37> setting fParNtrig ->10<- from sval = 10
[11:05:15.073] DEBUG: <PixTestPhOptimization.cc/setParameter:L42> setting fSafetyMarginLow ->20<- from sval = 20
[11:05:15.073] DEBUG: <PixTestPhOptimization.cc/setParameter:L48> setting fVcalMax ->100<- from sval = 100
[11:05:15.073] DEBUG: <PixTestPhOptimization.cc/setParameter:L53> setting fQuantMax ->0.98<- from sval = 0.98
[11:05:15.073] INFO: ######################################################################
[11:05:15.073] INFO: PixTestPhOptimization::doTest() Ntrig = 10
[11:05:15.073] INFO: ######################################################################
[11:05:15.074] DEBUG: <PixTest.cc/efficiencyMaps:L328> attempt #0
[11:05:18.811] INFO: Test took 3736ms.
[11:05:18.835] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:05:18.835] DEBUG: <PixTest.cc/efficiencyMaps:L339> eff result size = 66545
[11:05:18.835] DEBUG: <PixTest.cc/efficiencyMaps:L344> Create hists PixelAlive_C0 .. PixelAlive_C15
[11:05:18.838] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [0, 35, 26] has eff 0/10
[11:05:18.838] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [0, 35, 26]
[11:05:18.838] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [1, 32, 30] has eff 0/10
[11:05:18.838] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [1, 32, 30]
[11:05:18.838] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [4, 34, 18] has eff 5/10
[11:05:18.838] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [4, 34, 18]
[11:05:18.838] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [4, 0, 38] has eff 9/10
[11:05:18.838] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [4, 0, 38]
[11:05:18.838] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [4, 4, 76] has eff 0/10
[11:05:18.838] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [4, 4, 76]
[11:05:18.839] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [5, 47, 60] has eff 0/10
[11:05:18.839] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [5, 47, 60]
[11:05:18.839] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [6, 6, 11] has eff 0/10
[11:05:18.839] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [6, 6, 11]
[11:05:18.839] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [6, 30, 35] has eff 0/10
[11:05:18.839] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [6, 30, 35]
[11:05:18.839] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [6, 45, 37] has eff 0/10
[11:05:18.839] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [6, 45, 37]
[11:05:18.839] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [10, 37, 54] has eff 1/10
[11:05:18.839] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [10, 37, 54]
[11:05:18.839] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [10, 49, 61] has eff 0/10
[11:05:18.839] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [10, 49, 61]
[11:05:18.839] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [11, 36, 43] has eff 0/10
[11:05:18.839] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [11, 36, 43]
[11:05:18.839] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [11, 51, 50] has eff 0/10
[11:05:18.839] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [11, 51, 50]
[11:05:18.839] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [11, 46, 52] has eff 0/10
[11:05:18.839] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [11, 46, 52]
[11:05:18.840] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [12, 49, 31] has eff 0/10
[11:05:18.840] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [12, 49, 31]
[11:05:18.840] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [15, 43, 9] has eff 0/10
[11:05:18.840] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [15, 43, 9]
[11:05:18.840] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [15, 43, 10] has eff 0/10
[11:05:18.840] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [15, 43, 10]
[11:05:18.840] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [15, 51, 26] has eff 4/10
[11:05:18.840] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [15, 51, 26]
[11:05:18.840] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [15, 51, 54] has eff 0/10
[11:05:18.840] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [15, 51, 54]
[11:05:18.844] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L239> Number of bad pixels found: 19
[11:05:18.844] DEBUG: <PixTestPhOptimization.cc/doTest:L124> **********Ph range will be optimised on the whole ROC***********
[11:05:18.844] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L276> ROC type is newer than digv2
[11:05:18.844] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L277> ROC type is psi46digv21respin
[11:05:19.034] DEBUG: <PixTest.cc/phMaps:L264> attempt #0
[11:05:22.759] INFO: Test took 3725ms.
[11:05:22.826] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:05:22.826] DEBUG: <PixTest.cc/phMaps:L275> eff result size = 66545
[11:05:22.826] DEBUG: <PixTest.cc/phMaps:L282> Create hists maxphmap_C0 .. maxphmap_C15
[11:05:22.830] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 209.933
[11:05:22.830] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,9] phvalue 210
[11:05:22.830] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 210.236
[11:05:22.830] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,5] phvalue 210
[11:05:22.830] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 187.479
[11:05:22.830] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,5] phvalue 188
[11:05:22.830] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 220.122
[11:05:22.830] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,5] phvalue 220
[11:05:22.830] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 196.777
[11:05:22.830] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [4 ,16] phvalue 196
[11:05:22.830] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 205.682
[11:05:22.830] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,6] phvalue 206
[11:05:22.830] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 208.41
[11:05:22.830] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,15] phvalue 208
[11:05:22.831] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 215.133
[11:05:22.831] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [9 ,16] phvalue 215
[11:05:22.831] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 199.02
[11:05:22.831] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [4 ,6] phvalue 200
[11:05:22.831] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 198.214
[11:05:22.831] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,5] phvalue 199
[11:05:22.831] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 212.34
[11:05:22.831] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,6] phvalue 213
[11:05:22.831] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 195.997
[11:05:22.831] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,5] phvalue 195
[11:05:22.831] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 195.638
[11:05:22.831] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,5] phvalue 195
[11:05:22.831] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 211.349
[11:05:22.831] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [4 ,5] phvalue 212
[11:05:22.831] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 204.126
[11:05:22.831] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [4 ,5] phvalue 204
[11:05:22.832] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 196.183
[11:05:22.832] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,5] phvalue 196
[11:05:22.832] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L427> ROC type is newer than digv2
[11:05:22.832] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L428> ROC type is psi46digv21respin
[11:05:22.832] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L450> init_phScale=150, flag_minPh = 0, minph = 0
[11:05:22.840] DEBUG: <PixTest.cc/phMaps:L264> attempt #0
[11:05:26.592] INFO: Test took 3752ms.
[11:05:26.657] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:05:26.657] DEBUG: <PixTest.cc/phMaps:L275> eff result size = 66545
[11:05:26.657] DEBUG: <PixTest.cc/phMaps:L282> Create hists minphmap_C0 .. minphmap_C15
[11:05:26.660] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L457> result size 0

[11:05:26.661] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L484> done. init_phScale=155, flag_minPh = 1, minph = 63minph_roc = 2
[11:05:26.661] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 96.9421
[11:05:26.661] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [8 ,25] phvalue 97
[11:05:26.661] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 80.335
[11:05:26.661] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [4 ,12] phvalue 80
[11:05:26.661] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 67.1367
[11:05:26.661] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,12] phvalue 68
[11:05:26.661] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 107.629
[11:05:26.661] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,62] phvalue 107
[11:05:26.662] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 74.9093
[11:05:26.662] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [6 ,12] phvalue 75
[11:05:26.662] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 74.855
[11:05:26.662] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [4 ,8] phvalue 75
[11:05:26.662] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 96.7391
[11:05:26.662] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [4 ,62] phvalue 97
[11:05:26.662] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 97.6468
[11:05:26.662] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,13] phvalue 97
[11:05:26.662] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 77.734
[11:05:26.662] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,13] phvalue 78
[11:05:26.662] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 79.829
[11:05:26.662] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,32] phvalue 80
[11:05:26.662] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 91.8071
[11:05:26.662] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [4 ,49] phvalue 92
[11:05:26.662] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 78.8172
[11:05:26.662] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [6 ,24] phvalue 79
[11:05:26.663] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 82.2405
[11:05:26.663] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [10 ,6] phvalue 82
[11:05:26.663] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 98.9745
[11:05:26.663] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,24] phvalue 99
[11:05:26.663] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 79.2442
[11:05:26.663] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,68] phvalue 80
[11:05:26.663] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 69.2236
[11:05:26.663] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,67] phvalue 70
[11:05:26.665] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 8, 25, 0 0
[11:05:26.665] INFO: The DUT currently contains the following objects:
[11:05:26.665] INFO: 2 TBM Cores tbm08c (2 ON)
[11:05:26.665] INFO: TBM Core alpha (0): 7 registers set
[11:05:26.665] INFO: TBM Core beta (1): 7 registers set
[11:05:26.665] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[11:05:26.665] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:26.665] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:26.665] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:26.665] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:26.665] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:26.665] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:26.665] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:26.665] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:26.665] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:26.665] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:26.665] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:26.665] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:26.665] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:26.665] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:26.666] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:26.666] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:27.758] INFO: Test took 1092ms.
[11:05:27.759] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[11:05:27.759] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 4, 12, 1 1
[11:05:27.759] INFO: The DUT currently contains the following objects:
[11:05:27.759] INFO: 2 TBM Cores tbm08c (2 ON)
[11:05:27.759] INFO: TBM Core alpha (0): 7 registers set
[11:05:27.759] INFO: TBM Core beta (1): 7 registers set
[11:05:27.759] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[11:05:27.759] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:27.759] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:27.759] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:27.759] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:27.759] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:27.759] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:27.759] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:27.759] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:27.759] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:27.759] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:27.759] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:27.759] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:27.759] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:27.759] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:27.759] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:27.759] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:28.850] INFO: Test took 1091ms.
[11:05:28.851] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[11:05:28.851] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 12, 2 2
[11:05:28.851] INFO: The DUT currently contains the following objects:
[11:05:28.851] INFO: 2 TBM Cores tbm08c (2 ON)
[11:05:28.851] INFO: TBM Core alpha (0): 7 registers set
[11:05:28.851] INFO: TBM Core beta (1): 7 registers set
[11:05:28.851] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[11:05:28.851] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:28.851] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:28.851] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:28.851] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:28.851] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:28.851] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:28.851] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:28.851] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:28.851] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:28.851] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:28.851] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:28.851] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:28.852] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:28.852] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:28.852] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:28.852] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:29.949] INFO: Test took 1097ms.
[11:05:29.950] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[11:05:29.950] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 62, 3 3
[11:05:29.950] INFO: The DUT currently contains the following objects:
[11:05:29.950] INFO: 2 TBM Cores tbm08c (2 ON)
[11:05:29.950] INFO: TBM Core alpha (0): 7 registers set
[11:05:29.950] INFO: TBM Core beta (1): 7 registers set
[11:05:29.950] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[11:05:29.950] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:29.950] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:29.950] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:29.950] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:29.950] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:29.950] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:29.950] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:29.950] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:29.950] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:29.950] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:29.950] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:29.950] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:29.951] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:29.951] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:29.951] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:29.951] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:31.044] INFO: Test took 1093ms.
[11:05:31.045] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[11:05:31.045] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 6, 12, 4 4
[11:05:31.045] INFO: The DUT currently contains the following objects:
[11:05:31.045] INFO: 2 TBM Cores tbm08c (2 ON)
[11:05:31.045] INFO: TBM Core alpha (0): 7 registers set
[11:05:31.045] INFO: TBM Core beta (1): 7 registers set
[11:05:31.045] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[11:05:31.045] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:31.045] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:31.045] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:31.045] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:31.045] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:31.046] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:31.046] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:31.046] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:31.046] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:31.046] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:31.046] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:31.046] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:31.046] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:31.046] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:31.046] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:31.046] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:32.139] INFO: Test took 1093ms.
[11:05:32.140] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[11:05:32.141] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 4, 8, 5 5
[11:05:32.141] INFO: The DUT currently contains the following objects:
[11:05:32.141] INFO: 2 TBM Cores tbm08c (2 ON)
[11:05:32.141] INFO: TBM Core alpha (0): 7 registers set
[11:05:32.141] INFO: TBM Core beta (1): 7 registers set
[11:05:32.141] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[11:05:32.141] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:32.141] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:32.141] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:32.141] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:32.141] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:32.141] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:32.141] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:32.141] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:32.141] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:32.141] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:32.141] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:32.141] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:32.141] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:32.141] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:32.141] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:32.141] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:33.234] INFO: Test took 1093ms.
[11:05:33.235] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[11:05:33.235] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 4, 62, 6 6
[11:05:33.235] INFO: The DUT currently contains the following objects:
[11:05:33.236] INFO: 2 TBM Cores tbm08c (2 ON)
[11:05:33.236] INFO: TBM Core alpha (0): 7 registers set
[11:05:33.236] INFO: TBM Core beta (1): 7 registers set
[11:05:33.236] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[11:05:33.236] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:33.236] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:33.236] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:33.236] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:33.236] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:33.236] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:33.236] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:33.236] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:33.236] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:33.236] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:33.236] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:33.236] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:33.236] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:33.236] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:33.236] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:33.236] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:34.330] INFO: Test took 1094ms.
[11:05:34.330] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[11:05:34.331] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 13, 7 7
[11:05:34.331] INFO: The DUT currently contains the following objects:
[11:05:34.331] INFO: 2 TBM Cores tbm08c (2 ON)
[11:05:34.331] INFO: TBM Core alpha (0): 7 registers set
[11:05:34.331] INFO: TBM Core beta (1): 7 registers set
[11:05:34.331] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[11:05:34.331] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:34.331] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:34.331] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:34.331] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:34.331] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:34.331] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:34.331] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:34.331] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:34.331] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:34.331] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:34.331] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:34.331] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:34.331] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:34.331] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:34.331] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:34.331] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:35.424] INFO: Test took 1093ms.
[11:05:35.425] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[11:05:35.425] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 13, 8 8
[11:05:35.425] INFO: The DUT currently contains the following objects:
[11:05:35.425] INFO: 2 TBM Cores tbm08c (2 ON)
[11:05:35.425] INFO: TBM Core alpha (0): 7 registers set
[11:05:35.425] INFO: TBM Core beta (1): 7 registers set
[11:05:35.425] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[11:05:35.425] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:35.425] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:35.425] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:35.425] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:35.426] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:35.426] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:35.426] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:35.426] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:35.426] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:35.426] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:35.426] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:35.426] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:35.426] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:35.426] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:35.426] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:35.426] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:36.520] INFO: Test took 1094ms.
[11:05:36.520] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[11:05:36.521] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 32, 9 9
[11:05:36.521] INFO: The DUT currently contains the following objects:
[11:05:36.521] INFO: 2 TBM Cores tbm08c (2 ON)
[11:05:36.521] INFO: TBM Core alpha (0): 7 registers set
[11:05:36.521] INFO: TBM Core beta (1): 7 registers set
[11:05:36.521] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[11:05:36.521] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:36.521] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:36.521] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:36.521] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:36.521] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:36.521] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:36.521] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:36.521] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:36.521] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:36.521] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:36.521] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:36.521] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:36.521] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:36.521] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:36.521] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:36.521] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:37.615] INFO: Test took 1094ms.
[11:05:37.616] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[11:05:37.616] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 4, 49, 10 10
[11:05:37.616] INFO: The DUT currently contains the following objects:
[11:05:37.616] INFO: 2 TBM Cores tbm08c (2 ON)
[11:05:37.616] INFO: TBM Core alpha (0): 7 registers set
[11:05:37.616] INFO: TBM Core beta (1): 7 registers set
[11:05:37.616] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[11:05:37.616] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:37.616] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:37.616] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:37.616] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:37.616] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:37.616] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:37.616] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:37.616] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:37.616] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:37.616] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:37.616] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:37.616] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:37.616] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:37.616] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:37.616] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:37.616] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:38.710] INFO: Test took 1094ms.
[11:05:38.711] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[11:05:38.711] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 6, 24, 11 11
[11:05:38.711] INFO: The DUT currently contains the following objects:
[11:05:38.711] INFO: 2 TBM Cores tbm08c (2 ON)
[11:05:38.711] INFO: TBM Core alpha (0): 7 registers set
[11:05:38.711] INFO: TBM Core beta (1): 7 registers set
[11:05:38.711] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[11:05:38.711] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:38.711] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:38.711] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:38.711] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:38.711] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:38.711] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:38.711] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:38.711] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:38.711] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:38.711] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:38.711] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:38.711] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:38.711] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:38.711] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:38.711] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:38.711] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:39.806] INFO: Test took 1095ms.
[11:05:39.806] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[11:05:39.806] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 10, 6, 12 12
[11:05:39.806] INFO: The DUT currently contains the following objects:
[11:05:39.807] INFO: 2 TBM Cores tbm08c (2 ON)
[11:05:39.807] INFO: TBM Core alpha (0): 7 registers set
[11:05:39.807] INFO: TBM Core beta (1): 7 registers set
[11:05:39.807] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[11:05:39.807] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:39.807] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:39.807] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:39.807] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:39.807] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:39.807] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:39.807] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:39.807] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:39.807] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:39.807] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:39.807] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:39.807] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:39.807] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:39.807] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:39.807] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:39.807] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:40.899] INFO: Test took 1092ms.
[11:05:40.900] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[11:05:40.900] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 24, 13 13
[11:05:40.900] INFO: The DUT currently contains the following objects:
[11:05:40.900] INFO: 2 TBM Cores tbm08c (2 ON)
[11:05:40.900] INFO: TBM Core alpha (0): 7 registers set
[11:05:40.900] INFO: TBM Core beta (1): 7 registers set
[11:05:40.900] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[11:05:40.900] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:40.900] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:40.900] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:40.900] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:40.900] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:40.900] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:40.900] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:40.900] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:40.900] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:40.900] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:40.900] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:40.900] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:40.900] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:40.900] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:40.900] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:40.900] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:41.993] INFO: Test took 1093ms.
[11:05:41.994] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[11:05:41.994] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 68, 14 14
[11:05:41.994] INFO: The DUT currently contains the following objects:
[11:05:41.994] INFO: 2 TBM Cores tbm08c (2 ON)
[11:05:41.994] INFO: TBM Core alpha (0): 7 registers set
[11:05:41.994] INFO: TBM Core beta (1): 7 registers set
[11:05:41.995] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[11:05:41.995] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:41.995] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:41.995] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:41.995] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:41.995] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:41.995] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:41.995] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:41.995] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:41.995] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:41.995] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:41.995] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:41.995] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:41.995] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:41.995] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:41.995] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:41.995] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:43.089] INFO: Test took 1094ms.
[11:05:43.090] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[11:05:43.090] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 67, 15 15
[11:05:43.090] INFO: The DUT currently contains the following objects:
[11:05:43.090] INFO: 2 TBM Cores tbm08c (2 ON)
[11:05:43.090] INFO: TBM Core alpha (0): 7 registers set
[11:05:43.090] INFO: TBM Core beta (1): 7 registers set
[11:05:43.090] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[11:05:43.090] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:43.090] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:43.090] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:43.090] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:43.090] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:43.090] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:43.090] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:43.090] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:43.090] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:43.090] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:43.090] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:43.090] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:43.090] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:43.090] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:43.090] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:43.091] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:05:44.184] INFO: Test took 1093ms.
[11:05:44.185] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[11:05:44.185] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 28 on ROC0
[11:05:44.185] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 31 on ROC1
[11:05:44.185] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 33 on ROC2
[11:05:44.185] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 35 on ROC3
[11:05:44.185] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 29 on ROC4
[11:05:44.185] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 31 on ROC5
[11:05:44.185] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 30 on ROC6
[11:05:44.185] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 31 on ROC7
[11:05:44.185] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 28 on ROC8
[11:05:44.185] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 32 on ROC9
[11:05:44.185] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 32 on ROC10
[11:05:44.185] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 30 on ROC11
[11:05:44.185] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 31 on ROC12
[11:05:44.185] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 32 on ROC13
[11:05:44.185] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 33 on ROC14
[11:05:44.185] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 33 on ROC15
[11:05:44.190] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.




[11:08:39.511] INFO: Test took 175321ms.
[11:08:41.098] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.




[11:11:36.297] INFO: Test took 175199ms.
[11:11:37.933] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[11:11:37.933] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip0
[11:11:37.933] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[11:11:37.933] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip1
[11:11:37.933] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[11:11:37.934] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip2
[11:11:37.934] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[11:11:37.934] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip3
[11:11:37.934] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[11:11:37.935] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip4
[11:11:37.935] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[11:11:37.935] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip5
[11:11:37.935] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[11:11:37.936] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip6
[11:11:37.936] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[11:11:37.937] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip7
[11:11:37.937] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[11:11:37.937] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip8
[11:11:37.937] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[11:11:37.937] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip9
[11:11:37.937] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[11:11:37.938] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip10
[11:11:37.938] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[11:11:37.938] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip11
[11:11:37.938] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[11:11:37.939] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip12
[11:11:37.939] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[11:11:37.939] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip13
[11:11:37.939] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[11:11:37.939] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip14
[11:11:37.939] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[11:11:37.940] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip15
[11:11:37.940] INFO: safety margin for low PH: adding 0, margin is now 20
[11:11:37.947] INFO: safety margin for low PH: adding 0, margin is now 20
[11:11:37.953] INFO: safety margin for low PH: adding 0, margin is now 20
[11:11:37.961] INFO: safety margin for low PH: adding 0, margin is now 20
[11:11:37.969] INFO: safety margin for low PH: adding 0, margin is now 20
[11:11:37.978] INFO: safety margin for low PH: adding 0, margin is now 20
[11:11:37.985] INFO: safety margin for low PH: adding 1, margin is now 21
[11:11:37.991] INFO: safety margin for low PH: adding 2, margin is now 22
[11:11:37.998] INFO: safety margin for low PH: adding 3, margin is now 23
[11:11:38.004] INFO: safety margin for low PH: adding 4, margin is now 24
[11:11:38.010] INFO: safety margin for low PH: adding 5, margin is now 25
[11:11:38.018] INFO: safety margin for low PH: adding 6, margin is now 26
[11:11:38.024] INFO: safety margin for low PH: adding 7, margin is now 27
[11:11:38.030] INFO: safety margin for low PH: adding 8, margin is now 28
[11:11:38.037] INFO: safety margin for low PH: adding 0, margin is now 20
[11:11:38.044] INFO: safety margin for low PH: adding 0, margin is now 20
[11:11:38.051] INFO: safety margin for low PH: adding 0, margin is now 20
[11:11:38.057] INFO: safety margin for low PH: adding 0, margin is now 20
[11:11:38.063] INFO: safety margin for low PH: adding 0, margin is now 20
[11:11:38.070] INFO: safety margin for low PH: adding 0, margin is now 20
[11:11:38.077] INFO: safety margin for low PH: adding 1, margin is now 21
[11:11:38.084] INFO: safety margin for low PH: adding 2, margin is now 22
[11:11:38.090] INFO: safety margin for low PH: adding 3, margin is now 23
[11:11:38.097] INFO: safety margin for low PH: adding 4, margin is now 24
[11:11:38.104] INFO: safety margin for low PH: adding 5, margin is now 25
[11:11:38.110] INFO: safety margin for low PH: adding 6, margin is now 26
[11:11:38.117] INFO: safety margin for low PH: adding 7, margin is now 27
[11:11:38.124] INFO: safety margin for low PH: adding 8, margin is now 28
[11:11:38.130] INFO: safety margin for low PH: adding 0, margin is now 20
[11:11:38.137] INFO: safety margin for low PH: adding 0, margin is now 20
[11:11:38.143] INFO: safety margin for low PH: adding 0, margin is now 20
[11:11:38.150] INFO: safety margin for low PH: adding 0, margin is now 20
[11:11:38.157] DEBUG: <PixTestPhOptimization.cc/doTest:L172> optimisation done
[11:11:38.210] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//dacParameters35_C0.dat
[11:11:38.210] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//dacParameters35_C1.dat
[11:11:38.210] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//dacParameters35_C2.dat
[11:11:38.211] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//dacParameters35_C3.dat
[11:11:38.211] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//dacParameters35_C4.dat
[11:11:38.211] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//dacParameters35_C5.dat
[11:11:38.211] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//dacParameters35_C6.dat
[11:11:38.211] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//dacParameters35_C7.dat
[11:11:38.211] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//dacParameters35_C8.dat
[11:11:38.211] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//dacParameters35_C9.dat
[11:11:38.211] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//dacParameters35_C10.dat
[11:11:38.211] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//dacParameters35_C11.dat
[11:11:38.211] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//dacParameters35_C12.dat
[11:11:38.212] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//dacParameters35_C13.dat
[11:11:38.212] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//dacParameters35_C14.dat
[11:11:38.212] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//dacParameters35_C15.dat
[11:11:41.935] INFO: Test took 3716ms.
[11:11:45.909] INFO: Test took 3696ms.
[11:11:49.922] INFO: Test took 3730ms.
[11:11:50.207] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:11:51.111] INFO: Test took 904ms.
[11:11:51.115] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:11:52.208] INFO: Test took 1093ms.
[11:11:52.212] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:11:53.304] INFO: Test took 1092ms.
[11:11:53.307] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:11:54.400] INFO: Test took 1093ms.
[11:11:54.407] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:11:55.497] INFO: Test took 1090ms.
[11:11:55.504] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:11:56.595] INFO: Test took 1091ms.
[11:11:56.598] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:11:57.691] INFO: Test took 1093ms.
[11:11:57.695] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:11:58.785] INFO: Test took 1091ms.
[11:11:58.789] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:11:59.881] INFO: Test took 1092ms.
[11:11:59.888] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:12:00.976] INFO: Test took 1089ms.
[11:12:00.982] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:12:02.071] INFO: Test took 1090ms.
[11:12:02.076] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:12:03.165] INFO: Test took 1089ms.
[11:12:03.169] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:12:04.261] INFO: Test took 1092ms.
[11:12:04.268] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:12:05.356] INFO: Test took 1088ms.
[11:12:05.359] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:12:06.454] INFO: Test took 1095ms.
[11:12:06.457] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:12:07.554] INFO: Test took 1097ms.
[11:12:07.561] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:12:08.650] INFO: Test took 1089ms.
[11:12:08.653] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:12:09.746] INFO: Test took 1093ms.
[11:12:09.750] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:12:10.841] INFO: Test took 1091ms.
[11:12:10.843] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:12:11.936] INFO: Test took 1093ms.
[11:12:11.941] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:12:13.032] INFO: Test took 1091ms.
[11:12:13.038] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:12:14.127] INFO: Test took 1089ms.
[11:12:14.131] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:12:15.223] INFO: Test took 1092ms.
[11:12:15.226] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:12:16.318] INFO: Test took 1092ms.
[11:12:16.321] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:12:17.415] INFO: Test took 1094ms.
[11:12:17.419] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:12:18.510] INFO: Test took 1091ms.
[11:12:18.513] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:12:19.607] INFO: Test took 1094ms.
[11:12:19.611] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:12:20.702] INFO: Test took 1091ms.
[11:12:20.706] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:12:21.799] INFO: Test took 1093ms.
[11:12:21.803] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:12:22.896] INFO: Test took 1093ms.
[11:12:22.899] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:12:23.992] INFO: Test took 1093ms.
[11:12:23.998] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:12:25.088] INFO: Test took 1090ms.
[11:12:25.700] INFO: PixTestPhOptimization::doTest() done, duration: 430 seconds
[11:12:25.700] INFO: PH scale (per ROC): 75 80 76 82 67 78 69 86 71 75 79 73 66 78 79 79
[11:12:25.700] INFO: PH offset (per ROC): 159 168 180 145 176 176 161 151 175 172 159 176 175 155 169 176
[11:12:25.848] DEBUG: <PixTestGainPedestal.cc/setParameter:L83> PixTestGainPedestal::PixTest() fVcalStep = 10
[11:12:25.850] INFO: ######################################################################
[11:12:25.850] INFO: PixTestGainPedestal::fullTest() ntrig = 10
[11:12:25.850] INFO: ######################################################################
[11:12:25.850] DEBUG: <PixTestGainPedestal.cc/measure:L192> using FLAGS = 16
[11:12:25.865] INFO: scanning low vcal = 10
[11:12:29.187] INFO: Test took 3321ms.
[11:12:29.192] INFO: scanning low vcal = 20
[11:12:32.517] INFO: Test took 3325ms.
[11:12:32.522] INFO: scanning low vcal = 30
[11:12:35.866] INFO: Test took 3344ms.
[11:12:35.877] INFO: scanning low vcal = 40
[11:12:39.609] INFO: Test took 3732ms.
[11:12:39.672] INFO: scanning low vcal = 50
[11:12:43.459] INFO: Test took 3787ms.
[11:12:43.520] INFO: scanning low vcal = 60
[11:12:47.318] INFO: Test took 3798ms.
[11:12:47.381] INFO: scanning low vcal = 70
[11:12:51.168] INFO: Test took 3787ms.
[11:12:51.232] INFO: scanning low vcal = 80
[11:12:55.022] INFO: Test took 3790ms.
[11:12:55.085] INFO: scanning low vcal = 90
[11:12:58.857] INFO: Test took 3772ms.
[11:12:58.921] INFO: scanning low vcal = 100
[11:13:02.740] INFO: Test took 3818ms.
[11:13:02.819] INFO: scanning low vcal = 110
[11:13:06.583] INFO: Test took 3764ms.
[11:13:06.647] INFO: scanning low vcal = 120
[11:13:10.445] INFO: Test took 3798ms.
[11:13:10.510] INFO: scanning low vcal = 130
[11:13:14.404] INFO: Test took 3894ms.
[11:13:14.467] INFO: scanning low vcal = 140
[11:13:18.320] INFO: Test took 3853ms.
[11:13:18.383] INFO: scanning low vcal = 150
[11:13:22.113] INFO: Test took 3730ms.
[11:13:22.172] INFO: scanning low vcal = 160
[11:13:25.963] INFO: Test took 3791ms.
[11:13:26.032] INFO: scanning low vcal = 170
[11:13:29.865] INFO: Test took 3833ms.
[11:13:29.934] INFO: scanning low vcal = 180
[11:13:33.697] INFO: Test took 3763ms.
[11:13:33.766] INFO: scanning low vcal = 190
[11:13:37.558] INFO: Test took 3792ms.
[11:13:37.633] INFO: scanning low vcal = 200
[11:13:41.406] INFO: Test took 3773ms.
[11:13:41.496] INFO: scanning low vcal = 210
[11:13:45.266] INFO: Test took 3770ms.
[11:13:45.324] INFO: scanning low vcal = 220
[11:13:49.046] INFO: Test took 3722ms.
[11:13:49.105] INFO: scanning low vcal = 230
[11:13:52.871] INFO: Test took 3766ms.
[11:13:52.930] INFO: scanning low vcal = 240
[11:13:56.706] INFO: Test took 3776ms.
[11:13:56.770] INFO: scanning low vcal = 250
[11:14:00.534] INFO: Test took 3764ms.
[11:14:00.599] INFO: scanning high vcal = 30 (= 210 in low range)
[11:14:04.374] INFO: Test took 3775ms.
[11:14:04.439] INFO: scanning high vcal = 50 (= 350 in low range)
[11:14:08.207] INFO: Test took 3768ms.
[11:14:08.269] INFO: scanning high vcal = 70 (= 490 in low range)
[11:14:12.050] INFO: Test took 3781ms.
[11:14:12.115] INFO: scanning high vcal = 90 (= 630 in low range)
[11:14:15.883] INFO: Test took 3768ms.
[11:14:15.947] INFO: scanning high vcal = 200 (= 1400 in low range)
[11:14:19.737] INFO: Test took 3790ms.
[11:14:20.273] INFO: PixTestGainPedestal::measure() done
[11:14:20.275] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C0
[11:14:20.276] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C1
[11:14:20.276] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C2
[11:14:20.276] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C3
[11:14:20.276] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C4
[11:14:20.277] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C5
[11:14:20.277] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C6
[11:14:20.277] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C7
[11:14:20.277] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C8
[11:14:20.278] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C9
[11:14:20.278] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C10
[11:14:20.278] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C11
[11:14:20.279] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C12
[11:14:20.279] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C13
[11:14:20.279] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C14
[11:14:20.279] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C15
[11:14:49.561] INFO: PixTestGainPedestal::fit() done
[11:14:49.561] INFO: non-linearity mean: 0.961 0.953 0.951 0.956 0.956 0.967 0.954 0.955 0.961 0.952 0.959 0.960 0.961 0.953 0.955 0.951
[11:14:49.561] INFO: non-linearity RMS: 0.006 0.007 0.006 0.006 0.006 0.006 0.008 0.005 0.006 0.006 0.006 0.004 0.005 0.005 0.007 0.007
[11:14:49.561] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//phCalibrationFitErr35_C0.dat
[11:14:49.580] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//phCalibrationFitErr35_C1.dat
[11:14:49.597] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//phCalibrationFitErr35_C2.dat
[11:14:49.614] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//phCalibrationFitErr35_C3.dat
[11:14:49.631] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//phCalibrationFitErr35_C4.dat
[11:14:49.648] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//phCalibrationFitErr35_C5.dat
[11:14:49.664] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//phCalibrationFitErr35_C6.dat
[11:14:49.681] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//phCalibrationFitErr35_C7.dat
[11:14:49.698] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//phCalibrationFitErr35_C8.dat
[11:14:49.715] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//phCalibrationFitErr35_C9.dat
[11:14:49.731] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//phCalibrationFitErr35_C10.dat
[11:14:49.748] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//phCalibrationFitErr35_C11.dat
[11:14:49.765] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//phCalibrationFitErr35_C12.dat
[11:14:49.782] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//phCalibrationFitErr35_C13.dat
[11:14:49.799] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//phCalibrationFitErr35_C14.dat
[11:14:49.816] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//000_Fulltest_m20//phCalibrationFitErr35_C15.dat
[11:14:49.833] INFO: PixTestGainPedestal::doTest() done, duration: 143 seconds
[11:14:49.833] DEBUG: <PixTestGainPedestal.cc/~PixTestGainPedestal:L125> PixTestGainPedestal dtor
[11:14:49.839] DEBUG: <PixTestFullTest.cc/~PixTestFullTest:L78> PixTestFullTest dtor
[11:14:49.839] INFO: enter test to run
[11:14:49.839] INFO: test: q no parameter change
[11:14:49.839] DEBUG: <PixMonitor.cc/dumpSummaries:L34> PixMonitor::dumpSummaries
[11:14:49.967] QUIET: Connection to board 111 closed.
[11:14:49.968] INFO: pXar: this is the end, my friend
[11:14:49.968] DEBUG: <PixSetup.cc/~PixSetup:L68> PixSetup free fPxarMemory