[09:20:14.164] INFO: *** Welcome to pxar ***
[09:20:14.164] INFO: *** Today: 2015/07/31
[09:20:14.164] INFO: readRocDacs: /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters_C0.dat .. /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters_C15.dat
[09:20:14.165] INFO: readTbmDacs: /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//tbmParameters_C0a.dat .. /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//tbmParameters_C0b.dat
[09:20:14.165] INFO: readMaskFile: /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//defaultMaskFile.dat
[09:20:14.165] INFO: readTrimFile: /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//trimParameters_C0.dat .. /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//trimParameters_C15.dat
[09:20:14.225] INFO: clk: 4
[09:20:14.225] INFO: ctr: 4
[09:20:14.225] INFO: sda: 19
[09:20:14.225] INFO: tin: 9
[09:20:14.225] INFO: level: 15
[09:20:14.226] INFO: triggerdelay: 0
[09:20:14.226] QUIET: Instanciating API for pxar v2.2.5+67~g3b1c276
[09:20:14.226] INFO: Log level: DEBUG
[09:20:14.234] INFO: Found DTB DTB_WV80Z6
[09:20:14.243] QUIET: Connection to board DTB_WV80Z6 opened.
[09:20:14.246] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 107
HW version: DTB1.2
FW version: 4.2
SW version: 4.2
USB id: DTB_WV80Z6
MAC address: 40D85511806B
Hostname: pixelDTB107
Comment:
------------------------------------------------------
[09:20:14.249] INFO: RPC call hashes of host and DTB match: 447413373
[09:20:15.769] INFO: DUT info:
[09:20:15.769] INFO: The DUT currently contains the following objects:
[09:20:15.769] INFO: 2 TBM Cores tbm08c (2 ON)
[09:20:15.769] INFO: TBM Core alpha (0): 7 registers set
[09:20:15.769] INFO: TBM Core beta (1): 7 registers set
[09:20:15.769] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[09:20:15.769] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[09:20:15.769] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[09:20:15.769] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[09:20:15.769] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[09:20:15.769] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[09:20:15.770] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[09:20:15.770] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[09:20:15.770] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[09:20:15.770] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[09:20:15.770] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[09:20:15.770] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[09:20:15.770] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[09:20:15.770] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[09:20:15.770] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[09:20:15.770] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[09:20:15.770] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[09:20:15.770] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->BB<-
[09:20:15.770] DEBUG: <PixTestParameters.cc/dump:L107> dumpall: checkbox(0)
[09:20:15.770] DEBUG: <PixTestParameters.cc/dump:L107> dumpproblematic: checkbox(0)
[09:20:15.770] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 5
[09:20:15.770] DEBUG: <PixTestParameters.cc/dump:L107> vcals: 250
[09:20:15.770] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->BB2<-
[09:20:15.770] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[09:20:15.770] DEBUG: <PixTestParameters.cc/dump:L107> vcals: 222
[09:20:15.770] DEBUG: <PixTestParameters.cc/dump:L107> plwidth: 35
[09:20:15.770] DEBUG: <PixTestParameters.cc/dump:L107> pix: 11,20
[09:20:15.770] DEBUG: <PixTestParameters.cc/dump:L107> targetia: 24
[09:20:15.770] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->BB3<-
[09:20:15.770] DEBUG: <PixTestParameters.cc/dump:L107> dumpall: checkbox(0)
[09:20:15.770] DEBUG: <PixTestParameters.cc/dump:L107> dumpproblematic: checkbox(0)
[09:20:15.770] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 5
[09:20:15.770] DEBUG: <PixTestParameters.cc/dump:L107> vcals: 250
[09:20:15.770] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Cmd<-
[09:20:15.770] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->DacDacScan<-
[09:20:15.770] DEBUG: <PixTestParameters.cc/dump:L107> phmap: checkbox
[09:20:15.770] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[09:20:15.770] DEBUG: <PixTestParameters.cc/dump:L107> dac1: caldel
[09:20:15.770] DEBUG: <PixTestParameters.cc/dump:L107> dac1lo: 0
[09:20:15.770] DEBUG: <PixTestParameters.cc/dump:L107> dac1hi: 255
[09:20:15.770] DEBUG: <PixTestParameters.cc/dump:L107> dac2: vthrcomp
[09:20:15.770] DEBUG: <PixTestParameters.cc/dump:L107> dac2lo: 0
[09:20:15.770] DEBUG: <PixTestParameters.cc/dump:L107> dac2hi: 255
[09:20:15.770] DEBUG: <PixTestParameters.cc/dump:L107> pix: 11,20
[09:20:15.770] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->DacScan<-
[09:20:15.770] DEBUG: <PixTestParameters.cc/dump:L107> phmap: checkbox(1)
[09:20:15.770] DEBUG: <PixTestParameters.cc/dump:L107> allpixels: checkbox(0)
[09:20:15.770] DEBUG: <PixTestParameters.cc/dump:L107> unmasked: checkbox(0)
[09:20:15.770] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[09:20:15.770] DEBUG: <PixTestParameters.cc/dump:L107> dac: vcal
[09:20:15.770] DEBUG: <PixTestParameters.cc/dump:L107> daclo: 0
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> dachi: 255
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> pix: 11,20
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->GainPedestal<-
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> showfits: checkbox(0)
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> extended: checkbox(0)
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> dumphists: checkbox(0)
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> vcalstep: 10
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> measure: button
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> fit: button
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> save: button
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->HighRate<-
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> pix: 11,20
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> maskhotpixels: button
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> savemaskfile: checkbox(0)
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> maskfilename: default
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> caldelscan: button
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> xpixelalive: button
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 50
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> vcal: 200
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> xnoisemaps: button
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> daclo: 0
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> dachi: 100
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> dacs/step: 20
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> rundaq: button
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> trgfrequency(khz): 20
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> runseconds: 2
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> triggerdelay: 20
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> delaytbm: checkbox
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> filltree: checkbox
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->IV<-
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> port: /dev/FIXME
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> voltagestart: 0
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> voltagestop: 600
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> voltagestep: 5
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> delay: 1
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> compliance(ua): 100
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->PhOptimization<-
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> safetymarginlow: 20
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> saturationvcal: 100
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> quantilesaturation: 0.98
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->PixelAlive<-
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> vcal: 200
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> alivetest: button
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> masktest: button
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> addressdecodingtest: button
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Pretest<-
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> programroc: button
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> targetia: 24
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> setvana: button
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> iterations: 100
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> settimings: button
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> findworkingpixel: button
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> setvthrcompcaldel: button
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> pix: 11,20
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> vcal: 250
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> deltavthrcomp: 50
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> fraccaldel: 0.5
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 5
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> savedacs: button
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Readback<-
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> calibratevd: button
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> calibrateva: button
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> calibrateia: button
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> readbackvbg: button
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> getcalibratedvbg: button
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> usecalvd: checkbox(1)
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> usecalva: checkbox(0)
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> setvana: button
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Scurves<-
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> adjustvcal: checkbox(1)
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> dumpall: checkbox(0)
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> dumpproblematic: checkbox(0)
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> dumpoutputfile: checkbox(0)
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 50
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> dac: VthrComp
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> daclo: 0
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> dachi: 200
[09:20:15.771] DEBUG: <PixTestParameters.cc/dump:L107> dacs/step: 10
[09:20:15.772] DEBUG: <PixTestParameters.cc/dump:L107> scurves: button
[09:20:15.772] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Timing<-
[09:20:15.772] DEBUG: <PixTestParameters.cc/dump:L107> fastscan: checkbox(0)
[09:20:15.772] DEBUG: <PixTestParameters.cc/dump:L107> targetclk: 4
[09:20:15.772] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[09:20:15.772] DEBUG: <PixTestParameters.cc/dump:L107> clocksdascan: button
[09:20:15.772] DEBUG: <PixTestParameters.cc/dump:L107> phasescan: button
[09:20:15.772] DEBUG: <PixTestParameters.cc/dump:L107> levelscan: button
[09:20:15.772] DEBUG: <PixTestParameters.cc/dump:L107> tbmphasescan: button
[09:20:15.772] DEBUG: <PixTestParameters.cc/dump:L107> rocdelayscan: button
[09:20:15.772] DEBUG: <PixTestParameters.cc/dump:L107> timingtest: button
[09:20:15.772] DEBUG: <PixTestParameters.cc/dump:L107> saveparameters: button
[09:20:15.772] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Trim<-
[09:20:15.772] DEBUG: <PixTestParameters.cc/dump:L107> trim: button
[09:20:15.772] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[09:20:15.772] DEBUG: <PixTestParameters.cc/dump:L107> vcal: 35
[09:20:15.772] DEBUG: <PixTestParameters.cc/dump:L107> trimbits: button
[09:20:15.772] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Xray<-
[09:20:15.772] DEBUG: <PixTestParameters.cc/dump:L107> maskhotpixels: button
[09:20:15.772] DEBUG: <PixTestParameters.cc/dump:L107> savemaskfile: checkbox(0)
[09:20:15.772] DEBUG: <PixTestParameters.cc/dump:L107> maskfilename: default
[09:20:15.772] DEBUG: <PixTestParameters.cc/dump:L107> source: Ag
[09:20:15.772] DEBUG: <PixTestParameters.cc/dump:L107> phrun: button
[09:20:15.772] DEBUG: <PixTestParameters.cc/dump:L107> runseconds: 100
[09:20:15.772] DEBUG: <PixTestParameters.cc/dump:L107> trgfrequency(khz): 100
[09:20:15.772] DEBUG: <PixTestParameters.cc/dump:L107> ratescan: button
[09:20:15.772] DEBUG: <PixTestParameters.cc/dump:L107> vthrcompmin: 10
[09:20:15.772] DEBUG: <PixTestParameters.cc/dump:L107> vthrcompmax: 80
[09:20:15.772] DEBUG: <PixTestParameters.cc/dump:L107> stepseconds: 5
[09:20:15.772] DEBUG: <PixTestParameters.cc/dump:L107> delaytbm: checkbox
[09:20:15.772] DEBUG: <PixTestParameters.cc/dump:L107> filltree: checkbox
[09:20:15.772] DEBUG: <PixSetup.cc/init:L81> PixSetup init start; getCurrentRSS() = 34148352
[09:20:15.772] DEBUG: <PixSetup.cc/init:L87> fPixTestParameters = 0x168e160
[09:20:15.772] DEBUG: <PixSetup.cc/init:L88> fConfigParameters = 0x15f39c0
[09:20:15.772] DEBUG: <PixSetup.cc/init:L89> fPxarMemory = 0x7f7481d94010
[09:20:15.772] DEBUG: <PixSetup.cc/init:L90> fPxarMemHi = 0x7f7487fff510
[09:20:15.772] DEBUG: <PixSetup.cc/init:L106> PixSetup init done; getCurrentRSS() = 34209792 fPxarMemory = 0x7f7481d94010
[09:20:15.772] DEBUG: <PixTestFactory.cc/PixTestFactory:L52> PixTestFactory::PixTestFactory()
[09:20:16.173] INFO: enter 'restricted' command line mode
[09:20:16.173] INFO: enter test to run
[09:20:16.173] INFO: test: Pretest no parameter change
[09:20:16.173] INFO: running: pretest
[09:20:16.178] INFO: ######################################################################
[09:20:16.178] INFO: PixTestPretest::doTest()
[09:20:16.178] INFO: ######################################################################
[09:20:16.180] INFO: ----------------------------------------------------------------------
[09:20:16.180] INFO: PixTestPretest::programROC()
[09:20:16.180] INFO: ----------------------------------------------------------------------
[09:20:34.200] INFO: PixTestPretest::programROC() done: ROCs are all programmable
[09:20:34.200] INFO: IA differences per ROC: 18.5 16.1 17.7 19.3 20.1 19.3 19.3 18.5 16.1 18.5 17.7 18.5 20.9 18.5 18.5 20.1
[09:20:34.272] INFO: ----------------------------------------------------------------------
[09:20:34.272] INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[09:20:34.272] INFO: ----------------------------------------------------------------------
[09:20:34.378] DEBUG: <PixTestPretest.cc/setVana:L254> offset current from other 15 ROCs is 67.7812 mA
[09:20:34.480] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 0 iter 0 Vana 78 Ia 21.4188 mA
[09:20:34.581] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 1 Vana 94 Ia 25.4188 mA
[09:20:34.681] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 2 Vana 87 Ia 24.6187 mA
[09:20:34.782] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 3 Vana 84 Ia 23.8187 mA
[09:20:34.883] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 4 Vana 85 Ia 23.8187 mA
[09:20:34.983] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 5 Vana 86 Ia 23.8187 mA
[09:20:35.084] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 6 Vana 87 Ia 24.6187 mA
[09:20:35.185] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 7 Vana 84 Ia 23.8187 mA
[09:20:35.286] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 8 Vana 85 Ia 23.8187 mA
[09:20:35.387] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 9 Vana 86 Ia 23.8187 mA
[09:20:35.487] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 10 Vana 87 Ia 24.6187 mA
[09:20:35.588] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 11 Vana 84 Ia 23.8187 mA
[09:20:35.690] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 1 iter 0 Vana 78 Ia 19.8187 mA
[09:20:35.791] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 1 Vana 103 Ia 24.6187 mA
[09:20:35.891] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 2 Vana 100 Ia 23.8187 mA
[09:20:35.992] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 3 Vana 101 Ia 24.6187 mA
[09:20:36.093] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 4 Vana 98 Ia 23.8187 mA
[09:20:36.194] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 5 Vana 99 Ia 23.8187 mA
[09:20:36.295] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 6 Vana 100 Ia 23.8187 mA
[09:20:36.396] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 7 Vana 101 Ia 24.6187 mA
[09:20:36.496] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 8 Vana 98 Ia 23.8187 mA
[09:20:36.597] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 9 Vana 99 Ia 23.8187 mA
[09:20:36.698] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 10 Vana 100 Ia 24.6187 mA
[09:20:36.798] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 11 Vana 97 Ia 23.8187 mA
[09:20:36.900] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 2 iter 0 Vana 78 Ia 21.4188 mA
[09:20:36.001] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 2 iter 1 Vana 94 Ia 24.6187 mA
[09:20:37.102] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 2 iter 2 Vana 91 Ia 24.6187 mA
[09:20:37.203] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 2 iter 3 Vana 88 Ia 23.8187 mA
[09:20:37.304] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 2 iter 4 Vana 89 Ia 23.8187 mA
[09:20:37.404] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 2 iter 5 Vana 90 Ia 24.6187 mA
[09:20:37.505] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 2 iter 6 Vana 87 Ia 23.8187 mA
[09:20:37.606] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 2 iter 7 Vana 88 Ia 23.8187 mA
[09:20:37.707] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 2 iter 8 Vana 89 Ia 23.8187 mA
[09:20:37.808] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 2 iter 9 Vana 90 Ia 23.8187 mA
[09:20:37.909] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 2 iter 10 Vana 91 Ia 24.6187 mA
[09:20:38.009] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 2 iter 11 Vana 88 Ia 23.8187 mA
[09:20:38.111] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 3 iter 0 Vana 78 Ia 23.0188 mA
[09:20:38.212] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 1 Vana 84 Ia 24.6187 mA
[09:20:38.313] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 2 Vana 81 Ia 23.8187 mA
[09:20:38.414] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 3 Vana 82 Ia 23.8187 mA
[09:20:38.515] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 4 Vana 83 Ia 24.6187 mA
[09:20:38.615] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 5 Vana 80 Ia 23.8187 mA
[09:20:38.716] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 6 Vana 81 Ia 23.8187 mA
[09:20:38.817] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 7 Vana 82 Ia 24.6187 mA
[09:20:38.918] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 8 Vana 79 Ia 23.0188 mA
[09:20:39.018] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 9 Vana 85 Ia 24.6187 mA
[09:20:39.119] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 10 Vana 82 Ia 24.6187 mA
[09:20:39.220] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 11 Vana 79 Ia 23.0188 mA
[09:20:39.321] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 4 iter 0 Vana 78 Ia 23.8187 mA
[09:20:39.422] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 4 iter 1 Vana 79 Ia 23.8187 mA
[09:20:39.523] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 4 iter 2 Vana 80 Ia 24.6187 mA
[09:20:39.623] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 4 iter 3 Vana 77 Ia 23.8187 mA
[09:20:39.724] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 4 iter 4 Vana 78 Ia 23.8187 mA
[09:20:39.825] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 4 iter 5 Vana 79 Ia 23.8187 mA
[09:20:39.925] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 4 iter 6 Vana 80 Ia 24.6187 mA
[09:20:40.026] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 4 iter 7 Vana 77 Ia 23.0188 mA
[09:20:40.127] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 4 iter 8 Vana 83 Ia 25.4188 mA
[09:20:40.227] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 4 iter 9 Vana 76 Ia 23.0188 mA
[09:20:40.328] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 4 iter 10 Vana 82 Ia 24.6187 mA
[09:20:40.429] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 4 iter 11 Vana 79 Ia 23.8187 mA
[09:20:40.531] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 5 iter 0 Vana 78 Ia 23.0188 mA
[09:20:40.631] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 1 Vana 84 Ia 23.8187 mA
[09:20:40.732] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 2 Vana 85 Ia 24.6187 mA
[09:20:40.833] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 3 Vana 82 Ia 23.8187 mA
[09:20:40.933] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 4 Vana 83 Ia 23.8187 mA
[09:20:41.034] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 5 Vana 84 Ia 24.6187 mA
[09:20:41.135] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 6 Vana 81 Ia 23.8187 mA
[09:20:41.235] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 7 Vana 82 Ia 23.8187 mA
[09:20:41.336] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 8 Vana 83 Ia 24.6187 mA
[09:20:41.437] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 9 Vana 80 Ia 23.8187 mA
[09:20:41.537] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 10 Vana 81 Ia 23.8187 mA
[09:20:41.638] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 11 Vana 82 Ia 23.8187 mA
[09:20:41.739] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 6 iter 0 Vana 78 Ia 23.0188 mA
[09:20:41.840] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 1 Vana 84 Ia 24.6187 mA
[09:20:41.941] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 2 Vana 81 Ia 23.8187 mA
[09:20:42.042] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 3 Vana 82 Ia 23.8187 mA
[09:20:42.142] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 4 Vana 83 Ia 23.8187 mA
[09:20:42.243] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 5 Vana 84 Ia 24.6187 mA
[09:20:42.343] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 6 Vana 81 Ia 23.8187 mA
[09:20:42.444] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 7 Vana 82 Ia 23.8187 mA
[09:20:42.545] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 8 Vana 83 Ia 24.6187 mA
[09:20:42.646] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 9 Vana 80 Ia 23.8187 mA
[09:20:42.747] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 10 Vana 81 Ia 23.8187 mA
[09:20:42.847] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 11 Vana 82 Ia 23.8187 mA
[09:20:42.949] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 7 iter 0 Vana 78 Ia 22.2188 mA
[09:20:43.050] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 7 iter 1 Vana 89 Ia 25.4188 mA
[09:20:43.150] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 7 iter 2 Vana 82 Ia 23.8187 mA
[09:20:43.251] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 7 iter 3 Vana 83 Ia 23.8187 mA
[09:20:43.352] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 7 iter 4 Vana 84 Ia 24.6187 mA
[09:20:43.453] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 7 iter 5 Vana 81 Ia 23.8187 mA
[09:20:43.553] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 7 iter 6 Vana 82 Ia 23.8187 mA
[09:20:43.653] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 7 iter 7 Vana 83 Ia 23.8187 mA
[09:20:43.754] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 7 iter 8 Vana 84 Ia 24.6187 mA
[09:20:43.855] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 7 iter 9 Vana 81 Ia 23.8187 mA
[09:20:43.956] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 7 iter 10 Vana 82 Ia 23.8187 mA
[09:20:44.056] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 7 iter 11 Vana 83 Ia 23.8187 mA
[09:20:44.158] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 8 iter 0 Vana 78 Ia 19.8187 mA
[09:20:44.259] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 8 iter 1 Vana 103 Ia 24.6187 mA
[09:20:44.360] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 8 iter 2 Vana 100 Ia 23.8187 mA
[09:20:44.461] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 8 iter 3 Vana 101 Ia 23.8187 mA
[09:20:44.562] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 8 iter 4 Vana 102 Ia 23.8187 mA
[09:20:44.663] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 8 iter 5 Vana 103 Ia 23.8187 mA
[09:20:44.764] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 8 iter 6 Vana 104 Ia 23.8187 mA
[09:20:44.865] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 8 iter 7 Vana 105 Ia 24.6187 mA
[09:20:44.966] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 8 iter 8 Vana 102 Ia 23.8187 mA
[09:20:45.067] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 8 iter 9 Vana 103 Ia 24.6187 mA
[09:20:45.168] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 8 iter 10 Vana 100 Ia 23.8187 mA
[09:20:45.268] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 8 iter 11 Vana 101 Ia 23.8187 mA
[09:20:45.370] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 9 iter 0 Vana 78 Ia 22.2188 mA
[09:20:45.471] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 9 iter 1 Vana 89 Ia 24.6187 mA
[09:20:45.572] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 9 iter 2 Vana 86 Ia 23.8187 mA
[09:20:45.673] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 9 iter 3 Vana 87 Ia 23.8187 mA
[09:20:45.774] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 9 iter 4 Vana 88 Ia 23.8187 mA
[09:20:45.875] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 9 iter 5 Vana 89 Ia 24.6187 mA
[09:20:45.976] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 9 iter 6 Vana 86 Ia 23.8187 mA
[09:20:46.077] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 9 iter 7 Vana 87 Ia 24.6187 mA
[09:20:46.178] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 9 iter 8 Vana 84 Ia 23.8187 mA
[09:20:46.278] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 9 iter 9 Vana 85 Ia 23.8187 mA
[09:20:46.379] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 9 iter 10 Vana 86 Ia 24.6187 mA
[09:20:46.479] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 9 iter 11 Vana 83 Ia 23.8187 mA
[09:20:46.581] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 10 iter 0 Vana 78 Ia 21.4188 mA
[09:20:46.681] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 1 Vana 94 Ia 25.4188 mA
[09:20:46.782] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 2 Vana 87 Ia 23.8187 mA
[09:20:46.883] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 3 Vana 88 Ia 23.8187 mA
[09:20:46.984] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 4 Vana 89 Ia 23.8187 mA
[09:20:47.085] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 5 Vana 90 Ia 24.6187 mA
[09:20:47.186] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 6 Vana 87 Ia 23.8187 mA
[09:20:47.287] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 7 Vana 88 Ia 23.8187 mA
[09:20:47.387] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 8 Vana 89 Ia 23.8187 mA
[09:20:47.488] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 9 Vana 90 Ia 24.6187 mA
[09:20:47.588] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 10 Vana 87 Ia 23.8187 mA
[09:20:47.689] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 11 Vana 88 Ia 23.8187 mA
[09:20:47.791] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 11 iter 0 Vana 78 Ia 22.2188 mA
[09:20:47.892] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter 1 Vana 89 Ia 24.6187 mA
[09:20:47.993] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter 2 Vana 86 Ia 24.6187 mA
[09:20:48.094] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter 3 Vana 83 Ia 23.8187 mA
[09:20:48.195] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter 4 Vana 84 Ia 23.8187 mA
[09:20:48.296] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter 5 Vana 85 Ia 23.8187 mA
[09:20:48.397] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter 6 Vana 86 Ia 24.6187 mA
[09:20:48.497] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter 7 Vana 83 Ia 23.8187 mA
[09:20:48.598] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter 8 Vana 84 Ia 23.8187 mA
[09:20:48.699] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter 9 Vana 85 Ia 23.8187 mA
[09:20:48.800] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter 10 Vana 86 Ia 24.6187 mA
[09:20:48.901] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter 11 Vana 83 Ia 23.8187 mA
[09:20:49.003] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 12 iter 0 Vana 78 Ia 23.8187 mA
[09:20:49.103] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter 1 Vana 79 Ia 24.6187 mA
[09:20:49.204] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter 2 Vana 76 Ia 23.8187 mA
[09:20:49.304] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter 3 Vana 77 Ia 23.8187 mA
[09:20:49.405] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter 4 Vana 78 Ia 23.8187 mA
[09:20:49.506] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter 5 Vana 79 Ia 24.6187 mA
[09:20:49.608] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter 6 Vana 76 Ia 23.8187 mA
[09:20:49.708] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter 7 Vana 77 Ia 23.8187 mA
[09:20:49.809] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter 8 Vana 78 Ia 24.6187 mA
[09:20:49.911] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter 9 Vana 75 Ia 23.8187 mA
[09:20:50.012] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter 10 Vana 76 Ia 23.8187 mA
[09:20:50.113] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter 11 Vana 77 Ia 23.8187 mA
[09:20:50.214] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 13 iter 0 Vana 78 Ia 22.2188 mA
[09:20:50.315] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 1 Vana 89 Ia 24.6187 mA
[09:20:50.416] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 2 Vana 86 Ia 24.6187 mA
[09:20:50.517] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 3 Vana 83 Ia 23.8187 mA
[09:20:50.619] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 4 Vana 84 Ia 23.8187 mA
[09:20:50.720] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 5 Vana 85 Ia 23.8187 mA
[09:20:50.821] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 6 Vana 86 Ia 24.6187 mA
[09:20:50.921] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 7 Vana 83 Ia 23.8187 mA
[09:20:51.022] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 8 Vana 84 Ia 23.8187 mA
[09:20:51.123] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 9 Vana 85 Ia 23.8187 mA
[09:20:51.223] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 10 Vana 86 Ia 23.8187 mA
[09:20:51.324] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 11 Vana 87 Ia 24.6187 mA
[09:20:51.426] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 14 iter 0 Vana 78 Ia 23.0188 mA
[09:20:51.527] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 1 Vana 84 Ia 23.8187 mA
[09:20:51.628] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 2 Vana 85 Ia 24.6187 mA
[09:20:51.728] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 3 Vana 82 Ia 23.8187 mA
[09:20:51.829] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 4 Vana 83 Ia 24.6187 mA
[09:20:51.929] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 5 Vana 80 Ia 23.8187 mA
[09:20:52.031] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 6 Vana 81 Ia 23.8187 mA
[09:20:52.131] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 7 Vana 82 Ia 23.8187 mA
[09:20:52.232] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 8 Vana 83 Ia 23.8187 mA
[09:20:52.332] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 9 Vana 84 Ia 24.6187 mA
[09:20:52.433] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 10 Vana 81 Ia 23.8187 mA
[09:20:52.534] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 11 Vana 82 Ia 23.8187 mA
[09:20:52.635] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 15 iter 0 Vana 78 Ia 23.8187 mA
[09:20:52.736] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 1 Vana 79 Ia 23.8187 mA
[09:20:52.837] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 2 Vana 80 Ia 24.6187 mA
[09:20:52.938] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 3 Vana 77 Ia 23.0188 mA
[09:20:53.039] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 4 Vana 83 Ia 25.4188 mA
[09:20:53.140] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 5 Vana 76 Ia 23.0188 mA
[09:20:53.240] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 6 Vana 82 Ia 24.6187 mA
[09:20:53.341] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 7 Vana 79 Ia 23.8187 mA
[09:20:53.442] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 8 Vana 80 Ia 24.6187 mA
[09:20:53.543] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 9 Vana 77 Ia 23.0188 mA
[09:20:53.644] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 10 Vana 83 Ia 24.6187 mA
[09:20:53.744] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 11 Vana 80 Ia 23.8187 mA
[09:20:53.789] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 0 Vana 84
[09:20:53.789] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 1 Vana 97
[09:20:53.790] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 2 Vana 88
[09:20:53.790] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 3 Vana 79
[09:20:53.790] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 4 Vana 79
[09:20:53.790] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 5 Vana 82
[09:20:53.791] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 6 Vana 82
[09:20:53.791] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 7 Vana 83
[09:20:53.791] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 8 Vana 101
[09:20:53.791] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 9 Vana 83
[09:20:53.791] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 10 Vana 88
[09:20:53.791] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 11 Vana 83
[09:20:53.792] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 12 Vana 77
[09:20:53.792] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 13 Vana 87
[09:20:53.792] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 14 Vana 82
[09:20:53.792] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 15 Vana 80
[09:20:53.895] INFO: PixTestPretest::setVana() done, Module Ia 390.7 mA = 24.4187 mA/ROC
[09:20:53.896] INFO: ----------------------------------------------------------------------
[09:20:53.896] INFO: PixTestPreTest::setTimings()
[09:20:53.896] INFO: ----------------------------------------------------------------------
[09:20:53.896] DEBUG: <PixTestPretest.cc/setTimings:L392> Testing Timing: Attempt #1





[09:20:54.862] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:20:54.862] INFO: Decoding statistics:
[09:20:54.862] INFO: General information:
[09:20:54.862] INFO: 16bit words read: 120
[09:20:54.862] INFO: valid events total: 5
[09:20:54.862] INFO: empty events: 5
[09:20:54.862] INFO: valid events with pixels: 0
[09:20:54.862] INFO: valid pixel hits: 0
[09:20:54.862] INFO: Event errors: 0
[09:20:54.862] INFO: start marker: 0
[09:20:54.862] INFO: stop marker: 0
[09:20:54.862] INFO: overflow: 0
[09:20:54.862] INFO: invalid 5bit words: 0
[09:20:54.862] INFO: invalid XOR eye diagram: 0
[09:20:54.862] INFO: TBM errors: 0
[09:20:54.862] INFO: flawed TBM headers: 0
[09:20:54.862] INFO: flawed TBM trailers: 0
[09:20:54.862] INFO: event ID mismatches: 0
[09:20:54.862] INFO: ROC errors: 5
[09:20:54.862] INFO: missing ROC header(s): 5
[09:20:54.862] INFO: misplaced readback start: 0
[09:20:54.862] INFO: Pixel decoding errors: 10
[09:20:54.862] INFO: pixel data incomplete: 0
[09:20:54.862] INFO: pixel address: 0
[09:20:54.862] INFO: pulse height fill bit: 10
[09:20:54.862] INFO: buffer corruption: 0
[09:20:54.862] DEBUG: <PixTestPretest.cc/setTimings:L392> Testing Timing: Attempt #2





[09:20:56.012] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:20:56.012] INFO: Decoding statistics:
[09:20:56.012] INFO: General information:
[09:20:56.012] INFO: 16bit words read: 120
[09:20:56.012] INFO: valid events total: 5
[09:20:56.012] INFO: empty events: 5
[09:20:56.012] INFO: valid events with pixels: 0
[09:20:56.012] INFO: valid pixel hits: 0
[09:20:56.012] INFO: Event errors: 0
[09:20:56.012] INFO: start marker: 0
[09:20:56.012] INFO: stop marker: 0
[09:20:56.012] INFO: overflow: 0
[09:20:56.012] INFO: invalid 5bit words: 0
[09:20:56.012] INFO: invalid XOR eye diagram: 0
[09:20:56.012] INFO: TBM errors: 0
[09:20:56.012] INFO: flawed TBM headers: 0
[09:20:56.012] INFO: flawed TBM trailers: 0
[09:20:56.012] INFO: event ID mismatches: 0
[09:20:56.012] INFO: ROC errors: 5
[09:20:56.012] INFO: missing ROC header(s): 5
[09:20:56.012] INFO: misplaced readback start: 0
[09:20:56.012] INFO: Pixel decoding errors: 10
[09:20:56.012] INFO: pixel data incomplete: 2
[09:20:56.012] INFO: pixel address: 0
[09:20:56.012] INFO: pulse height fill bit: 8
[09:20:56.012] INFO: buffer corruption: 0
[09:20:56.012] DEBUG: <PixTestPretest.cc/setTimings:L392> Testing Timing: Attempt #3





[09:20:57.162] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:20:57.162] INFO: Decoding statistics:
[09:20:57.162] INFO: General information:
[09:20:57.162] INFO: 16bit words read: 120
[09:20:57.162] INFO: valid events total: 5
[09:20:57.162] INFO: empty events: 5
[09:20:57.162] INFO: valid events with pixels: 0
[09:20:57.162] INFO: valid pixel hits: 0
[09:20:57.162] INFO: Event errors: 0
[09:20:57.162] INFO: start marker: 0
[09:20:57.162] INFO: stop marker: 0
[09:20:57.162] INFO: overflow: 0
[09:20:57.162] INFO: invalid 5bit words: 0
[09:20:57.162] INFO: invalid XOR eye diagram: 0
[09:20:57.162] INFO: TBM errors: 0
[09:20:57.162] INFO: flawed TBM headers: 0
[09:20:57.162] INFO: flawed TBM trailers: 0
[09:20:57.162] INFO: event ID mismatches: 0
[09:20:57.162] INFO: ROC errors: 5
[09:20:57.162] INFO: missing ROC header(s): 5
[09:20:57.162] INFO: misplaced readback start: 0
[09:20:57.162] INFO: Pixel decoding errors: 10
[09:20:57.162] INFO: pixel data incomplete: 0
[09:20:57.162] INFO: pixel address: 0
[09:20:57.162] INFO: pulse height fill bit: 10
[09:20:57.162] INFO: buffer corruption: 0
[09:20:57.162] DEBUG: <PixTestPretest.cc/setTimings:L412> Testing TBM Phase: 00000000 160 MHz PLL: 0 400MHz PLL: 0
[09:20:58.306] DEBUG: <PixTestPretest.cc/setTimings:L422> Testing ROC Phase: 01100100
[09:20:58.308] DEBUG: <PixTestPretest.cc/setTimings:L430> Event: ====== 0 ====== a010 80b1 4038 4038 4038 4038 4038 4039 4038 4039 e022 c000 a110 80b0 4039 4039 4039 4038 4039 4039 4039 4039 e022 c000
[09:20:58.308] DEBUG: <PixTestPretest.cc/setTimings:L430> Event: ====== 0 ====== a011 80c1 4038 4038 4039 4038 4038 4038 4039 4039 e022 c000 a111 80c0 4038 4038 4038 4038 4039 4039 4039 4039 e022 c000
[09:20:58.308] DEBUG: <PixTestPretest.cc/setTimings:L430> Event: ====== 0 ====== a012 8001 4038 4038 4038 4038 4038 4038 4039 4039 e022 c000 a112 8000 4038 4038 4039 4038 4038 4038 4039 4039 e022 c000
[09:20:58.308] DEBUG: <PixTestPretest.cc/setTimings:L430> Event: ====== 0 ====== a013 8041 4038 4039 4038 4038 4038 4038 4038 4039 e022 c000 a113 8040 4038 4039 4038 4038 4038 4039 4038 4039 e022 c000
[09:20:58.308] DEBUG: <PixTestPretest.cc/setTimings:L430> Event: ====== 0 ====== a014 80b1 4038 4038 4038 4038 4038 4038 4038 4039 e022 c000 a114 80b0 4038 4038 4038 4038 4038 4038 4038 4039 e022 c000
[09:20:58.487] DEBUG: <PixTestPretest.cc/setTimings:L441> Number of Errors: 0
[09:20:58.487] DEBUG: <PixTestPretest.cc/setTimings:L442> Number of Events: 500
[09:20:58.487] INFO: Decoding statistics:
[09:20:58.487] INFO: General information:
[09:20:58.487] INFO: 16bit words read: 12000
[09:20:58.487] INFO: valid events total: 1000
[09:20:58.487] INFO: empty events: 1000
[09:20:58.487] INFO: valid events with pixels: 0
[09:20:58.487] INFO: valid pixel hits: 0
[09:20:58.487] INFO: Event errors: 0
[09:20:58.487] INFO: start marker: 0
[09:20:58.487] INFO: stop marker: 0
[09:20:58.487] INFO: overflow: 0
[09:20:58.487] INFO: invalid 5bit words: 0
[09:20:58.487] INFO: invalid XOR eye diagram: 0
[09:20:58.487] INFO: TBM errors: 0
[09:20:58.487] INFO: flawed TBM headers: 0
[09:20:58.487] INFO: flawed TBM trailers: 0
[09:20:58.487] INFO: event ID mismatches: 0
[09:20:58.487] INFO: ROC errors: 0
[09:20:58.487] INFO: missing ROC header(s): 0
[09:20:58.487] INFO: misplaced readback start: 0
[09:20:58.487] INFO: Pixel decoding errors: 0
[09:20:58.487] INFO: pixel data incomplete: 0
[09:20:58.487] INFO: pixel address: 0
[09:20:58.487] INFO: pulse height fill bit: 0
[09:20:58.487] INFO: buffer corruption: 0
[09:20:58.487] INFO: ----------------------------------------------------------------------
[09:20:58.487] INFO: Good Timings Found!!!
[09:20:58.487] INFO: ----------------------------------------------------------------------
[09:20:58.487] INFO: Setting TBM Phases to 00000000 160 MHz PLL: 0 400MHz PLL: 0
[09:20:58.487] INFO: Setting ROC Phases to 01100100
[09:20:58.490] INFO: Test took 4594 ms.
[09:20:58.490] INFO: PixTestPretest::setTimings() done.
[09:20:58.682] INFO: ----------------------------------------------------------------------
[09:20:58.682] INFO: PixTestPretest::findWorkingPixel()
[09:20:58.682] INFO: ----------------------------------------------------------------------
[09:21:05.937] INFO: Test took 7251ms.
[09:21:06.167] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C0 OK, with vthrComp = 109 and Delta(CalDel) = 55
[09:21:06.170] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C1 OK, with vthrComp = 82 and Delta(CalDel) = 58
[09:21:06.172] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C2 OK, with vthrComp = 83 and Delta(CalDel) = 55
[09:21:06.174] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C3 OK, with vthrComp = 81 and Delta(CalDel) = 59
[09:21:06.176] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C4 OK, with vthrComp = 81 and Delta(CalDel) = 59
[09:21:06.178] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C5 OK, with vthrComp = 119 and Delta(CalDel) = 57
[09:21:06.181] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C6 OK, with vthrComp = 86 and Delta(CalDel) = 56
[09:21:06.183] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C7 OK, with vthrComp = 116 and Delta(CalDel) = 58
[09:21:06.185] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C8 OK, with vthrComp = 94 and Delta(CalDel) = 57
[09:21:06.188] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C9 OK, with vthrComp = 89 and Delta(CalDel) = 58
[09:21:06.190] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C10 OK, with vthrComp = 94 and Delta(CalDel) = 59
[09:21:06.192] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C11 OK, with vthrComp = 113 and Delta(CalDel) = 57
[09:21:06.194] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C12 OK, with vthrComp = 109 and Delta(CalDel) = 58
[09:21:06.197] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C13 OK, with vthrComp = 88 and Delta(CalDel) = 56
[09:21:06.199] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C14 OK, with vthrComp = 99 and Delta(CalDel) = 57
[09:21:06.201] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C15 OK, with vthrComp = 106 and Delta(CalDel) = 60
[09:21:06.225] INFO: Found working pixel in all ROCs: col/row = 12/22
[09:21:06.274] INFO: ----------------------------------------------------------------------
[09:21:06.274] INFO: PixTestPretest::setVthrCompCalDel()
[09:21:06.274] INFO: ----------------------------------------------------------------------
[09:21:13.574] INFO: Test took 7294ms.
[09:21:13.630] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 108 +/- 28.5
[09:21:13.805] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 109 +/- 29
[09:21:13.807] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 103 +/- 26.5
[09:21:13.809] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 108 +/- 28.5
[09:21:13.812] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 124 +/- 29.5
[09:21:13.814] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 109 +/- 29.5
[09:21:13.817] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 115 +/- 28
[09:21:13.819] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 112 +/- 30
[09:21:13.821] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 111 +/- 30.5
[09:21:13.824] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 114 +/- 29
[09:21:13.826] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 103 +/- 28
[09:21:13.828] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 113 +/- 29.5
[09:21:13.830] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 117 +/- 27.5
[09:21:13.832] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 111 +/- 29
[09:21:13.836] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 108 +/- 29
[09:21:13.838] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 115 +/- 30
[09:21:13.889] INFO: PixTestPretest::setVthrCompCalDel() done
[09:21:13.889] INFO: CalDel: 108 109 103 108 124 109 115 112 111 114 103 113 117 111 108 115
[09:21:13.889] INFO: VthrComp: 51 51 51 51 51 55 51 51 51 51 51 53 51 51 51 53
[09:21:13.892] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters_C0.dat
[09:21:13.893] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters_C1.dat
[09:21:13.893] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters_C2.dat
[09:21:13.893] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters_C3.dat
[09:21:13.893] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters_C4.dat
[09:21:13.893] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters_C5.dat
[09:21:13.893] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters_C6.dat
[09:21:13.893] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters_C7.dat
[09:21:13.893] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters_C8.dat
[09:21:13.893] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters_C9.dat
[09:21:13.893] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters_C10.dat
[09:21:13.894] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters_C11.dat
[09:21:13.894] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters_C12.dat
[09:21:13.894] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters_C13.dat
[09:21:13.894] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters_C14.dat
[09:21:13.894] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters_C15.dat
[09:21:13.894] INFO: PixTestPretest::doTest() done, duration: 57 seconds
[09:21:13.894] DEBUG: <PixTestPretest.cc/~PixTestPretest:L134> PixTestPretest dtor
[09:21:13.967] INFO: enter test to run
[09:21:13.967] INFO: test: Fulltest no parameter change
[09:21:13.967] INFO: running: fulltest
[09:21:13.967] DEBUG: <PixTestFullTest.cc/init:L49> PixTestFullTest::init()
[09:21:13.967] DEBUG: <PixTestFullTest.cc/PixTestFullTest:L20> PixTestFullTest ctor(PixSetup &a, string, TGTab *)
[09:21:13.968] INFO: ######################################################################
[09:21:13.968] INFO: PixTestFullTest::doTest()
[09:21:13.968] INFO: ######################################################################
[09:21:13.968] DEBUG: <PixTestAlive.cc/init:L77> PixTestAlive::init()
[09:21:13.968] DEBUG: <PixTestAlive.cc/PixTestAlive:L21> PixTestAlive ctor(PixSetup &a, string, TGTab *)
[09:21:13.969] INFO: ######################################################################
[09:21:13.969] INFO: PixTestAlive::doTest()
[09:21:13.969] INFO: ######################################################################
[09:21:13.971] INFO: ----------------------------------------------------------------------
[09:21:13.971] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[09:21:13.971] INFO: ----------------------------------------------------------------------
[09:21:13.973] DEBUG: <PixTest.cc/efficiencyMaps:L328> attempt #0
[09:21:17.698] INFO: Test took 3725ms.
[09:21:17.717] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:21:17.717] DEBUG: <PixTest.cc/efficiencyMaps:L339> eff result size = 66532
[09:21:17.717] DEBUG: <PixTest.cc/efficiencyMaps:L344> Create hists PixelAlive_C0 .. PixelAlive_C15
[09:21:17.957] INFO: PixTestAlive::aliveTest() done
[09:21:17.957] INFO: number of dead pixels (per ROC): 2 0 0 0 0 0 1 4 6 2 1 0 0 4 0 8
[09:21:17.957] DEBUG: <PixTestAlive.cc/aliveTest:L188> number of red-efficiency pixels: 2 0 0 0 0 0 1 4 6 2 1 0 0 4 0 8
[09:21:17.959] INFO: ----------------------------------------------------------------------
[09:21:17.959] INFO: PixTestAlive::maskTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[09:21:17.959] INFO: ----------------------------------------------------------------------
[09:21:17.961] DEBUG: <PixTest.cc/efficiencyMaps:L328> attempt #0
[09:21:20.634] INFO: Test took 2673ms.
[09:21:20.637] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:21:20.637] DEBUG: <PixTest.cc/efficiencyMaps:L339> eff result size = 0
[09:21:20.637] DEBUG: <PixTest.cc/efficiencyMaps:L344> Create hists MaskTest_C0 .. MaskTest_C15
[09:21:20.637] INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[09:21:20.876] INFO: PixTestAlive::maskTest() done
[09:21:20.876] INFO: number of mask-defect pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[09:21:20.878] INFO: ----------------------------------------------------------------------
[09:21:20.878] INFO: PixTestAlive::addressDecodingTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[09:21:20.878] INFO: ----------------------------------------------------------------------
[09:21:20.880] DEBUG: <PixTest.cc/efficiencyMaps:L328> attempt #0
[09:21:24.550] INFO: Test took 3670ms.
[09:21:24.568] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:21:24.568] DEBUG: <PixTest.cc/efficiencyMaps:L339> eff result size = 66533
[09:21:24.568] DEBUG: <PixTest.cc/efficiencyMaps:L344> Create hists AddressDecodingTest_C0 .. AddressDecodingTest_C15
[09:21:24.810] INFO: PixTestAlive::addressDecodingTest() done
[09:21:24.810] INFO: number of address-decoding pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[09:21:24.810] INFO: PixTestAlive::doTest() done, duration: 10 seconds
[09:21:24.810] DEBUG: <PixTestAlive.cc/~PixTestAlive:L109> PixTestAlive dtor
[09:21:24.815] DEBUG: <PixTestBBMap.cc/init:L79> PixTestBBMap::init()
[09:21:24.816] DEBUG: <PixTestBBMap.cc/PixTestBBMap:L27> PixTestBBMap ctor(PixSetup &a, string, TGTab *)
[09:21:24.817] INFO: ######################################################################
[09:21:24.817] INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[09:21:24.817] INFO: ######################################################################
[09:21:24.822] INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (30) hits flags = 2 (plus default)
[09:21:24.834] INFO: dacScan step from 0 .. 29
[09:21:24.834] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:21:42.658] INFO: Test took 17824ms.
[09:21:42.694] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:21:42.694] INFO: dacScan step from 30 .. 59
[09:21:42.694] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:22:02.717] INFO: Test took 20023ms.
[09:22:02.863] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:22:02.892] INFO: dacScan step from 60 .. 89
[09:22:02.892] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:22:27.312] INFO: Test took 24420ms.
[09:22:27.571] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:22:27.653] INFO: dacScan step from 90 .. 119
[09:22:27.654] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:22:52.448] INFO: Test took 24794ms.
[09:22:52.700] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:22:52.782] INFO: dacScan step from 120 .. 149
[09:22:52.782] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:23:16.079] INFO: Test took 23297ms.
[09:23:16.336] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:23:16.430] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[09:23:18.064] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[09:23:19.334] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[09:23:20.588] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[09:23:21.798] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[09:23:23.005] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[09:23:24.285] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[09:23:25.458] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[09:23:26.721] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[09:23:27.955] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[09:23:29.204] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[09:23:30.463] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[09:23:31.692] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[09:23:32.917] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[09:23:34.141] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[09:23:35.352] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[09:23:36.610] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 261898240
[09:23:36.659] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C0_V0
[09:23:36.659] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 89 (obtained for minval = 0) start: 89 .. 109 last peak: 51.0365 last sigma: 5.87743 lcuts[0] = 68.6688 lcuts[1] = 109.811
[09:23:36.660] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C1_V0
[09:23:36.660] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 78 (obtained for minval = 0) start: 78 .. 96 last peak: 44.3956 last sigma: 5.23136 lcuts[0] = 60.0897 lcuts[1] = 96.7093
[09:23:36.660] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C2_V0
[09:23:36.661] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 84 (obtained for minval = 0) start: 84 .. 102 last peak: 49.8164 last sigma: 5.26418 lcuts[0] = 65.6089 lcuts[1] = 102.458
[09:23:36.661] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C3_V0
[09:23:36.661] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 82 (obtained for minval = 0) start: 82 .. 102 last peak: 46.123 last sigma: 5.6504 lcuts[0] = 63.0742 lcuts[1] = 102.627
[09:23:36.662] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C4_V0
[09:23:36.662] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 87 (obtained for minval = 0) start: 87 .. 110 last peak: 45.9412 last sigma: 6.40673 lcuts[0] = 65.1614 lcuts[1] = 110.008
[09:23:36.663] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C5_V0
[09:23:36.663] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 98 (obtained for minval = 0) start: 98 .. 119 last peak: 58.6799 last sigma: 6.07897 lcuts[0] = 76.9169 lcuts[1] = 119.47
[09:23:36.663] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C6_V0
[09:23:36.664] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 74 (obtained for minval = 0) start: 74 .. 88 last peak: 47.0014 last sigma: 4.16431 lcuts[0] = 59.4943 lcuts[1] = 88.6445
[09:23:36.664] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C7_V0
[09:23:36.665] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 95 (obtained for minval = 0) start: 95 .. 115 last peak: 57.1201 last sigma: 5.84636 lcuts[0] = 74.6592 lcuts[1] = 115.584
[09:23:36.665] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C8_V0
[09:23:36.665] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 80 (obtained for minval = 0) start: 80 .. 98 last peak: 48.2819 last sigma: 4.97879 lcuts[0] = 63.2182 lcuts[1] = 98.0698
[09:23:36.666] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C9_V0
[09:23:36.666] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 90 (obtained for minval = 0) start: 90 .. 109 last peak: 53.3748 last sigma: 5.65042 lcuts[0] = 70.3261 lcuts[1] = 109.879
[09:23:36.666] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C10_V0
[09:23:36.667] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 91 (obtained for minval = 0) start: 91 .. 111 last peak: 55.4771 last sigma: 5.55881 lcuts[0] = 72.1535 lcuts[1] = 111.065
[09:23:36.667] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C11_V0
[09:23:36.667] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 79 (obtained for minval = 0) start: 79 .. 96 last peak: 49.3611 last sigma: 4.67642 lcuts[0] = 63.3903 lcuts[1] = 96.1253
[09:23:36.668] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C12_V0
[09:23:36.668] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 88 (obtained for minval = 0) start: 88 .. 110 last peak: 48.6394 last sigma: 6.17978 lcuts[0] = 67.1787 lcuts[1] = 110.437
[09:23:36.668] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C13_V0
[09:23:36.669] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 81 (obtained for minval = 0) start: 81 .. 98 last peak: 48.8834 last sigma: 4.95132 lcuts[0] = 63.7373 lcuts[1] = 98.3966
[09:23:36.669] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C14_V0
[09:23:36.670] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 82 (obtained for minval = 0) start: 82 .. 100 last peak: 47.2689 last sigma: 5.34531 lcuts[0] = 63.3048 lcuts[1] = 100.722
[09:23:36.670] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C15_V0
[09:23:36.670] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 93 (obtained for minval = 0) start: 93 .. 115 last peak: 50.7413 last sigma: 6.51276 lcuts[0] = 70.2796 lcuts[1] = 115.869
[09:23:36.672] INFO: PixTestBBMap::doTest() done, duration: 131 seconds
[09:23:36.672] INFO: number of dead bumps (per ROC): 1 1 1 0 0 1 2 0 1 0 0 0 0 1 0 1
[09:23:36.672] INFO: separation cut (per ROC): 90 79 85 83 88 99 75 96 81 91 92 80 89 82 83 94
[09:23:36.672] DEBUG: <PixTestBBMap.cc/~PixTestBBMap:L97> PixTestBBMap dtor
[09:23:36.710] DEBUG: <PixTestScurves.cc/setParameter:L92> set fOutputFilename =
[09:23:36.712] INFO: ######################################################################
[09:23:36.712] INFO: PixTestScurves::fullTest() ntrig = 50
[09:23:36.712] INFO: ######################################################################
[09:23:36.712] INFO: ----------------------------------------------------------------------
[09:23:36.712] INFO: PixTestScurves::scurves(Vcal), ntrig = 50
[09:23:36.712] INFO: ----------------------------------------------------------------------
[09:23:36.712] INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 0 .. 149 (10) hits flags = 16 (plus default)
[09:23:36.721] INFO: dacScan step from 0 .. 9
[09:23:36.721] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:24:10.822] INFO: Test took 34101ms.
[09:24:10.890] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:24:10.890] INFO: dacScan step from 10 .. 19
[09:24:10.890] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:24:45.184] INFO: Test took 34294ms.
[09:24:45.249] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:24:45.250] INFO: dacScan step from 20 .. 29
[09:24:45.250] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:25:19.363] INFO: Test took 34113ms.
[09:25:19.432] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:25:19.432] INFO: dacScan step from 30 .. 39
[09:25:19.432] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:25:53.424] INFO: Test took 33992ms.
[09:25:53.488] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:25:53.488] INFO: dacScan step from 40 .. 49
[09:25:53.489] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:26:27.609] INFO: Test took 34120ms.
[09:26:27.675] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:26:27.675] INFO: dacScan step from 50 .. 59
[09:26:27.676] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:27:01.900] INFO: Test took 34224ms.
[09:27:01.968] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:27:01.968] INFO: dacScan step from 60 .. 69
[09:27:01.968] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:27:36.233] INFO: Test took 34265ms.
[09:27:36.298] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:27:36.298] INFO: dacScan step from 70 .. 79
[09:27:36.298] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:28:10.598] INFO: Test took 34300ms.
[09:28:10.667] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:28:10.667] INFO: dacScan step from 80 .. 89
[09:28:10.667] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0









[09:28:45.422] INFO: Test took 34755ms.
[09:28:45.544] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:28:45.548] INFO: dacScan step from 90 .. 99
[09:28:45.548] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0





[09:29:24.662] INFO: Test took 39114ms.
[09:29:24.944] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:29:24.959] INFO: dacScan step from 100 .. 109
[09:29:24.959] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0









[09:30:13.140] INFO: Test took 48181ms.
[09:30:13.614] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:30:13.638] INFO: dacScan step from 110 .. 119
[09:30:13.638] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0












[09:31:09.147] INFO: Test took 55509ms.
[09:31:09.718] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:31:09.754] INFO: dacScan step from 120 .. 129
[09:31:09.754] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0





[09:32:07.846] INFO: Test took 58092ms.
[09:32:08.432] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:32:08.464] INFO: dacScan step from 130 .. 139
[09:32:08.464] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0




[09:33:06.425] INFO: Test took 57961ms.
[09:33:06.989] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:33:07.021] INFO: dacScan step from 140 .. 149
[09:33:07.021] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0




[09:34:03.589] INFO: Test took 56568ms.
[09:34:04.168] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:34:04.198] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[09:34:04.198] INFO: dumping ASCII scurve output file: SCurveData
[09:34:05.444] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[09:34:05.444] INFO: dumping ASCII scurve output file: SCurveData
[09:34:06.728] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[09:34:06.728] INFO: dumping ASCII scurve output file: SCurveData
[09:34:08.010] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[09:34:08.010] INFO: dumping ASCII scurve output file: SCurveData
[09:34:09.594] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[09:34:09.594] INFO: dumping ASCII scurve output file: SCurveData
[09:34:11.267] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[09:34:11.267] INFO: dumping ASCII scurve output file: SCurveData
[09:34:12.582] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[09:34:12.582] INFO: dumping ASCII scurve output file: SCurveData
[09:34:14.108] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[09:34:14.108] INFO: dumping ASCII scurve output file: SCurveData
[09:34:15.376] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[09:34:15.376] INFO: dumping ASCII scurve output file: SCurveData
[09:34:16.635] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[09:34:16.635] INFO: dumping ASCII scurve output file: SCurveData
[09:34:17.881] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[09:34:17.881] INFO: dumping ASCII scurve output file: SCurveData
[09:34:19.134] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[09:34:19.134] INFO: dumping ASCII scurve output file: SCurveData
[09:34:20.389] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[09:34:20.389] INFO: dumping ASCII scurve output file: SCurveData
[09:34:21.652] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[09:34:21.652] INFO: dumping ASCII scurve output file: SCurveData
[09:34:22.904] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[09:34:22.904] INFO: dumping ASCII scurve output file: SCurveData
[09:34:24.151] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[09:34:24.151] INFO: dumping ASCII scurve output file: SCurveData
[09:34:25.365] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 571244544
[09:34:25.413] INFO: PixTestScurves::scurves() done
[09:34:25.414] INFO: Vcal mean: 102.49 92.34 93.32 99.61 111.90 110.66 92.21 105.03 99.32 104.71 109.11 104.98 97.40 94.83 101.28 112.55
[09:34:25.414] INFO: Vcal RMS: 6.31 4.99 4.89 5.47 10.17 5.41 5.19 6.65 6.86 5.47 5.44 5.54 5.17 6.12 5.47 8.65
[09:34:25.414] INFO: PixTestScurves::fullTest() done, duration: 648 seconds
[09:34:25.414] DEBUG: <PixTestScurves.cc/~PixTestScurves:L141> PixTestScurves dtor
[09:34:25.477] INFO: ######################################################################
[09:34:25.477] INFO: PixTestTrim::doTest()
[09:34:25.477] INFO: ######################################################################
[09:34:25.478] INFO: ----------------------------------------------------------------------
[09:34:25.478] INFO: PixTestTrim::trimTest() ntrig = 10, vcal = 35
[09:34:25.478] INFO: ----------------------------------------------------------------------
[09:34:25.547] INFO: ---> VthrComp thr map (minimal VthrComp)
[09:34:25.548] INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 5 dacrange: 0 .. 159 (20) hits flags = 16 (plus default)
[09:34:25.557] INFO: dacScan step from 0 .. 19
[09:34:25.557] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:34:38.097] INFO: Test took 12540ms.
[09:34:38.123] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:34:38.123] INFO: dacScan step from 20 .. 39
[09:34:38.123] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:34:50.733] INFO: Test took 12610ms.
[09:34:50.757] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:34:50.757] INFO: dacScan step from 40 .. 59
[09:34:50.757] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:35:03.325] INFO: Test took 12568ms.
[09:35:03.349] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:35:03.349] INFO: dacScan step from 60 .. 79
[09:35:03.349] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:35:15.903] INFO: Test took 12553ms.
[09:35:15.925] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:35:15.925] INFO: dacScan step from 80 .. 99
[09:35:15.925] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:35:28.541] INFO: Test took 12616ms.
[09:35:28.575] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:35:28.577] INFO: dacScan step from 100 .. 119
[09:35:28.577] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:35:43.112] INFO: Test took 14535ms.
[09:35:43.240] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:35:43.267] INFO: dacScan step from 120 .. 139
[09:35:43.267] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:36:00.518] INFO: Test took 17251ms.
[09:36:00.685] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:36:00.722] INFO: dacScan step from 140 .. 159
[09:36:00.722] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:36:14.130] INFO: Test took 13408ms.
[09:36:14.232] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:36:14.250] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[09:36:15.470] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[09:36:16.575] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[09:36:17.691] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[09:36:18.833] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[09:36:19.959] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[09:36:21.144] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[09:36:22.256] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[09:36:23.450] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[09:36:24.581] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[09:36:25.755] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[09:36:26.933] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[09:36:28.097] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[09:36:29.265] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[09:36:30.424] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[09:36:31.565] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[09:36:32.764] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 571265024
[09:36:32.766] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 100.422 minThrLimit = 100.378 minThrNLimit = 121.348 -> result = 100.422 -> 100
[09:36:32.767] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 91.2435 minThrLimit = 91.1965 minThrNLimit = 109.891 -> result = 91.2435 -> 91
[09:36:32.767] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 93.781 minThrLimit = 93.7488 minThrNLimit = 114.339 -> result = 93.781 -> 93
[09:36:32.767] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 98.9134 minThrLimit = 98.9075 minThrNLimit = 119.355 -> result = 98.9134 -> 98
[09:36:32.768] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 98.6685 minThrLimit = 98.5821 minThrNLimit = 115.183 -> result = 98.6685 -> 98
[09:36:32.768] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 108.79 minThrLimit = 108.599 minThrNLimit = 133.401 -> result = 108.79 -> 108
[09:36:32.768] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 91.7271 minThrLimit = 91.7215 minThrNLimit = 110.533 -> result = 91.7271 -> 91
[09:36:32.769] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 101.833 minThrLimit = 101.831 minThrNLimit = 126.529 -> result = 101.833 -> 101
[09:36:32.769] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 96.1658 minThrLimit = 96.125 minThrNLimit = 115.993 -> result = 96.1658 -> 96
[09:36:32.769] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 102.388 minThrLimit = 102.341 minThrNLimit = 124.056 -> result = 102.388 -> 102
[09:36:32.770] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 103.581 minThrLimit = 103.554 minThrNLimit = 127.495 -> result = 103.581 -> 103
[09:36:32.770] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 102.865 minThrLimit = 102.857 minThrNLimit = 124.568 -> result = 102.865 -> 102
[09:36:32.770] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 100.319 minThrLimit = 100.313 minThrNLimit = 123.018 -> result = 100.319 -> 100
[09:36:32.771] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 98.5502 minThrLimit = 98.5476 minThrNLimit = 121.697 -> result = 98.5502 -> 98
[09:36:32.771] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 100.548 minThrLimit = 100.521 minThrNLimit = 119.733 -> result = 100.548 -> 100
[09:36:32.771] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 104.898 minThrLimit = 104.732 minThrNLimit = 131.013 -> result = 104.898 -> 104
[09:36:32.771] INFO: ROC 0 VthrComp = 100
[09:36:32.771] INFO: ROC 1 VthrComp = 91
[09:36:32.772] INFO: ROC 2 VthrComp = 93
[09:36:32.772] INFO: ROC 3 VthrComp = 98
[09:36:32.772] INFO: ROC 4 VthrComp = 98
[09:36:32.772] INFO: ROC 5 VthrComp = 108
[09:36:32.772] INFO: ROC 6 VthrComp = 91
[09:36:32.773] INFO: ROC 7 VthrComp = 101
[09:36:32.773] INFO: ROC 8 VthrComp = 96
[09:36:32.773] INFO: ROC 9 VthrComp = 102
[09:36:32.773] INFO: ROC 10 VthrComp = 103
[09:36:32.773] INFO: ROC 11 VthrComp = 102
[09:36:32.773] INFO: ROC 12 VthrComp = 100
[09:36:32.774] INFO: ROC 13 VthrComp = 98
[09:36:32.774] INFO: ROC 14 VthrComp = 100
[09:36:32.774] INFO: ROC 15 VthrComp = 104
[09:36:32.774] INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[09:36:32.774] INFO: ---> dac: vcal name: TrimThr1 ntrig: 5 dacrange: 0 .. 159 (20) hits flags = 16 (plus default)
[09:36:32.783] INFO: dacScan step from 0 .. 19
[09:36:32.783] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:36:45.123] INFO: Test took 12340ms.
[09:36:45.145] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:36:45.145] INFO: dacScan step from 20 .. 39
[09:36:45.145] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:36:57.834] INFO: Test took 12689ms.
[09:36:57.865] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:36:57.868] INFO: dacScan step from 40 .. 59
[09:36:57.868] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:37:13.184] INFO: Test took 15316ms.
[09:37:13.331] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:37:13.369] INFO: dacScan step from 60 .. 79
[09:37:13.369] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:37:30.493] INFO: Test took 17124ms.
[09:37:30.663] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:37:30.719] INFO: dacScan step from 80 .. 99
[09:37:30.719] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:37:47.718] INFO: Test took 16999ms.
[09:37:47.882] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:37:47.936] INFO: dacScan step from 100 .. 119
[09:37:47.936] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:38:05.125] INFO: Test took 17189ms.
[09:38:05.287] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:38:05.341] INFO: dacScan step from 120 .. 139
[09:38:05.342] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:38:23.958] INFO: Test took 18616ms.
[09:38:24.122] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:38:24.175] INFO: dacScan step from 140 .. 159
[09:38:24.175] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:38:40.906] INFO: Test took 16731ms.
[09:38:41.068] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:38:41.121] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[09:38:42.503] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[09:38:43.881] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[09:38:45.247] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[09:38:46.622] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[09:38:48.033] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[09:38:49.426] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[09:38:50.790] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[09:38:52.159] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[09:38:53.521] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[09:38:54.887] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[09:38:56.256] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[09:38:57.643] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[09:38:58.986] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[09:39:00.328] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[09:39:01.703] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[09:39:03.099] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 571265024
[09:39:03.100] INFO: roc 0 with ID = 0 has maximal Vcal 60.9508 for pixel 0/77 mean/min/max = 46.4418/31.9201/60.9634
[09:39:03.101] INFO: roc 1 with ID = 1 has maximal Vcal 58.1268 for pixel 12/62 mean/min/max = 45.9641/33.7694/58.1588
[09:39:03.101] INFO: roc 2 with ID = 2 has maximal Vcal 56.8837 for pixel 24/48 mean/min/max = 45.4034/33.8295/56.9773
[09:39:03.101] INFO: roc 3 with ID = 3 has maximal Vcal 58.6044 for pixel 2/0 mean/min/max = 45.7425/32.4945/58.9905
[09:39:03.102] INFO: roc 4 with ID = 4 has maximal Vcal 69.1964 for pixel 24/73 mean/min/max = 50.662/31.9966/69.3273
[09:39:03.102] INFO: roc 5 with ID = 5 has maximal Vcal 67.5502 for pixel 1/0 mean/min/max = 51.0771/34.537/67.6172
[09:39:03.102] INFO: roc 6 with ID = 6 has maximal Vcal 58.9353 for pixel 51/3 mean/min/max = 46.6703/34.3746/58.9659
[09:39:03.102] INFO: roc 7 with ID = 7 has maximal Vcal 62.5151 for pixel 0/59 mean/min/max = 47.7047/32.8624/62.547
[09:39:03.103] INFO: roc 8 with ID = 8 has maximal Vcal 61.0281 for pixel 6/1 mean/min/max = 46.567/32.0954/61.0386
[09:39:03.103] INFO: roc 9 with ID = 9 has maximal Vcal 59.8452 for pixel 3/3 mean/min/max = 46.3763/32.8872/59.8655
[09:39:03.103] INFO: roc 10 with ID = 10 has maximal Vcal 62.4419 for pixel 5/71 mean/min/max = 48.1462/33.6651/62.6273
[09:39:03.103] INFO: roc 11 with ID = 11 has maximal Vcal 61.7497 for pixel 23/55 mean/min/max = 47.3397/32.9113/61.7682
[09:39:03.104] INFO: roc 12 with ID = 12 has maximal Vcal 57.4829 for pixel 17/0 mean/min/max = 44.7316/31.8637/57.5996
[09:39:03.104] INFO: roc 13 with ID = 13 has maximal Vcal 58.4484 for pixel 26/4 mean/min/max = 44.9881/31.4839/58.4922
[09:39:03.104] INFO: roc 14 with ID = 14 has maximal Vcal 58.9971 for pixel 25/2 mean/min/max = 45.4715/31.7552/59.1877
[09:39:03.104] INFO: roc 15 with ID = 15 has maximal Vcal 69.8812 for pixel 21/5 mean/min/max = 51.9793/34.0378/69.9208
[09:39:03.105] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:40:18.198] INFO: Test took 75093ms.
[09:40:18.981] DEBUG: <PixTestTrim.cc/trimTest:L309> vtrim: vcal = 35.7379 < 35 for itrim+1 = 109; old thr = 34.2867 ... break
[09:40:19.008] DEBUG: <PixTestTrim.cc/trimTest:L309> vtrim: vcal = 36.4397 < 35 for itrim+1 = 97; old thr = 34.0754 ... break
[09:40:19.037] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.2133 < 35 for itrim = 97; old thr = 34.3754 ... break
[09:40:19.065] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.1563 < 35 for itrim = 117; old thr = 34.8335 ... break
[09:40:19.078] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.0019 < 35 for itrim = 117; old thr = 34.3453 ... break
[09:40:19.106] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.1122 < 35 for itrim = 131; old thr = 33.3144 ... break
[09:40:19.128] DEBUG: <PixTestTrim.cc/trimTest:L309> vtrim: vcal = 36.2503 < 35 for itrim+1 = 100; old thr = 34.7562 ... break
[09:40:19.150] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.1802 < 35 for itrim = 114; old thr = 33.3346 ... break
[09:40:19.176] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 36.5181 < 35 for itrim = 112; old thr = 32.8241 ... break
[09:40:19.209] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.5599 < 35 for itrim = 115; old thr = 34.4335 ... break
[09:40:19.233] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.5084 < 35 for itrim = 128; old thr = 33.5016 ... break
[09:40:19.260] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.6339 < 35 for itrim = 120; old thr = 33.0292 ... break
[09:40:19.293] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.0946 < 35 for itrim = 117; old thr = 34.4779 ... break
[09:40:19.329] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.4047 < 35 for itrim = 119; old thr = 32.4509 ... break
[09:40:19.354] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.1349 < 35 for itrim = 112; old thr = 33.4867 ... break
[09:40:19.382] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.5044 < 35 for itrim = 138; old thr = 34.3376 ... break
[09:40:19.447] INFO: ---> dac: vcal name: TrimThr2 ntrig: 10 dacrange: 0 .. 199 (20) hits flags = 16 (plus default)
[09:40:19.456] INFO: dacScan step from 0 .. 19
[09:40:19.456] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:40:38.007] INFO: Test took 18551ms.
[09:40:38.057] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:40:38.059] INFO: dacScan step from 20 .. 39
[09:40:38.059] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:41:00.983] INFO: Test took 22924ms.
[09:41:01.214] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:41:01.250] INFO: dacScan step from 40 .. 59
[09:41:01.250] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:41:28.734] INFO: Test took 27484ms.
[09:41:29.012] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:41:29.070] INFO: dacScan step from 60 .. 79
[09:41:29.070] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:41:56.520] INFO: Test took 27450ms.
[09:41:56.794] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:41:56.850] INFO: dacScan step from 80 .. 99
[09:41:56.851] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:42:24.231] INFO: Test took 27380ms.
[09:42:24.511] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:42:24.566] INFO: dacScan step from 100 .. 119
[09:42:24.566] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:42:52.098] INFO: Test took 27532ms.
[09:42:52.380] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:42:52.435] INFO: dacScan step from 120 .. 139
[09:42:52.435] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:43:21.383] INFO: Test took 28948ms.
[09:43:21.659] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:43:21.714] INFO: dacScan step from 140 .. 159
[09:43:21.714] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:43:49.430] INFO: Test took 27716ms.
[09:43:49.711] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:43:49.765] INFO: dacScan step from 160 .. 179
[09:43:49.765] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:44:17.289] INFO: Test took 27524ms.
[09:44:17.573] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:44:17.628] INFO: dacScan step from 180 .. 199
[09:44:17.628] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:44:45.612] INFO: Test took 27984ms.
[09:44:45.894] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:44:45.970] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[09:44:47.384] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[09:44:48.782] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[09:44:50.149] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[09:44:51.561] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[09:44:52.993] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[09:44:54.417] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[09:44:55.805] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[09:44:57.196] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[09:44:58.722] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[09:45:00.117] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[09:45:01.529] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[09:45:02.941] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[09:45:04.308] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[09:45:05.660] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[09:45:07.085] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[09:45:08.520] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 576143360
[09:45:08.521] INFO: ---> TrimStepCorr4 extremal thresholds: 0.058151 .. 255.000000
[09:45:08.585] INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 4 dacrange: 0 .. 255 (20) hits flags = 16 (plus default)
[09:45:08.594] INFO: dacScan step from 0 .. 19
[09:45:08.594] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:45:19.971] INFO: Test took 11377ms.
[09:45:19.993] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:45:19.993] INFO: dacScan step from 20 .. 39
[09:45:19.993] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:45:31.989] INFO: Test took 11996ms.
[09:45:32.069] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:45:32.088] INFO: dacScan step from 40 .. 59
[09:45:32.089] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:45:46.439] INFO: Test took 14350ms.
[09:45:46.587] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:45:46.640] INFO: dacScan step from 60 .. 79
[09:45:46.640] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:46:01.686] INFO: Test took 15046ms.
[09:46:01.831] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:46:01.886] INFO: dacScan step from 80 .. 99
[09:46:01.886] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:46:16.913] INFO: Test took 15027ms.
[09:46:17.056] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:46:17.110] INFO: dacScan step from 100 .. 119
[09:46:17.110] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:46:32.236] INFO: Test took 15126ms.
[09:46:32.383] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:46:32.436] INFO: dacScan step from 120 .. 139
[09:46:32.437] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:46:49.066] INFO: Test took 16629ms.
[09:46:49.211] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:46:49.265] INFO: dacScan step from 140 .. 159
[09:46:49.265] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:47:04.623] INFO: Test took 15358ms.
[09:47:04.769] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:47:04.823] INFO: dacScan step from 160 .. 179
[09:47:04.824] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:47:20.107] INFO: Test took 15283ms.
[09:47:20.249] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:47:20.303] INFO: dacScan step from 180 .. 199
[09:47:20.303] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:47:36.356] INFO: Test took 16053ms.
[09:47:36.497] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:47:36.551] INFO: dacScan step from 200 .. 219
[09:47:36.551] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:47:51.686] INFO: Test took 15135ms.
[09:47:51.832] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:47:51.885] INFO: dacScan step from 220 .. 239
[09:47:51.885] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:48:07.031] INFO: Test took 15146ms.
[09:48:07.174] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:48:07.231] INFO: dacScan step from 240 .. 255
[09:48:07.231] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:48:19.504] INFO: Test took 12273ms.
[09:48:19.617] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:48:19.662] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[09:48:21.394] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[09:48:23.132] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[09:48:24.846] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[09:48:26.597] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[09:48:28.392] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[09:48:30.147] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[09:48:31.947] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[09:48:33.687] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[09:48:35.417] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[09:48:37.152] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[09:48:38.893] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[09:48:40.642] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[09:48:42.359] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[09:48:44.096] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[09:48:45.855] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[09:48:47.608] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 576143360
[09:48:47.676] INFO: ---> TrimStepCorr2 extremal thresholds: 2.800207 .. 64.651137
[09:48:47.739] INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 4 dacrange: 2 .. 74 (20) hits flags = 16 (plus default)
[09:48:47.748] INFO: dacScan step from 2 .. 21
[09:48:47.748] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:48:59.161] INFO: Test took 11413ms.
[09:48:59.185] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:48:59.185] INFO: dacScan step from 22 .. 41
[09:48:59.185] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:49:11.778] INFO: Test took 12593ms.
[09:49:11.870] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:49:11.893] INFO: dacScan step from 42 .. 61
[09:49:11.893] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:49:26.449] INFO: Test took 14556ms.
[09:49:26.597] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:49:26.651] INFO: dacScan step from 62 .. 74
[09:49:26.651] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:49:37.073] INFO: Test took 10422ms.
[09:49:37.167] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:49:37.206] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[09:49:38.590] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[09:49:39.789] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[09:49:40.935] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[09:49:42.140] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[09:49:43.316] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[09:49:44.494] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[09:49:45.506] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[09:49:46.525] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[09:49:47.553] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[09:49:48.576] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[09:49:49.583] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[09:49:50.595] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[09:49:51.599] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[09:49:52.606] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[09:49:53.619] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[09:49:54.627] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 576266240
[09:49:54.694] INFO: ---> TrimStepCorr1a extremal thresholds: 2.790106 .. 50.848150
[09:49:54.759] INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 4 dacrange: 2 .. 60 (20) hits flags = 16 (plus default)
[09:49:54.768] INFO: dacScan step from 2 .. 21
[09:49:54.768] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:50:06.132] INFO: Test took 11364ms.
[09:50:06.153] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:50:06.153] INFO: dacScan step from 22 .. 41
[09:50:06.153] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:50:18.596] INFO: Test took 12443ms.
[09:50:18.686] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:50:18.711] INFO: dacScan step from 42 .. 60
[09:50:18.711] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:50:32.810] INFO: Test took 14099ms.
[09:50:32.947] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:50:32.001] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[09:50:33.905] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[09:50:34.810] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[09:50:35.709] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[09:50:36.615] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[09:50:37.518] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[09:50:38.422] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[09:50:39.332] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[09:50:40.234] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[09:50:41.138] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[09:50:42.041] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[09:50:42.947] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[09:50:43.850] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[09:50:44.755] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[09:50:45.660] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[09:50:46.565] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[09:50:47.469] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 576266240
[09:50:47.536] INFO: ---> TrimStepCorr1b extremal thresholds: 2.790106 .. 50.848150
[09:50:47.599] INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 4 dacrange: 2 .. 60 (20) hits flags = 16 (plus default)
[09:50:47.608] INFO: dacScan step from 2 .. 21
[09:50:47.608] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:50:59.017] INFO: Test took 11409ms.
[09:50:59.042] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:50:59.042] INFO: dacScan step from 22 .. 41
[09:50:59.042] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:51:11.255] INFO: Test took 12213ms.
[09:51:11.344] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:51:11.367] INFO: dacScan step from 42 .. 60
[09:51:11.367] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:51:25.744] INFO: Test took 14377ms.
[09:51:25.887] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:51:25.947] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[09:51:26.867] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[09:51:27.789] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[09:51:28.709] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[09:51:29.630] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[09:51:30.553] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[09:51:31.472] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[09:51:32.405] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[09:51:33.339] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[09:51:34.275] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[09:51:35.210] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[09:51:36.147] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[09:51:37.082] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[09:51:38.024] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[09:51:38.967] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[09:51:39.888] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[09:51:40.809] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 576270336
[09:51:40.878] INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[09:51:40.878] INFO: ---> dac: vcal name: TrimThrFinal ntrig: 10 dacrange: 15 .. 55 (20) hits flags = 16 (plus default)
[09:51:40.887] INFO: dacScan step from 15 .. 34
[09:51:40.887] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:51:59.688] INFO: Test took 18801ms.
[09:51:59.760] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:51:59.770] INFO: dacScan step from 35 .. 54
[09:51:59.770] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:52:25.812] INFO: Test took 26042ms.
[09:52:26.108] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:52:26.167] INFO: dacScan step from 55 .. 55
[09:52:26.167] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:52:29.911] INFO: Test took 3744ms.
[09:52:29.928] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:52:29.932] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[09:52:30.669] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[09:52:31.405] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[09:52:32.140] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[09:52:32.872] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[09:52:33.598] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[09:52:34.335] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[09:52:35.083] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[09:52:35.826] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[09:52:36.566] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[09:52:37.306] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[09:52:38.045] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[09:52:38.788] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[09:52:39.533] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[09:52:40.280] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[09:52:41.022] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[09:52:41.763] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 576270336
[09:52:41.814] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C0.dat
[09:52:41.814] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C1.dat
[09:52:41.814] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C2.dat
[09:52:41.814] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C3.dat
[09:52:41.814] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C4.dat
[09:52:41.814] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C5.dat
[09:52:41.814] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C6.dat
[09:52:41.815] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C7.dat
[09:52:41.815] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C8.dat
[09:52:41.815] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C9.dat
[09:52:41.815] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C10.dat
[09:52:41.815] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C11.dat
[09:52:41.815] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C12.dat
[09:52:41.815] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C13.dat
[09:52:41.815] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C14.dat
[09:52:41.815] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C15.dat
[09:52:41.815] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//trimParameters35_C0.dat
[09:52:41.820] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//trimParameters35_C1.dat
[09:52:41.826] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//trimParameters35_C2.dat
[09:52:41.831] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//trimParameters35_C3.dat
[09:52:41.836] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//trimParameters35_C4.dat
[09:52:41.842] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//trimParameters35_C5.dat
[09:52:41.847] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//trimParameters35_C6.dat
[09:52:41.852] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//trimParameters35_C7.dat
[09:52:41.857] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//trimParameters35_C8.dat
[09:52:41.863] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//trimParameters35_C9.dat
[09:52:41.868] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//trimParameters35_C10.dat
[09:52:41.873] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//trimParameters35_C11.dat
[09:52:41.878] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//trimParameters35_C12.dat
[09:52:41.884] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//trimParameters35_C13.dat
[09:52:41.889] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//trimParameters35_C14.dat
[09:52:41.894] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//trimParameters35_C15.dat
[09:52:41.900] INFO: PixTestTrim::trimTest() done
[09:52:41.900] INFO: vtrim: 109 97 97 117 117 131 100 114 112 115 128 120 117 119 112 138
[09:52:41.900] INFO: vthrcomp: 100 91 93 98 98 108 91 101 96 102 103 102 100 98 100 104
[09:52:41.900] INFO: vcal mean: 35.07 34.96 35.08 35.06 35.13 35.10 35.11 35.06 35.12 35.12 35.08 35.13 35.04 35.02 35.09 35.06
[09:52:41.900] INFO: vcal RMS: 1.36 1.06 1.03 1.25 1.62 1.13 1.21 1.54 1.73 1.36 1.18 1.23 1.09 1.44 1.17 1.96
[09:52:41.900] INFO: bits mean: 9.62 9.61 9.74 10.09 9.28 8.62 9.10 9.05 9.54 9.57 9.31 9.80 10.36 10.57 10.19 8.71
[09:52:41.900] INFO: bits RMS: 2.68 2.50 2.44 2.38 2.36 2.37 2.58 2.70 2.64 2.57 2.46 2.37 2.39 2.30 2.44 2.30
[09:52:41.909] INFO: ----------------------------------------------------------------------
[09:52:41.909] INFO: PixTestTrim::trimBitTest() ntrig = 10, vtrims = 254 126 63 32
[09:52:41.909] INFO: ----------------------------------------------------------------------
[09:52:41.913] DEBUG: <PixTestTrim.cc/trimBitTest:L518> trimBitTest determine threshold map without trims
[09:52:41.913] INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 10 dacrange: 0 .. 199 (20) hits flags = 16 (plus default)
[09:52:41.922] INFO: dacScan step from 0 .. 19
[09:52:41.923] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:53:00.465] INFO: Test took 18542ms.
[09:53:00.505] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:53:00.505] INFO: dacScan step from 20 .. 39
[09:53:00.505] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:53:18.854] INFO: Test took 18349ms.
[09:53:18.894] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:53:18.894] INFO: dacScan step from 40 .. 59
[09:53:18.894] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:53:37.243] INFO: Test took 18349ms.
[09:53:37.284] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:53:37.284] INFO: dacScan step from 60 .. 79
[09:53:37.284] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:53:55.325] INFO: Test took 18041ms.
[09:53:55.362] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:53:55.362] INFO: dacScan step from 80 .. 99
[09:53:55.362] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:54:13.758] INFO: Test took 18395ms.
[09:54:13.797] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:54:13.797] INFO: dacScan step from 100 .. 119
[09:54:13.797] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:54:32.601] INFO: Test took 18804ms.
[09:54:32.669] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:54:32.674] INFO: dacScan step from 120 .. 139
[09:54:32.674] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:54:56.588] INFO: Test took 23914ms.
[09:54:56.801] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:54:56.826] INFO: dacScan step from 140 .. 159
[09:54:56.826] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:55:23.710] INFO: Test took 26884ms.
[09:55:23.993] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:55:24.045] INFO: dacScan step from 160 .. 179
[09:55:24.046] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:55:51.848] INFO: Test took 27802ms.
[09:55:52.127] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:55:52.180] INFO: dacScan step from 180 .. 199
[09:55:52.180] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:56:19.676] INFO: Test took 27496ms.
[09:56:19.952] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:56:20.006] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[09:56:21.375] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[09:56:22.819] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[09:56:24.226] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[09:56:25.591] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[09:56:26.928] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[09:56:28.263] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[09:56:29.648] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[09:56:31.005] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[09:56:32.368] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[09:56:33.730] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[09:56:35.081] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[09:56:36.444] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[09:56:37.827] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[09:56:39.227] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[09:56:40.602] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[09:56:41.948] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 576286720
[09:56:41.949] DEBUG: <PixTestTrim.cc/trimBitTest:L533> trimBitTest initDUT with trim bits = 14
[09:56:42.013] DEBUG: <PixTestTrim.cc/trimBitTest:L539> trimBitTest threshold map with trim = 14
[09:56:42.013] INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 10 dacrange: 0 .. 200 (20) hits flags = 16 (plus default)
[09:56:42.022] INFO: dacScan step from 0 .. 19
[09:56:42.023] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:57:00.367] INFO: Test took 18344ms.
[09:57:00.403] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:57:00.403] INFO: dacScan step from 20 .. 39
[09:57:00.403] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:57:18.802] INFO: Test took 18399ms.
[09:57:18.842] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:57:18.842] INFO: dacScan step from 40 .. 59
[09:57:18.842] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:57:37.216] INFO: Test took 18374ms.
[09:57:37.255] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:57:37.255] INFO: dacScan step from 60 .. 79
[09:57:37.255] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:57:55.428] INFO: Test took 18173ms.
[09:57:55.466] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:57:55.466] INFO: dacScan step from 80 .. 99
[09:57:55.466] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:58:13.595] INFO: Test took 18129ms.
[09:58:13.638] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:58:13.638] INFO: dacScan step from 100 .. 119
[09:58:13.638] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:58:33.744] INFO: Test took 20106ms.
[09:58:33.879] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:58:33.895] INFO: dacScan step from 120 .. 139
[09:58:33.895] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:59:00.502] INFO: Test took 26607ms.
[09:59:00.768] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:59:00.812] INFO: dacScan step from 140 .. 159
[09:59:00.812] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:59:28.513] INFO: Test took 27701ms.
[09:59:28.797] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:59:28.851] INFO: dacScan step from 160 .. 179
[09:59:28.852] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[09:59:56.737] INFO: Test took 27885ms.
[09:59:57.013] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:59:57.071] INFO: dacScan step from 180 .. 199
[09:59:57.071] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:00:24.719] INFO: Test took 27648ms.
[10:00:24.990] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:00:25.047] INFO: dacScan step from 200 .. 200
[10:00:25.047] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:00:28.790] INFO: Test took 3743ms.
[10:00:28.808] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:00:28.812] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[10:00:30.250] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[10:00:31.698] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[10:00:33.147] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[10:00:34.588] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[10:00:36.012] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[10:00:37.416] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[10:00:38.871] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[10:00:40.309] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[10:00:41.753] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[10:00:43.177] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[10:00:44.583] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[10:00:45.985] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[10:00:47.410] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[10:00:48.836] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[10:00:50.261] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[10:00:51.655] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 576286720
[10:00:51.656] DEBUG: <PixTestTrim.cc/trimBitTest:L533> trimBitTest initDUT with trim bits = 13
[10:00:51.720] DEBUG: <PixTestTrim.cc/trimBitTest:L539> trimBitTest threshold map with trim = 13
[10:00:51.720] INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 10 dacrange: 0 .. 186 (20) hits flags = 16 (plus default)
[10:00:51.729] INFO: dacScan step from 0 .. 19
[10:00:51.729] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:01:10.144] INFO: Test took 18415ms.
[10:01:10.181] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:01:10.181] INFO: dacScan step from 20 .. 39
[10:01:10.181] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:01:28.669] INFO: Test took 18488ms.
[10:01:28.707] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:01:28.707] INFO: dacScan step from 40 .. 59
[10:01:28.708] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:01:47.401] INFO: Test took 18693ms.
[10:01:47.439] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:01:47.440] INFO: dacScan step from 60 .. 79
[10:01:47.440] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:02:05.479] INFO: Test took 18039ms.
[10:02:05.516] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:02:05.516] INFO: dacScan step from 80 .. 99
[10:02:05.516] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:02:23.917] INFO: Test took 18401ms.
[10:02:23.958] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:02:23.958] INFO: dacScan step from 100 .. 119
[10:02:23.958] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:02:43.002] INFO: Test took 20044ms.
[10:02:44.135] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:02:44.152] INFO: dacScan step from 120 .. 139
[10:02:44.152] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:03:10.706] INFO: Test took 26554ms.
[10:03:10.972] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:03:11.014] INFO: dacScan step from 140 .. 159
[10:03:11.014] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:03:38.524] INFO: Test took 27510ms.
[10:03:38.811] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:03:38.866] INFO: dacScan step from 160 .. 179
[10:03:38.866] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:04:06.005] INFO: Test took 27139ms.
[10:04:06.284] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:04:06.341] INFO: dacScan step from 180 .. 186
[10:04:06.341] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:04:18.032] INFO: Test took 11691ms.
[10:04:18.130] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:04:18.151] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[10:04:19.471] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[10:04:20.816] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[10:04:22.154] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[10:04:23.477] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[10:04:24.769] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[10:04:26.047] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[10:04:27.389] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[10:04:28.692] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[10:04:30.011] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[10:04:31.317] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[10:04:32.604] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[10:04:33.900] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[10:04:35.228] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[10:04:36.566] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[10:04:37.892] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[10:04:39.180] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 576286720
[10:04:39.181] DEBUG: <PixTestTrim.cc/trimBitTest:L533> trimBitTest initDUT with trim bits = 11
[10:04:39.245] DEBUG: <PixTestTrim.cc/trimBitTest:L539> trimBitTest threshold map with trim = 11
[10:04:39.245] INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 10 dacrange: 0 .. 185 (20) hits flags = 16 (plus default)
[10:04:39.254] INFO: dacScan step from 0 .. 19
[10:04:39.254] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:04:57.721] INFO: Test took 18467ms.
[10:04:57.759] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:04:57.759] INFO: dacScan step from 20 .. 39
[10:04:57.760] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:05:16.306] INFO: Test took 18546ms.
[10:05:16.344] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:05:16.344] INFO: dacScan step from 40 .. 59
[10:05:16.344] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:05:34.716] INFO: Test took 18372ms.
[10:05:34.753] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:05:34.753] INFO: dacScan step from 60 .. 79
[10:05:34.753] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:05:53.104] INFO: Test took 18351ms.
[10:05:53.142] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:05:53.142] INFO: dacScan step from 80 .. 99
[10:05:53.142] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:06:11.205] INFO: Test took 18063ms.
[10:06:11.246] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:06:11.246] INFO: dacScan step from 100 .. 119
[10:06:11.246] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:06:31.437] INFO: Test took 20191ms.
[10:06:31.579] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:06:31.596] INFO: dacScan step from 120 .. 139
[10:06:31.596] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:06:58.263] INFO: Test took 26667ms.
[10:06:58.540] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:06:58.586] INFO: dacScan step from 140 .. 159
[10:06:58.586] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:07:25.497] INFO: Test took 26911ms.
[10:07:25.785] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:07:25.840] INFO: dacScan step from 160 .. 179
[10:07:25.840] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:07:53.557] INFO: Test took 27717ms.
[10:07:53.831] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:07:53.887] INFO: dacScan step from 180 .. 185
[10:07:53.887] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:08:04.317] INFO: Test took 10430ms.
[10:08:04.400] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:08:04.419] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[10:08:05.738] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[10:08:07.087] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[10:08:08.426] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[10:08:09.755] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[10:08:11.045] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[10:08:12.322] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[10:08:13.657] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[10:08:14.956] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[10:08:16.273] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[10:08:17.584] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[10:08:18.872] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[10:08:20.169] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[10:08:21.499] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[10:08:22.843] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[10:08:24.177] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[10:08:25.457] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 576286720
[10:08:25.457] DEBUG: <PixTestTrim.cc/trimBitTest:L533> trimBitTest initDUT with trim bits = 7
[10:08:25.520] DEBUG: <PixTestTrim.cc/trimBitTest:L539> trimBitTest threshold map with trim = 7
[10:08:25.520] INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 10 dacrange: 0 .. 185 (20) hits flags = 16 (plus default)
[10:08:25.529] INFO: dacScan step from 0 .. 19
[10:08:25.529] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:08:43.838] INFO: Test took 18309ms.
[10:08:43.874] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:08:43.875] INFO: dacScan step from 20 .. 39
[10:08:43.875] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:09:02.230] INFO: Test took 18355ms.
[10:09:02.272] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:09:02.272] INFO: dacScan step from 40 .. 59
[10:09:02.272] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:09:20.655] INFO: Test took 18383ms.
[10:09:20.693] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:09:20.693] INFO: dacScan step from 60 .. 79
[10:09:20.693] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:09:39.091] INFO: Test took 18398ms.
[10:09:39.134] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:09:39.134] INFO: dacScan step from 80 .. 99
[10:09:39.134] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:09:57.175] INFO: Test took 18041ms.
[10:09:57.214] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:09:57.214] INFO: dacScan step from 100 .. 119
[10:09:57.214] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:10:17.366] INFO: Test took 20152ms.
[10:10:17.497] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:10:17.513] INFO: dacScan step from 120 .. 139
[10:10:17.513] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:10:43.899] INFO: Test took 26386ms.
[10:10:44.164] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:10:44.209] INFO: dacScan step from 140 .. 159
[10:10:44.209] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:11:11.615] INFO: Test took 27405ms.
[10:11:11.897] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:11:11.952] INFO: dacScan step from 160 .. 179
[10:11:11.953] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:11:39.684] INFO: Test took 27731ms.
[10:11:39.967] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:11:40.023] INFO: dacScan step from 180 .. 185
[10:11:40.024] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[10:11:50.428] INFO: Test took 10404ms.
[10:11:50.513] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:11:50.532] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[10:11:51.852] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[10:11:53.195] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[10:11:54.532] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[10:11:55.856] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[10:11:57.147] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[10:11:58.418] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[10:11:59.759] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[10:12:01.064] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[10:12:02.383] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[10:12:03.689] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[10:12:04.976] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[10:12:06.271] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[10:12:07.596] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[10:12:08.926] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[10:12:10.241] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[10:12:11.517] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 576286720
[10:12:11.518] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 0 step 0: thr difference mean: 10.9543, thr difference RMS: 1.09402
[10:12:11.518] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 1 step 0: thr difference mean: 9.94056, thr difference RMS: 1.89775
[10:12:11.518] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 2 step 0: thr difference mean: 9.97845, thr difference RMS: 1.59998
[10:12:11.518] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 3 step 0: thr difference mean: 10.4241, thr difference RMS: 1.16374
[10:12:11.518] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 4 step 0: thr difference mean: 11.8229, thr difference RMS: 1.80789
[10:12:11.518] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 5 step 0: thr difference mean: 10.5986, thr difference RMS: 1.44975
[10:12:11.519] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 6 step 0: thr difference mean: 9.55953, thr difference RMS: 1.68676
[10:12:11.519] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 7 step 0: thr difference mean: 11.3129, thr difference RMS: 1.13572
[10:12:11.519] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 8 step 0: thr difference mean: 10.5414, thr difference RMS: 1.17134
[10:12:11.519] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 9 step 0: thr difference mean: 10.0648, thr difference RMS: 1.16875
[10:12:11.519] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 10 step 0: thr difference mean: 10.8117, thr difference RMS: 1.31413
[10:12:11.520] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 11 step 0: thr difference mean: 11.8278, thr difference RMS: 1.23964
[10:12:11.520] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 12 step 0: thr difference mean: 9.65032, thr difference RMS: 1.28401
[10:12:11.520] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 13 step 0: thr difference mean: 9.78452, thr difference RMS: 1.54598
[10:12:11.520] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 14 step 0: thr difference mean: 11.4839, thr difference RMS: 1.26351
[10:12:11.520] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 15 step 0: thr difference mean: 10.8256, thr difference RMS: 1.64226
[10:12:11.520] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 0 step 1: thr difference mean: 10.9623, thr difference RMS: 1.06911
[10:12:11.521] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 1 step 1: thr difference mean: 9.69636, thr difference RMS: 1.88843
[10:12:11.521] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 2 step 1: thr difference mean: 9.808, thr difference RMS: 1.56861
[10:12:11.521] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 3 step 1: thr difference mean: 10.3086, thr difference RMS: 1.1522
[10:12:11.521] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 4 step 1: thr difference mean: 11.8596, thr difference RMS: 2.08407
[10:12:11.521] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 5 step 1: thr difference mean: 10.6593, thr difference RMS: 1.44354
[10:12:11.521] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 6 step 1: thr difference mean: 9.38218, thr difference RMS: 1.67171
[10:12:11.522] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 7 step 1: thr difference mean: 11.1922, thr difference RMS: 1.09285
[10:12:11.522] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 8 step 1: thr difference mean: 10.3102, thr difference RMS: 1.14528
[10:12:11.522] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 9 step 1: thr difference mean: 9.84175, thr difference RMS: 1.14067
[10:12:11.522] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 10 step 1: thr difference mean: 10.6582, thr difference RMS: 1.29488
[10:12:11.522] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 11 step 1: thr difference mean: 11.8557, thr difference RMS: 1.22504
[10:12:11.522] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 12 step 1: thr difference mean: 9.38984, thr difference RMS: 1.28373
[10:12:11.523] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 13 step 1: thr difference mean: 9.51043, thr difference RMS: 1.52573
[10:12:11.523] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 14 step 1: thr difference mean: 11.4457, thr difference RMS: 1.25146
[10:12:11.523] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 15 step 1: thr difference mean: 10.9408, thr difference RMS: 1.66721
[10:12:11.523] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 0 step 2: thr difference mean: 11.3389, thr difference RMS: 1.07947
[10:12:11.523] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 1 step 2: thr difference mean: 10.0921, thr difference RMS: 1.89473
[10:12:11.523] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 2 step 2: thr difference mean: 10.0966, thr difference RMS: 1.56357
[10:12:11.524] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 3 step 2: thr difference mean: 10.5109, thr difference RMS: 1.1519
[10:12:11.524] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 4 step 2: thr difference mean: 12.1052, thr difference RMS: 2.22225
[10:12:11.524] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 5 step 2: thr difference mean: 10.8079, thr difference RMS: 1.43837
[10:12:11.524] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 6 step 2: thr difference mean: 9.54257, thr difference RMS: 1.66968
[10:12:11.524] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 7 step 2: thr difference mean: 11.4388, thr difference RMS: 1.10085
[10:12:11.524] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 8 step 2: thr difference mean: 10.6419, thr difference RMS: 1.14811
[10:12:11.525] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 9 step 2: thr difference mean: 10.0138, thr difference RMS: 1.15266
[10:12:11.525] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 10 step 2: thr difference mean: 10.8334, thr difference RMS: 1.28919
[10:12:11.525] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 11 step 2: thr difference mean: 12.2008, thr difference RMS: 1.21056
[10:12:11.525] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 12 step 2: thr difference mean: 9.71326, thr difference RMS: 1.29825
[10:12:11.525] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 13 step 2: thr difference mean: 9.87681, thr difference RMS: 1.52886
[10:12:11.526] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 14 step 2: thr difference mean: 11.6557, thr difference RMS: 1.26782
[10:12:11.526] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 15 step 2: thr difference mean: 10.9759, thr difference RMS: 1.63458
[10:12:11.526] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 0 step 3: thr difference mean: 10.9988, thr difference RMS: 1.05479
[10:12:11.526] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 1 step 3: thr difference mean: 9.72569, thr difference RMS: 1.8629
[10:12:11.526] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 2 step 3: thr difference mean: 9.70819, thr difference RMS: 1.54264
[10:12:11.526] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 3 step 3: thr difference mean: 10.3866, thr difference RMS: 1.12154
[10:12:11.527] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 4 step 3: thr difference mean: 11.9296, thr difference RMS: 2.34595
[10:12:11.527] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 5 step 3: thr difference mean: 10.7641, thr difference RMS: 1.41466
[10:12:11.527] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 6 step 3: thr difference mean: 9.3549, thr difference RMS: 1.65816
[10:12:11.527] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 7 step 3: thr difference mean: 11.1195, thr difference RMS: 1.05841
[10:12:11.527] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 8 step 3: thr difference mean: 10.3314, thr difference RMS: 1.12732
[10:12:11.527] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 9 step 3: thr difference mean: 9.80811, thr difference RMS: 1.13351
[10:12:11.528] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 10 step 3: thr difference mean: 10.5121, thr difference RMS: 1.27741
[10:12:11.528] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 11 step 3: thr difference mean: 11.9186, thr difference RMS: 1.18451
[10:12:11.528] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 12 step 3: thr difference mean: 9.39443, thr difference RMS: 1.27894
[10:12:11.528] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 13 step 3: thr difference mean: 9.39034, thr difference RMS: 1.52947
[10:12:11.528] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 14 step 3: thr difference mean: 11.4864, thr difference RMS: 1.24602
[10:12:11.528] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 15 step 3: thr difference mean: 10.9363, thr difference RMS: 1.6575
[10:12:11.645] INFO: PixTestTrim::trimBitTest() done
[10:12:11.647] INFO: PixTestTrim::doTest() done, duration: 2266 seconds
[10:12:11.647] DEBUG: <PixTestTrim.cc/~PixTestTrim:L104> PixTestTrim dtor
[10:12:12.225] DEBUG: <PixTest.cc/setTestParameter:L569> setting ntrig to new value 10
[10:12:12.225] DEBUG: <PixTestPhOptimization.cc/setParameter:L37> setting fParNtrig ->10<- from sval = 10
[10:12:12.225] DEBUG: <PixTestPhOptimization.cc/setParameter:L42> setting fSafetyMarginLow ->20<- from sval = 20
[10:12:12.225] DEBUG: <PixTestPhOptimization.cc/setParameter:L48> setting fVcalMax ->100<- from sval = 100
[10:12:12.225] DEBUG: <PixTestPhOptimization.cc/setParameter:L53> setting fQuantMax ->0.98<- from sval = 0.98
[10:12:12.225] INFO: ######################################################################
[10:12:12.225] INFO: PixTestPhOptimization::doTest() Ntrig = 10
[10:12:12.225] INFO: ######################################################################
[10:12:12.227] DEBUG: <PixTest.cc/efficiencyMaps:L328> attempt #0
[10:12:15.943] INFO: Test took 3716ms.
[10:12:15.963] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:12:15.963] DEBUG: <PixTest.cc/efficiencyMaps:L339> eff result size = 66527
[10:12:15.963] DEBUG: <PixTest.cc/efficiencyMaps:L344> Create hists PixelAlive_C0 .. PixelAlive_C15
[10:12:15.966] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [0, 51, 4] has eff 0/10
[10:12:15.966] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [0, 51, 4]
[10:12:15.966] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [0, 45, 36] has eff 0/10
[10:12:15.966] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [0, 45, 36]
[10:12:15.967] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [3, 38, 42] has eff 0/10
[10:12:15.967] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [3, 38, 42]
[10:12:15.967] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [4, 2, 54] has eff 0/10
[10:12:15.967] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [4, 2, 54]
[10:12:15.967] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [4, 49, 63] has eff 0/10
[10:12:15.967] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [4, 49, 63]
[10:12:15.967] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [4, 2, 74] has eff 0/10
[10:12:15.967] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [4, 2, 74]
[10:12:15.967] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [4, 1, 75] has eff 0/10
[10:12:15.967] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [4, 1, 75]
[10:12:15.967] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [4, 1, 76] has eff 0/10
[10:12:15.967] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [4, 1, 76]
[10:12:15.967] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [4, 2, 77] has eff 9/10
[10:12:15.967] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [4, 2, 77]
[10:12:15.967] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [6, 1, 79] has eff 0/10
[10:12:15.967] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [6, 1, 79]
[10:12:15.967] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [7, 48, 0] has eff 0/10
[10:12:15.967] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [7, 48, 0]
[10:12:15.967] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [7, 49, 0] has eff 0/10
[10:12:15.967] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [7, 49, 0]
[10:12:15.967] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [7, 50, 0] has eff 0/10
[10:12:15.967] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [7, 50, 0]
[10:12:15.967] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [7, 51, 0] has eff 0/10
[10:12:15.967] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [7, 51, 0]
[10:12:15.967] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [8, 0, 0] has eff 0/10
[10:12:15.967] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [8, 0, 0]
[10:12:15.967] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [8, 1, 0] has eff 0/10
[10:12:15.967] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [8, 1, 0]
[10:12:15.967] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [8, 2, 0] has eff 0/10
[10:12:15.967] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [8, 2, 0]
[10:12:15.967] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [8, 3, 0] has eff 0/10
[10:12:15.967] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [8, 3, 0]
[10:12:15.967] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [8, 0, 1] has eff 0/10
[10:12:15.967] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [8, 0, 1]
[10:12:15.967] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [8, 2, 1] has eff 0/10
[10:12:15.967] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [8, 2, 1]
[10:12:15.968] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [9, 50, 79] has eff 0/10
[10:12:15.968] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [9, 50, 79]
[10:12:15.968] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [9, 51, 79] has eff 0/10
[10:12:15.968] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [9, 51, 79]
[10:12:15.968] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [10, 2, 75] has eff 9/10
[10:12:15.968] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [10, 2, 75]
[10:12:15.968] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [11, 50, 51] has eff 0/10
[10:12:15.968] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [11, 50, 51]
[10:12:15.968] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [13, 30, 7] has eff 0/10
[10:12:15.968] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [13, 30, 7]
[10:12:15.968] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [13, 31, 7] has eff 0/10
[10:12:15.968] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [13, 31, 7]
[10:12:15.968] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [13, 51, 79] has eff 0/10
[10:12:15.968] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [13, 51, 79]
[10:12:15.968] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [15, 43, 0] has eff 0/10
[10:12:15.968] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [15, 43, 0]
[10:12:15.968] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [15, 47, 0] has eff 0/10
[10:12:15.968] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [15, 47, 0]
[10:12:15.968] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [15, 48, 0] has eff 0/10
[10:12:15.968] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [15, 48, 0]
[10:12:15.968] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [15, 49, 0] has eff 0/10
[10:12:15.968] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [15, 49, 0]
[10:12:15.968] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [15, 50, 0] has eff 0/10
[10:12:15.968] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [15, 50, 0]
[10:12:15.969] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [15, 51, 0] has eff 0/10
[10:12:15.969] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [15, 51, 0]
[10:12:15.969] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [15, 50, 1] has eff 0/10
[10:12:15.969] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [15, 50, 1]
[10:12:15.969] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [15, 51, 1] has eff 0/10
[10:12:15.969] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [15, 51, 1]
[10:12:15.973] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L239> Number of bad pixels found: 35
[10:12:15.973] DEBUG: <PixTestPhOptimization.cc/doTest:L124> **********Ph range will be optimised on the whole ROC***********
[10:12:15.973] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L276> ROC type is newer than digv2
[10:12:15.973] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L277> ROC type is psi46digv21respin
[10:12:16.163] DEBUG: <PixTest.cc/phMaps:L264> attempt #0
[10:12:19.867] INFO: Test took 3704ms.
[10:12:19.929] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:12:19.929] DEBUG: <PixTest.cc/phMaps:L275> eff result size = 66528
[10:12:19.929] DEBUG: <PixTest.cc/phMaps:L282> Create hists maxphmap_C0 .. maxphmap_C15
[10:12:19.933] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 171.373
[10:12:19.933] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,5] phvalue 172
[10:12:19.933] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 178.514
[10:12:19.933] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [6 ,5] phvalue 178
[10:12:19.933] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 192.472
[10:12:19.933] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,5] phvalue 192
[10:12:19.933] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 193.867
[10:12:19.933] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [4 ,6] phvalue 193
[10:12:19.933] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 181.013
[10:12:19.933] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [8 ,15] phvalue 181
[10:12:19.933] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 165.263
[10:12:19.933] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [4 ,5] phvalue 165
[10:12:19.933] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 176.085
[10:12:19.933] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,5] phvalue 176
[10:12:19.934] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 177.566
[10:12:19.934] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,5] phvalue 177
[10:12:19.934] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 189.706
[10:12:19.934] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [4 ,8] phvalue 189
[10:12:19.934] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 182.084
[10:12:19.934] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [4 ,5] phvalue 183
[10:12:19.934] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 184.968
[10:12:19.934] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,5] phvalue 185
[10:12:19.934] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 185.043
[10:12:19.934] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,5] phvalue 185
[10:12:19.934] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 185.116
[10:12:19.934] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,9] phvalue 186
[10:12:19.934] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 197.213
[10:12:19.934] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,5] phvalue 198
[10:12:19.934] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 180.921
[10:12:19.934] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [4 ,8] phvalue 181
[10:12:19.935] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 180.011
[10:12:19.935] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,5] phvalue 180
[10:12:19.935] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L427> ROC type is newer than digv2
[10:12:19.935] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L428> ROC type is psi46digv21respin
[10:12:19.935] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L450> init_phScale=150, flag_minPh = 0, minph = 0
[10:12:19.943] DEBUG: <PixTest.cc/phMaps:L264> attempt #0
[10:12:23.655] INFO: Test took 3712ms.
[10:12:23.718] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:12:23.718] DEBUG: <PixTest.cc/phMaps:L275> eff result size = 66528
[10:12:23.718] DEBUG: <PixTest.cc/phMaps:L282> Create hists minphmap_C0 .. minphmap_C15
[10:12:23.722] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L457> result size 0

[10:12:23.722] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L484> done. init_phScale=155, flag_minPh = 1, minph = 49minph_roc = 5
[10:12:23.722] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 61.9244
[10:12:23.722] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [6 ,49] phvalue 62
[10:12:23.722] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 74.2441
[10:12:23.722] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,13] phvalue 75
[10:12:23.723] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 84.3398
[10:12:23.723] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,25] phvalue 85
[10:12:23.723] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 78.2016
[10:12:23.723] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,32] phvalue 78
[10:12:23.723] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 70.8685
[10:12:23.723] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,13] phvalue 71
[10:12:23.723] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 53.6801
[10:12:23.723] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,13] phvalue 54
[10:12:23.723] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 74.8205
[10:12:23.723] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [8 ,12] phvalue 75
[10:12:23.723] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 67.7578
[10:12:23.723] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [6 ,66] phvalue 68
[10:12:23.723] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 88.0884
[10:12:23.723] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,13] phvalue 89
[10:12:23.723] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 81.5232
[10:12:23.724] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,7] phvalue 81
[10:12:23.724] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 75.2773
[10:12:23.724] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [5 ,67] phvalue 76
[10:12:23.724] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 77.1927
[10:12:23.724] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [4 ,12] phvalue 78
[10:12:23.724] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 82.9203
[10:12:23.724] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [4 ,66] phvalue 83
[10:12:23.724] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 100.629
[10:12:23.724] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [5 ,31] phvalue 101
[10:12:23.724] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 72.0976
[10:12:23.724] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [6 ,12] phvalue 73
[10:12:23.724] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 76.8573
[10:12:23.724] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,60] phvalue 77
[10:12:23.726] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 6, 49, 0 0
[10:12:23.726] INFO: The DUT currently contains the following objects:
[10:12:23.727] INFO: 2 TBM Cores tbm08c (2 ON)
[10:12:23.727] INFO: TBM Core alpha (0): 7 registers set
[10:12:23.727] INFO: TBM Core beta (1): 7 registers set
[10:12:23.727] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:12:23.727] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:23.727] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:23.727] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:23.727] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:23.727] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:23.727] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:23.727] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:23.727] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:23.727] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:23.727] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:23.727] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:23.727] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:23.727] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:23.727] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:23.727] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:23.727] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:24.817] INFO: Test took 1090ms.
[10:12:24.818] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[10:12:24.818] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 13, 1 1
[10:12:24.818] INFO: The DUT currently contains the following objects:
[10:12:24.818] INFO: 2 TBM Cores tbm08c (2 ON)
[10:12:24.818] INFO: TBM Core alpha (0): 7 registers set
[10:12:24.818] INFO: TBM Core beta (1): 7 registers set
[10:12:24.818] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:12:24.818] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:24.818] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:24.818] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:24.818] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:24.818] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:24.818] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:24.818] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:24.818] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:24.818] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:24.818] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:24.819] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:24.819] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:24.819] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:24.819] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:24.819] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:24.819] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:25.910] INFO: Test took 1091ms.
[10:12:25.911] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[10:12:25.911] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 25, 2 2
[10:12:25.911] INFO: The DUT currently contains the following objects:
[10:12:25.911] INFO: 2 TBM Cores tbm08c (2 ON)
[10:12:25.911] INFO: TBM Core alpha (0): 7 registers set
[10:12:25.911] INFO: TBM Core beta (1): 7 registers set
[10:12:25.911] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:12:25.912] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:25.912] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:25.912] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:25.912] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:25.912] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:25.912] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:25.912] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:25.912] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:25.912] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:25.912] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:25.912] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:25.912] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:25.912] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:25.912] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:25.912] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:25.912] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:27.004] INFO: Test took 1092ms.
[10:12:27.005] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[10:12:27.005] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 32, 3 3
[10:12:27.005] INFO: The DUT currently contains the following objects:
[10:12:27.005] INFO: 2 TBM Cores tbm08c (2 ON)
[10:12:27.005] INFO: TBM Core alpha (0): 7 registers set
[10:12:27.005] INFO: TBM Core beta (1): 7 registers set
[10:12:27.005] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:12:27.005] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:27.005] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:27.005] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:27.005] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:27.005] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:27.005] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:27.005] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:27.005] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:27.005] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:27.005] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:27.005] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:27.005] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:27.005] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:27.005] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:27.005] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:27.005] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:28.097] INFO: Test took 1092ms.
[10:12:28.098] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[10:12:28.098] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 13, 4 4
[10:12:28.099] INFO: The DUT currently contains the following objects:
[10:12:28.099] INFO: 2 TBM Cores tbm08c (2 ON)
[10:12:28.099] INFO: TBM Core alpha (0): 7 registers set
[10:12:28.099] INFO: TBM Core beta (1): 7 registers set
[10:12:28.099] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:12:28.099] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:28.099] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:28.099] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:28.099] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:28.099] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:28.099] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:28.099] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:28.099] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:28.099] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:28.099] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:28.099] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:28.099] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:28.099] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:28.099] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:28.099] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:28.099] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:29.190] INFO: Test took 1091ms.
[10:12:29.191] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[10:12:29.191] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 13, 5 5
[10:12:29.191] INFO: The DUT currently contains the following objects:
[10:12:29.191] INFO: 2 TBM Cores tbm08c (2 ON)
[10:12:29.191] INFO: TBM Core alpha (0): 7 registers set
[10:12:29.191] INFO: TBM Core beta (1): 7 registers set
[10:12:29.191] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:12:29.191] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:29.191] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:29.191] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:29.191] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:29.191] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:29.191] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:29.192] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:29.192] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:29.192] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:29.192] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:29.192] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:29.192] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:29.192] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:29.192] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:29.192] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:29.192] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:30.283] INFO: Test took 1091ms.
[10:12:30.284] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[10:12:30.284] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 8, 12, 6 6
[10:12:30.284] INFO: The DUT currently contains the following objects:
[10:12:30.284] INFO: 2 TBM Cores tbm08c (2 ON)
[10:12:30.284] INFO: TBM Core alpha (0): 7 registers set
[10:12:30.285] INFO: TBM Core beta (1): 7 registers set
[10:12:30.285] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:12:30.285] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:30.285] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:30.285] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:30.285] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:30.285] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:30.285] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:30.285] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:30.285] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:30.285] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:30.285] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:30.285] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:30.285] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:30.285] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:30.285] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:30.285] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:30.285] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:31.377] INFO: Test took 1092ms.
[10:12:31.378] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[10:12:31.378] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 6, 66, 7 7
[10:12:31.378] INFO: The DUT currently contains the following objects:
[10:12:31.378] INFO: 2 TBM Cores tbm08c (2 ON)
[10:12:31.378] INFO: TBM Core alpha (0): 7 registers set
[10:12:31.378] INFO: TBM Core beta (1): 7 registers set
[10:12:31.378] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:12:31.378] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:31.378] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:31.379] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:31.379] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:31.379] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:31.379] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:31.379] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:31.379] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:31.379] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:31.379] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:31.379] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:31.379] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:31.379] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:31.379] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:31.379] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:31.379] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:32.469] INFO: Test took 1090ms.
[10:12:32.470] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[10:12:32.470] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 13, 8 8
[10:12:32.470] INFO: The DUT currently contains the following objects:
[10:12:32.470] INFO: 2 TBM Cores tbm08c (2 ON)
[10:12:32.470] INFO: TBM Core alpha (0): 7 registers set
[10:12:32.470] INFO: TBM Core beta (1): 7 registers set
[10:12:32.470] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:12:32.470] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:32.470] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:32.470] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:32.470] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:32.470] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:32.470] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:32.470] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:32.470] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:32.470] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:32.470] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:32.470] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:32.470] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:32.470] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:32.470] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:32.470] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:32.470] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:33.563] INFO: Test took 1092ms.
[10:12:33.563] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[10:12:33.564] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 7, 9 9
[10:12:33.564] INFO: The DUT currently contains the following objects:
[10:12:33.564] INFO: 2 TBM Cores tbm08c (2 ON)
[10:12:33.564] INFO: TBM Core alpha (0): 7 registers set
[10:12:33.564] INFO: TBM Core beta (1): 7 registers set
[10:12:33.564] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:12:33.564] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:33.564] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:33.564] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:33.564] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:33.564] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:33.564] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:33.564] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:33.564] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:33.564] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:33.564] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:33.564] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:33.564] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:33.564] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:33.564] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:33.564] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:33.564] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:34.654] INFO: Test took 1090ms.
[10:12:34.655] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[10:12:34.655] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 5, 67, 10 10
[10:12:34.655] INFO: The DUT currently contains the following objects:
[10:12:34.655] INFO: 2 TBM Cores tbm08c (2 ON)
[10:12:34.655] INFO: TBM Core alpha (0): 7 registers set
[10:12:34.655] INFO: TBM Core beta (1): 7 registers set
[10:12:34.655] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:12:34.655] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:34.655] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:34.655] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:34.655] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:34.655] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:34.655] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:34.655] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:34.655] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:34.655] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:34.655] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:34.655] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:34.655] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:34.655] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:34.655] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:34.655] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:34.655] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:35.747] INFO: Test took 1092ms.
[10:12:35.748] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[10:12:35.748] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 4, 12, 11 11
[10:12:35.748] INFO: The DUT currently contains the following objects:
[10:12:35.748] INFO: 2 TBM Cores tbm08c (2 ON)
[10:12:35.748] INFO: TBM Core alpha (0): 7 registers set
[10:12:35.748] INFO: TBM Core beta (1): 7 registers set
[10:12:35.748] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:12:35.749] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:35.749] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:35.749] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:35.749] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:35.749] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:35.749] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:35.749] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:35.749] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:35.749] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:35.749] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:35.749] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:35.749] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:35.749] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:35.749] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:35.749] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:35.749] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:36.841] INFO: Test took 1092ms.
[10:12:36.842] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[10:12:36.842] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 4, 66, 12 12
[10:12:36.843] INFO: The DUT currently contains the following objects:
[10:12:36.843] INFO: 2 TBM Cores tbm08c (2 ON)
[10:12:36.843] INFO: TBM Core alpha (0): 7 registers set
[10:12:36.843] INFO: TBM Core beta (1): 7 registers set
[10:12:36.843] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:12:36.843] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:36.843] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:36.843] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:36.843] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:36.843] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:36.843] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:36.843] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:36.843] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:36.843] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:36.843] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:36.843] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:36.843] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:36.843] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:36.843] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:36.843] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:36.843] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:37.936] INFO: Test took 1093ms.
[10:12:37.937] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[10:12:37.937] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 5, 31, 13 13
[10:12:37.937] INFO: The DUT currently contains the following objects:
[10:12:37.937] INFO: 2 TBM Cores tbm08c (2 ON)
[10:12:37.937] INFO: TBM Core alpha (0): 7 registers set
[10:12:37.937] INFO: TBM Core beta (1): 7 registers set
[10:12:37.937] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:12:37.937] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:37.937] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:37.937] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:37.937] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:37.937] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:37.937] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:37.937] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:37.937] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:37.937] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:37.937] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:37.937] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:37.937] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:37.937] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:37.937] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:37.937] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:37.937] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:39.029] INFO: Test took 1092ms.
[10:12:39.030] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[10:12:39.030] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 6, 12, 14 14
[10:12:39.030] INFO: The DUT currently contains the following objects:
[10:12:39.030] INFO: 2 TBM Cores tbm08c (2 ON)
[10:12:39.030] INFO: TBM Core alpha (0): 7 registers set
[10:12:39.030] INFO: TBM Core beta (1): 7 registers set
[10:12:39.030] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:12:39.030] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:39.030] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:39.030] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:39.030] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:39.030] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:39.030] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:39.030] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:39.030] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:39.030] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:39.030] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:39.030] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:39.030] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:39.030] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:39.030] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:39.030] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:39.030] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:40.124] INFO: Test took 1094ms.
[10:12:40.125] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[10:12:40.125] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 60, 15 15
[10:12:40.125] INFO: The DUT currently contains the following objects:
[10:12:40.125] INFO: 2 TBM Cores tbm08c (2 ON)
[10:12:40.125] INFO: TBM Core alpha (0): 7 registers set
[10:12:40.125] INFO: TBM Core beta (1): 7 registers set
[10:12:40.125] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:12:40.125] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:40.125] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:40.125] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:40.125] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:40.125] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:40.125] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:40.125] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:40.125] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:40.125] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:40.125] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:40.125] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:40.125] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:40.126] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:40.126] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:40.126] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:40.126] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:12:41.218] INFO: Test took 1092ms.
[10:12:41.218] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[10:12:41.219] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 33 on ROC0
[10:12:41.219] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 30 on ROC1
[10:12:41.219] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 32 on ROC2
[10:12:41.219] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 30 on ROC3
[10:12:41.219] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 32 on ROC4
[10:12:41.219] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 33 on ROC5
[10:12:41.219] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 32 on ROC6
[10:12:41.219] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 32 on ROC7
[10:12:41.219] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 32 on ROC8
[10:12:41.219] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 33 on ROC9
[10:12:41.219] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 31 on ROC10
[10:12:41.219] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 31 on ROC11
[10:12:41.219] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 31 on ROC12
[10:12:41.219] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 33 on ROC13
[10:12:41.219] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 35 on ROC14
[10:12:41.219] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 31 on ROC15
[10:12:41.223] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:15:34.646] INFO: Test took 173423ms.
[10:15:36.202] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:18:30.510] INFO: Test took 174308ms.
[10:18:32.178] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[10:18:32.179] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip0
[10:18:32.179] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[10:18:32.179] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip1
[10:18:32.179] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[10:18:32.180] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip2
[10:18:32.180] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[10:18:32.180] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip3
[10:18:32.180] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[10:18:32.181] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip4
[10:18:32.181] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[10:18:32.181] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip5
[10:18:32.181] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[10:18:32.181] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip6
[10:18:32.181] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[10:18:32.182] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip7
[10:18:32.182] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[10:18:32.182] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip8
[10:18:32.182] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[10:18:32.182] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip9
[10:18:32.182] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[10:18:32.183] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip10
[10:18:32.183] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[10:18:32.183] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip11
[10:18:32.183] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[10:18:32.183] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip12
[10:18:32.183] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[10:18:32.184] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip13
[10:18:32.184] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[10:18:32.184] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip14
[10:18:32.184] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[10:18:32.184] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip15
[10:18:32.184] INFO: safety margin for low PH: adding 0, margin is now 20
[10:18:32.190] INFO: safety margin for low PH: adding 0, margin is now 20
[10:18:32.195] INFO: safety margin for low PH: adding 0, margin is now 20
[10:18:32.201] INFO: safety margin for low PH: adding 0, margin is now 20
[10:18:32.206] INFO: safety margin for low PH: adding 1, margin is now 21
[10:18:32.212] INFO: safety margin for low PH: adding 0, margin is now 20
[10:18:32.217] INFO: safety margin for low PH: adding 0, margin is now 20
[10:18:32.223] INFO: safety margin for low PH: adding 0, margin is now 20
[10:18:32.228] INFO: safety margin for low PH: adding 1, margin is now 21
[10:18:32.234] INFO: safety margin for low PH: adding 2, margin is now 22
[10:18:32.240] INFO: safety margin for low PH: adding 3, margin is now 23
[10:18:32.245] INFO: safety margin for low PH: adding 4, margin is now 24
[10:18:32.251] INFO: safety margin for low PH: adding 5, margin is now 25
[10:18:32.256] INFO: safety margin for low PH: adding 6, margin is now 26
[10:18:32.262] INFO: safety margin for low PH: adding 0, margin is now 20
[10:18:32.267] INFO: safety margin for low PH: adding 0, margin is now 20
[10:18:32.273] INFO: safety margin for low PH: adding 0, margin is now 20
[10:18:32.278] INFO: safety margin for low PH: adding 0, margin is now 20
[10:18:32.284] INFO: safety margin for low PH: adding 0, margin is now 20
[10:18:32.289] INFO: safety margin for low PH: adding 0, margin is now 20
[10:18:32.295] INFO: safety margin for low PH: adding 0, margin is now 20
[10:18:32.300] INFO: safety margin for low PH: adding 0, margin is now 20
[10:18:32.306] INFO: safety margin for low PH: adding 0, margin is now 20
[10:18:32.312] DEBUG: <PixTestPhOptimization.cc/doTest:L172> optimisation done
[10:18:32.360] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C0.dat
[10:18:32.360] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C1.dat
[10:18:32.360] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C2.dat
[10:18:32.360] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C3.dat
[10:18:32.360] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C4.dat
[10:18:32.361] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C5.dat
[10:18:32.361] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C6.dat
[10:18:32.361] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C7.dat
[10:18:32.361] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C8.dat
[10:18:32.361] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C9.dat
[10:18:32.361] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C10.dat
[10:18:32.361] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C11.dat
[10:18:32.361] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C12.dat
[10:18:32.361] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C13.dat
[10:18:32.362] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C14.dat
[10:18:32.362] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C15.dat
[10:18:36.103] INFO: Test took 3737ms.
[10:18:40.074] INFO: Test took 3693ms.
[10:18:44.095] INFO: Test took 3743ms.
[10:18:44.379] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:18:45.282] INFO: Test took 903ms.
[10:18:45.286] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:18:46.377] INFO: Test took 1091ms.
[10:18:46.381] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:18:47.470] INFO: Test took 1089ms.
[10:18:47.473] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:18:48.565] INFO: Test took 1092ms.
[10:18:48.569] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:18:49.660] INFO: Test took 1091ms.
[10:18:49.663] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:18:50.755] INFO: Test took 1092ms.
[10:18:50.758] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:18:51.849] INFO: Test took 1091ms.
[10:18:51.852] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:18:52.945] INFO: Test took 1093ms.
[10:18:52.948] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:18:54.040] INFO: Test took 1092ms.
[10:18:54.043] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:18:55.135] INFO: Test took 1092ms.
[10:18:55.139] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:18:56.230] INFO: Test took 1091ms.
[10:18:56.233] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:18:57.325] INFO: Test took 1092ms.
[10:18:57.328] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:18:58.419] INFO: Test took 1091ms.
[10:18:58.422] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:18:59.516] INFO: Test took 1094ms.
[10:18:59.520] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:19:00.610] INFO: Test took 1092ms.
[10:19:00.614] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:19:01.704] INFO: Test took 1090ms.
[10:19:01.707] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:19:02.799] INFO: Test took 1092ms.
[10:19:02.802] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:19:03.895] INFO: Test took 1093ms.
[10:19:03.899] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:19:04.991] INFO: Test took 1092ms.
[10:19:04.994] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:19:06.085] INFO: Test took 1091ms.
[10:19:06.088] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:19:07.180] INFO: Test took 1092ms.
[10:19:07.183] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:19:08.274] INFO: Test took 1091ms.
[10:19:08.277] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:19:09.368] INFO: Test took 1091ms.
[10:19:09.372] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:19:10.462] INFO: Test took 1090ms.
[10:19:10.465] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:19:11.557] INFO: Test took 1092ms.
[10:19:11.560] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:19:12.652] INFO: Test took 1092ms.
[10:19:12.656] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:19:13.748] INFO: Test took 1093ms.
[10:19:13.751] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:19:14.843] INFO: Test took 1092ms.
[10:19:14.847] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:19:15.939] INFO: Test took 1092ms.
[10:19:15.943] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:19:17.034] INFO: Test took 1092ms.
[10:19:17.037] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:19:18.128] INFO: Test took 1091ms.
[10:19:18.131] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:19:19.223] INFO: Test took 1092ms.
[10:19:19.808] INFO: PixTestPhOptimization::doTest() done, duration: 427 seconds
[10:19:19.808] INFO: PH scale (per ROC): 67 69 78 79 66 66 74 70 69 69 68 75 74 74 67 62
[10:19:19.808] INFO: PH offset (per ROC): 190 177 166 173 182 196 176 182 166 174 176 175 170 154 181 180
[10:19:19.950] DEBUG: <PixTestGainPedestal.cc/setParameter:L83> PixTestGainPedestal::PixTest() fVcalStep = 10
[10:19:19.952] INFO: ######################################################################
[10:19:19.952] INFO: PixTestGainPedestal::fullTest() ntrig = 10
[10:19:19.952] INFO: ######################################################################
[10:19:19.952] DEBUG: <PixTestGainPedestal.cc/measure:L192> using FLAGS = 16
[10:19:19.963] INFO: scanning low vcal = 10
[10:19:23.280] INFO: Test took 3317ms.
[10:19:23.285] INFO: scanning low vcal = 20
[10:19:26.617] INFO: Test took 3332ms.
[10:19:26.622] INFO: scanning low vcal = 30
[10:19:29.954] INFO: Test took 3332ms.
[10:19:29.966] INFO: scanning low vcal = 40
[10:19:33.675] INFO: Test took 3709ms.
[10:19:33.738] INFO: scanning low vcal = 50
[10:19:37.487] INFO: Test took 3749ms.
[10:19:37.548] INFO: scanning low vcal = 60
[10:19:41.308] INFO: Test took 3760ms.
[10:19:41.369] INFO: scanning low vcal = 70
[10:19:45.124] INFO: Test took 3755ms.
[10:19:45.182] INFO: scanning low vcal = 80
[10:19:48.943] INFO: Test took 3761ms.
[10:19:48.002] INFO: scanning low vcal = 90
[10:19:52.752] INFO: Test took 3750ms.
[10:19:52.811] INFO: scanning low vcal = 100
[10:19:56.576] INFO: Test took 3765ms.
[10:19:56.635] INFO: scanning low vcal = 110
[10:20:00.395] INFO: Test took 3759ms.
[10:20:00.453] INFO: scanning low vcal = 120
[10:20:04.209] INFO: Test took 3755ms.
[10:20:04.269] INFO: scanning low vcal = 130
[10:20:08.093] INFO: Test took 3824ms.
[10:20:08.153] INFO: scanning low vcal = 140
[10:20:11.986] INFO: Test took 3833ms.
[10:20:12.046] INFO: scanning low vcal = 150
[10:20:15.774] INFO: Test took 3728ms.
[10:20:15.834] INFO: scanning low vcal = 160
[10:20:19.564] INFO: Test took 3730ms.
[10:20:19.624] INFO: scanning low vcal = 170
[10:20:23.356] INFO: Test took 3732ms.
[10:20:23.417] INFO: scanning low vcal = 180
[10:20:27.155] INFO: Test took 3738ms.
[10:20:27.214] INFO: scanning low vcal = 190
[10:20:30.943] INFO: Test took 3729ms.
[10:20:31.005] INFO: scanning low vcal = 200
[10:20:34.722] INFO: Test took 3717ms.
[10:20:34.788] INFO: scanning low vcal = 210
[10:20:38.532] INFO: Test took 3744ms.
[10:20:38.593] INFO: scanning low vcal = 220
[10:20:42.368] INFO: Test took 3775ms.
[10:20:42.431] INFO: scanning low vcal = 230
[10:20:46.207] INFO: Test took 3776ms.
[10:20:46.267] INFO: scanning low vcal = 240
[10:20:50.039] INFO: Test took 3772ms.
[10:20:50.103] INFO: scanning low vcal = 250
[10:20:53.870] INFO: Test took 3767ms.
[10:20:53.935] INFO: scanning high vcal = 30 (= 210 in low range)
[10:20:57.709] INFO: Test took 3774ms.
[10:20:57.773] INFO: scanning high vcal = 50 (= 350 in low range)
[10:21:01.538] INFO: Test took 3765ms.
[10:21:01.599] INFO: scanning high vcal = 70 (= 490 in low range)
[10:21:05.360] INFO: Test took 3761ms.
[10:21:05.419] INFO: scanning high vcal = 90 (= 630 in low range)
[10:21:09.170] INFO: Test took 3751ms.
[10:21:09.229] INFO: scanning high vcal = 200 (= 1400 in low range)
[10:21:12.996] INFO: Test took 3768ms.
[10:21:13.545] INFO: PixTestGainPedestal::measure() done
[10:21:13.547] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C0
[10:21:13.547] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C1
[10:21:13.547] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C2
[10:21:13.548] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C3
[10:21:13.548] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C4
[10:21:13.548] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C5
[10:21:13.548] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C6
[10:21:13.548] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C7
[10:21:13.548] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C8
[10:21:13.549] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C9
[10:21:13.549] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C10
[10:21:13.549] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C11
[10:21:13.549] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C12
[10:21:13.549] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C13
[10:21:13.549] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C14
[10:21:13.549] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C15
[10:21:43.256] INFO: PixTestGainPedestal::fit() done
[10:21:43.256] INFO: non-linearity mean: 0.959 0.958 0.950 0.957 0.963 0.958 0.960 0.950 0.956 0.963 0.955 0.958 0.958 0.959 0.954 0.960
[10:21:43.256] INFO: non-linearity RMS: 0.007 0.006 0.007 0.006 0.007 0.006 0.004 0.007 0.006 0.005 0.007 0.007 0.006 0.006 0.007 0.006
[10:21:43.256] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//phCalibrationFitErr35_C0.dat
[10:21:43.276] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//phCalibrationFitErr35_C1.dat
[10:21:43.292] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//phCalibrationFitErr35_C2.dat
[10:21:43.309] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//phCalibrationFitErr35_C3.dat
[10:21:43.326] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//phCalibrationFitErr35_C4.dat
[10:21:43.342] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//phCalibrationFitErr35_C5.dat
[10:21:43.359] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//phCalibrationFitErr35_C6.dat
[10:21:43.376] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//phCalibrationFitErr35_C7.dat
[10:21:43.392] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//phCalibrationFitErr35_C8.dat
[10:21:43.409] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//phCalibrationFitErr35_C9.dat
[10:21:43.426] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//phCalibrationFitErr35_C10.dat
[10:21:43.443] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//phCalibrationFitErr35_C11.dat
[10:21:43.459] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//phCalibrationFitErr35_C12.dat
[10:21:43.476] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//phCalibrationFitErr35_C13.dat
[10:21:43.493] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//phCalibrationFitErr35_C14.dat
[10:21:43.510] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3021_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//phCalibrationFitErr35_C15.dat
[10:21:43.526] INFO: PixTestGainPedestal::doTest() done, duration: 143 seconds
[10:21:43.526] DEBUG: <PixTestGainPedestal.cc/~PixTestGainPedestal:L125> PixTestGainPedestal dtor
[10:21:43.532] DEBUG: <PixTestFullTest.cc/~PixTestFullTest:L78> PixTestFullTest dtor
[10:21:43.532] INFO: enter test to run
[10:21:43.532] INFO: test: q no parameter change
[10:21:43.532] DEBUG: <PixMonitor.cc/dumpSummaries:L34> PixMonitor::dumpSummaries
[10:21:43.678] QUIET: Connection to board 107 closed.
[10:21:43.679] INFO: pXar: this is the end, my friend
[10:21:43.679] DEBUG: <PixSetup.cc/~PixSetup:L68> PixSetup free fPxarMemory