[15:04:31.062] INFO: *** Welcome to pxar ***
[15:04:31.062] INFO: *** Today: 2015/07/27
[15:04:31.062] INFO: readRocDacs: /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//dacParameters_C0.dat .. /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//dacParameters_C15.dat
[15:04:31.063] INFO: readTbmDacs: /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//tbmParameters_C0a.dat .. /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//tbmParameters_C0b.dat
[15:04:31.063] INFO: readMaskFile: /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//defaultMaskFile.dat
[15:04:31.063] INFO: readTrimFile: /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//trimParameters_C0.dat .. /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//trimParameters_C15.dat
[15:04:31.125] INFO: clk: 4
[15:04:31.125] INFO: ctr: 4
[15:04:31.125] INFO: sda: 19
[15:04:31.125] INFO: tin: 9
[15:04:31.125] INFO: level: 15
[15:04:31.125] INFO: triggerdelay: 0
[15:04:31.125] QUIET: Instanciating API for pxar v2.2.5+67~g3b1c276
[15:04:31.125] INFO: Log level: DEBUG
[15:04:31.136] INFO: Found DTB DTB_WV86BD
[15:04:31.147] QUIET: Connection to board DTB_WV86BD opened.
[15:04:31.150] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 111
HW version: DTB1.2
FW version: 4.2
SW version: 4.2
USB id: DTB_WV86BD
MAC address: 40D85511806F
Hostname: pixelDTB111
Comment:
------------------------------------------------------
[15:04:31.153] INFO: RPC call hashes of host and DTB match: 447413373
[15:04:32.675] INFO: DUT info:
[15:04:32.675] INFO: The DUT currently contains the following objects:
[15:04:32.675] INFO: 2 TBM Cores tbm08c (2 ON)
[15:04:32.675] INFO: TBM Core alpha (0): 7 registers set
[15:04:32.675] INFO: TBM Core beta (1): 7 registers set
[15:04:32.675] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[15:04:32.675] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[15:04:32.675] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[15:04:32.675] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[15:04:32.675] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[15:04:32.675] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[15:04:32.675] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[15:04:32.675] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[15:04:32.675] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[15:04:32.675] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[15:04:32.675] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[15:04:32.675] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[15:04:32.675] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[15:04:32.675] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[15:04:32.675] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[15:04:32.675] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[15:04:32.675] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[15:04:32.676] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->BB<-
[15:04:32.676] DEBUG: <PixTestParameters.cc/dump:L107> dumpall: checkbox(0)
[15:04:32.676] DEBUG: <PixTestParameters.cc/dump:L107> dumpproblematic: checkbox(0)
[15:04:32.676] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 5
[15:04:32.676] DEBUG: <PixTestParameters.cc/dump:L107> vcals: 250
[15:04:32.676] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->BB2<-
[15:04:32.676] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[15:04:32.676] DEBUG: <PixTestParameters.cc/dump:L107> vcals: 222
[15:04:32.676] DEBUG: <PixTestParameters.cc/dump:L107> plwidth: 35
[15:04:32.676] DEBUG: <PixTestParameters.cc/dump:L107> pix: 11,20
[15:04:32.676] DEBUG: <PixTestParameters.cc/dump:L107> targetia: 24
[15:04:32.676] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->BB3<-
[15:04:32.676] DEBUG: <PixTestParameters.cc/dump:L107> dumpall: checkbox(0)
[15:04:32.676] DEBUG: <PixTestParameters.cc/dump:L107> dumpproblematic: checkbox(0)
[15:04:32.676] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 5
[15:04:32.676] DEBUG: <PixTestParameters.cc/dump:L107> vcals: 250
[15:04:32.676] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Cmd<-
[15:04:32.676] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->DacDacScan<-
[15:04:32.676] DEBUG: <PixTestParameters.cc/dump:L107> phmap: checkbox
[15:04:32.676] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[15:04:32.676] DEBUG: <PixTestParameters.cc/dump:L107> dac1: caldel
[15:04:32.676] DEBUG: <PixTestParameters.cc/dump:L107> dac1lo: 0
[15:04:32.676] DEBUG: <PixTestParameters.cc/dump:L107> dac1hi: 255
[15:04:32.676] DEBUG: <PixTestParameters.cc/dump:L107> dac2: vthrcomp
[15:04:32.676] DEBUG: <PixTestParameters.cc/dump:L107> dac2lo: 0
[15:04:32.676] DEBUG: <PixTestParameters.cc/dump:L107> dac2hi: 255
[15:04:32.676] DEBUG: <PixTestParameters.cc/dump:L107> pix: 11,20
[15:04:32.676] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->DacScan<-
[15:04:32.676] DEBUG: <PixTestParameters.cc/dump:L107> phmap: checkbox(1)
[15:04:32.676] DEBUG: <PixTestParameters.cc/dump:L107> allpixels: checkbox(0)
[15:04:32.676] DEBUG: <PixTestParameters.cc/dump:L107> unmasked: checkbox(0)
[15:04:32.676] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[15:04:32.676] DEBUG: <PixTestParameters.cc/dump:L107> dac: vcal
[15:04:32.676] DEBUG: <PixTestParameters.cc/dump:L107> daclo: 0
[15:04:32.676] DEBUG: <PixTestParameters.cc/dump:L107> dachi: 255
[15:04:32.677] DEBUG: <PixTestParameters.cc/dump:L107> pix: 11,20
[15:04:32.677] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->GainPedestal<-
[15:04:32.677] DEBUG: <PixTestParameters.cc/dump:L107> showfits: checkbox(0)
[15:04:32.677] DEBUG: <PixTestParameters.cc/dump:L107> extended: checkbox(0)
[15:04:32.677] DEBUG: <PixTestParameters.cc/dump:L107> dumphists: checkbox(0)
[15:04:32.677] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[15:04:32.677] DEBUG: <PixTestParameters.cc/dump:L107> vcalstep: 10
[15:04:32.677] DEBUG: <PixTestParameters.cc/dump:L107> measure: button
[15:04:32.677] DEBUG: <PixTestParameters.cc/dump:L107> fit: button
[15:04:32.677] DEBUG: <PixTestParameters.cc/dump:L107> save: button
[15:04:32.677] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->HighRate<-
[15:04:32.677] DEBUG: <PixTestParameters.cc/dump:L107> pix: 11,20
[15:04:32.677] DEBUG: <PixTestParameters.cc/dump:L107> maskhotpixels: button
[15:04:32.677] DEBUG: <PixTestParameters.cc/dump:L107> savemaskfile: checkbox(0)
[15:04:32.677] DEBUG: <PixTestParameters.cc/dump:L107> maskfilename: default
[15:04:32.677] DEBUG: <PixTestParameters.cc/dump:L107> caldelscan: button
[15:04:32.677] DEBUG: <PixTestParameters.cc/dump:L107> xpixelalive: button
[15:04:32.677] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 50
[15:04:32.677] DEBUG: <PixTestParameters.cc/dump:L107> vcal: 200
[15:04:32.677] DEBUG: <PixTestParameters.cc/dump:L107> xnoisemaps: button
[15:04:32.677] DEBUG: <PixTestParameters.cc/dump:L107> daclo: 0
[15:04:32.677] DEBUG: <PixTestParameters.cc/dump:L107> dachi: 100
[15:04:32.677] DEBUG: <PixTestParameters.cc/dump:L107> dacs/step: 20
[15:04:32.677] DEBUG: <PixTestParameters.cc/dump:L107> rundaq: button
[15:04:32.677] DEBUG: <PixTestParameters.cc/dump:L107> trgfrequency(khz): 20
[15:04:32.677] DEBUG: <PixTestParameters.cc/dump:L107> runseconds: 2
[15:04:32.677] DEBUG: <PixTestParameters.cc/dump:L107> triggerdelay: 20
[15:04:32.677] DEBUG: <PixTestParameters.cc/dump:L107> delaytbm: checkbox
[15:04:32.677] DEBUG: <PixTestParameters.cc/dump:L107> filltree: checkbox
[15:04:32.677] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->IV<-
[15:04:32.677] DEBUG: <PixTestParameters.cc/dump:L107> port: /dev/FIXME
[15:04:32.677] DEBUG: <PixTestParameters.cc/dump:L107> voltagestart: 0
[15:04:32.677] DEBUG: <PixTestParameters.cc/dump:L107> voltagestop: 600
[15:04:32.677] DEBUG: <PixTestParameters.cc/dump:L107> voltagestep: 5
[15:04:32.677] DEBUG: <PixTestParameters.cc/dump:L107> delay: 1
[15:04:32.677] DEBUG: <PixTestParameters.cc/dump:L107> compliance(ua): 100
[15:04:32.677] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->PhOptimization<-
[15:04:32.677] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[15:04:32.677] DEBUG: <PixTestParameters.cc/dump:L107> safetymarginlow: 20
[15:04:32.677] DEBUG: <PixTestParameters.cc/dump:L107> saturationvcal: 100
[15:04:32.677] DEBUG: <PixTestParameters.cc/dump:L107> quantilesaturation: 0.98
[15:04:32.677] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->PixelAlive<-
[15:04:32.677] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[15:04:32.677] DEBUG: <PixTestParameters.cc/dump:L107> vcal: 200
[15:04:32.677] DEBUG: <PixTestParameters.cc/dump:L107> alivetest: button
[15:04:32.677] DEBUG: <PixTestParameters.cc/dump:L107> masktest: button
[15:04:32.677] DEBUG: <PixTestParameters.cc/dump:L107> addressdecodingtest: button
[15:04:32.677] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Pretest<-
[15:04:32.678] DEBUG: <PixTestParameters.cc/dump:L107> programroc: button
[15:04:32.678] DEBUG: <PixTestParameters.cc/dump:L107> targetia: 24
[15:04:32.678] DEBUG: <PixTestParameters.cc/dump:L107> setvana: button
[15:04:32.678] DEBUG: <PixTestParameters.cc/dump:L107> iterations: 100
[15:04:32.678] DEBUG: <PixTestParameters.cc/dump:L107> settimings: button
[15:04:32.678] DEBUG: <PixTestParameters.cc/dump:L107> findworkingpixel: button
[15:04:32.678] DEBUG: <PixTestParameters.cc/dump:L107> setvthrcompcaldel: button
[15:04:32.678] DEBUG: <PixTestParameters.cc/dump:L107> pix: 11,20
[15:04:32.678] DEBUG: <PixTestParameters.cc/dump:L107> vcal: 250
[15:04:32.678] DEBUG: <PixTestParameters.cc/dump:L107> deltavthrcomp: 50
[15:04:32.678] DEBUG: <PixTestParameters.cc/dump:L107> fraccaldel: 0.5
[15:04:32.678] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 5
[15:04:32.678] DEBUG: <PixTestParameters.cc/dump:L107> savedacs: button
[15:04:32.678] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Readback<-
[15:04:32.678] DEBUG: <PixTestParameters.cc/dump:L107> calibratevd: button
[15:04:32.678] DEBUG: <PixTestParameters.cc/dump:L107> calibrateva: button
[15:04:32.678] DEBUG: <PixTestParameters.cc/dump:L107> calibrateia: button
[15:04:32.678] DEBUG: <PixTestParameters.cc/dump:L107> readbackvbg: button
[15:04:32.678] DEBUG: <PixTestParameters.cc/dump:L107> getcalibratedvbg: button
[15:04:32.678] DEBUG: <PixTestParameters.cc/dump:L107> usecalvd: checkbox(1)
[15:04:32.678] DEBUG: <PixTestParameters.cc/dump:L107> usecalva: checkbox(0)
[15:04:32.678] DEBUG: <PixTestParameters.cc/dump:L107> setvana: button
[15:04:32.678] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Scurves<-
[15:04:32.678] DEBUG: <PixTestParameters.cc/dump:L107> adjustvcal: checkbox(1)
[15:04:32.678] DEBUG: <PixTestParameters.cc/dump:L107> dumpall: checkbox(0)
[15:04:32.678] DEBUG: <PixTestParameters.cc/dump:L107> dumpproblematic: checkbox(0)
[15:04:32.678] DEBUG: <PixTestParameters.cc/dump:L107> dumpoutputfile: checkbox(0)
[15:04:32.678] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 50
[15:04:32.678] DEBUG: <PixTestParameters.cc/dump:L107> dac: VthrComp
[15:04:32.678] DEBUG: <PixTestParameters.cc/dump:L107> daclo: 0
[15:04:32.678] DEBUG: <PixTestParameters.cc/dump:L107> dachi: 200
[15:04:32.678] DEBUG: <PixTestParameters.cc/dump:L107> dacs/step: 10
[15:04:32.678] DEBUG: <PixTestParameters.cc/dump:L107> scurves: button
[15:04:32.678] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Timing<-
[15:04:32.678] DEBUG: <PixTestParameters.cc/dump:L107> fastscan: checkbox(0)
[15:04:32.678] DEBUG: <PixTestParameters.cc/dump:L107> targetclk: 4
[15:04:32.678] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[15:04:32.678] DEBUG: <PixTestParameters.cc/dump:L107> clocksdascan: button
[15:04:32.678] DEBUG: <PixTestParameters.cc/dump:L107> phasescan: button
[15:04:32.678] DEBUG: <PixTestParameters.cc/dump:L107> levelscan: button
[15:04:32.678] DEBUG: <PixTestParameters.cc/dump:L107> tbmphasescan: button
[15:04:32.678] DEBUG: <PixTestParameters.cc/dump:L107> rocdelayscan: button
[15:04:32.678] DEBUG: <PixTestParameters.cc/dump:L107> timingtest: button
[15:04:32.678] DEBUG: <PixTestParameters.cc/dump:L107> saveparameters: button
[15:04:32.678] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Trim<-
[15:04:32.678] DEBUG: <PixTestParameters.cc/dump:L107> trim: button
[15:04:32.678] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[15:04:32.678] DEBUG: <PixTestParameters.cc/dump:L107> vcal: 35
[15:04:32.678] DEBUG: <PixTestParameters.cc/dump:L107> trimbits: button
[15:04:32.678] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Xray<-
[15:04:32.679] DEBUG: <PixTestParameters.cc/dump:L107> maskhotpixels: button
[15:04:32.679] DEBUG: <PixTestParameters.cc/dump:L107> savemaskfile: checkbox(0)
[15:04:32.679] DEBUG: <PixTestParameters.cc/dump:L107> maskfilename: default
[15:04:32.679] DEBUG: <PixTestParameters.cc/dump:L107> source: Ag
[15:04:32.679] DEBUG: <PixTestParameters.cc/dump:L107> phrun: button
[15:04:32.679] DEBUG: <PixTestParameters.cc/dump:L107> runseconds: 100
[15:04:32.679] DEBUG: <PixTestParameters.cc/dump:L107> trgfrequency(khz): 100
[15:04:32.679] DEBUG: <PixTestParameters.cc/dump:L107> ratescan: button
[15:04:32.679] DEBUG: <PixTestParameters.cc/dump:L107> vthrcompmin: 10
[15:04:32.679] DEBUG: <PixTestParameters.cc/dump:L107> vthrcompmax: 80
[15:04:32.679] DEBUG: <PixTestParameters.cc/dump:L107> stepseconds: 5
[15:04:32.679] DEBUG: <PixTestParameters.cc/dump:L107> delaytbm: checkbox
[15:04:32.679] DEBUG: <PixTestParameters.cc/dump:L107> filltree: checkbox
[15:04:32.679] DEBUG: <PixSetup.cc/init:L81> PixSetup init start; getCurrentRSS() = 31674368
[15:04:32.679] DEBUG: <PixSetup.cc/init:L87> fPixTestParameters = 0x2801810
[15:04:32.679] DEBUG: <PixSetup.cc/init:L88> fConfigParameters = 0x272a9c0
[15:04:32.679] DEBUG: <PixSetup.cc/init:L89> fPxarMemory = 0x7f897dd94010
[15:04:32.679] DEBUG: <PixSetup.cc/init:L90> fPxarMemHi = 0x7f8983fff510
[15:04:32.679] DEBUG: <PixSetup.cc/init:L106> PixSetup init done; getCurrentRSS() = 31735808 fPxarMemory = 0x7f897dd94010
[15:04:32.679] DEBUG: <PixTestFactory.cc/PixTestFactory:L52> PixTestFactory::PixTestFactory()
[15:04:33.080] INFO: enter 'restricted' command line mode
[15:04:33.080] INFO: enter test to run
[15:04:33.080] INFO: test: Pretest no parameter change
[15:04:33.080] INFO: running: pretest
[15:04:33.087] INFO: ######################################################################
[15:04:33.087] INFO: PixTestPretest::doTest()
[15:04:33.087] INFO: ######################################################################
[15:04:33.089] INFO: ----------------------------------------------------------------------
[15:04:33.089] INFO: PixTestPretest::programROC()
[15:04:33.089] INFO: ----------------------------------------------------------------------
[15:04:51.111] INFO: PixTestPretest::programROC() done: ROCs are all programmable
[15:04:51.111] INFO: IA differences per ROC: 18.5 18.5 20.1 17.7 17.7 18.5 18.5 16.9 16.1 18.5 18.5 17.7 17.7 20.9 18.5 20.1
[15:04:51.189] INFO: ----------------------------------------------------------------------
[15:04:51.190] INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[15:04:51.190] INFO: ----------------------------------------------------------------------
[15:04:51.293] DEBUG: <PixTestPretest.cc/setVana:L254> offset current from other 15 ROCs is 67.7812 mA
[15:04:51.394] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 0 iter 0 Vana 78 Ia 22.2188 mA
[15:04:51.495] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 1 Vana 89 Ia 24.6187 mA
[15:04:51.596] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 2 Vana 86 Ia 23.8187 mA
[15:04:51.697] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 3 Vana 87 Ia 24.6187 mA
[15:04:51.797] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 4 Vana 84 Ia 23.8187 mA
[15:04:51.899] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 5 Vana 85 Ia 23.8187 mA
[15:04:51.000] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 6 Vana 86 Ia 24.6187 mA
[15:04:52.101] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 7 Vana 83 Ia 23.8187 mA
[15:04:52.202] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 8 Vana 84 Ia 23.8187 mA
[15:04:52.303] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 9 Vana 85 Ia 23.8187 mA
[15:04:52.404] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 10 Vana 86 Ia 23.8187 mA
[15:04:52.505] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 11 Vana 87 Ia 24.6187 mA
[15:04:52.607] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 1 iter 0 Vana 78 Ia 22.2188 mA
[15:04:52.709] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 1 Vana 89 Ia 24.6187 mA
[15:04:52.810] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 2 Vana 86 Ia 23.8187 mA
[15:04:52.911] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 3 Vana 87 Ia 24.6187 mA
[15:04:53.012] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 4 Vana 84 Ia 23.8187 mA
[15:04:53.112] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 5 Vana 85 Ia 23.8187 mA
[15:04:53.214] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 6 Vana 86 Ia 23.8187 mA
[15:04:53.315] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 7 Vana 87 Ia 24.6187 mA
[15:04:53.416] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 8 Vana 84 Ia 23.8187 mA
[15:04:53.517] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 9 Vana 85 Ia 23.8187 mA
[15:04:53.617] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 10 Vana 86 Ia 23.8187 mA
[15:04:53.718] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 11 Vana 87 Ia 23.8187 mA
[15:04:53.820] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 2 iter 0 Vana 78 Ia 23.0188 mA
[15:04:53.922] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 2 iter 1 Vana 84 Ia 25.4188 mA
[15:04:54.023] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 2 iter 2 Vana 77 Ia 23.0188 mA
[15:04:54.124] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 2 iter 3 Vana 83 Ia 24.6187 mA
[15:04:54.224] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 2 iter 4 Vana 80 Ia 23.8187 mA
[15:04:54.326] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 2 iter 5 Vana 81 Ia 24.6187 mA
[15:04:54.427] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 2 iter 6 Vana 78 Ia 23.8187 mA
[15:04:54.527] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 2 iter 7 Vana 79 Ia 23.8187 mA
[15:04:54.628] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 2 iter 8 Vana 80 Ia 23.8187 mA
[15:04:54.729] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 2 iter 9 Vana 81 Ia 24.6187 mA
[15:04:54.829] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 2 iter 10 Vana 78 Ia 23.8187 mA
[15:04:54.930] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 2 iter 11 Vana 79 Ia 23.8187 mA
[15:04:55.032] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 3 iter 0 Vana 78 Ia 22.2188 mA
[15:04:55.133] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 1 Vana 89 Ia 24.6187 mA
[15:04:55.235] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 2 Vana 86 Ia 23.8187 mA
[15:04:55.335] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 3 Vana 87 Ia 23.8187 mA
[15:04:55.436] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 4 Vana 88 Ia 23.8187 mA
[15:04:55.538] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 5 Vana 89 Ia 23.8187 mA
[15:04:55.642] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 6 Vana 90 Ia 24.6187 mA
[15:04:55.742] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 7 Vana 87 Ia 23.8187 mA
[15:04:55.843] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 8 Vana 88 Ia 23.8187 mA
[15:04:55.943] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 9 Vana 89 Ia 24.6187 mA
[15:04:56.044] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 10 Vana 86 Ia 23.8187 mA
[15:04:56.145] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 11 Vana 87 Ia 23.8187 mA
[15:04:56.247] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 4 iter 0 Vana 78 Ia 21.4188 mA
[15:04:56.348] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 4 iter 1 Vana 94 Ia 24.6187 mA
[15:04:56.449] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 4 iter 2 Vana 91 Ia 24.6187 mA
[15:04:56.551] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 4 iter 3 Vana 88 Ia 23.8187 mA
[15:04:56.652] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 4 iter 4 Vana 89 Ia 23.8187 mA
[15:04:56.753] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 4 iter 5 Vana 90 Ia 23.8187 mA
[15:04:56.854] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 4 iter 6 Vana 91 Ia 24.6187 mA
[15:04:56.955] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 4 iter 7 Vana 88 Ia 23.8187 mA
[15:04:57.055] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 4 iter 8 Vana 89 Ia 23.8187 mA
[15:04:57.156] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 4 iter 9 Vana 90 Ia 23.8187 mA
[15:04:57.257] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 4 iter 10 Vana 91 Ia 24.6187 mA
[15:04:57.358] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 4 iter 11 Vana 88 Ia 23.8187 mA
[15:04:57.461] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 5 iter 0 Vana 78 Ia 22.2188 mA
[15:04:57.562] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 1 Vana 89 Ia 25.4188 mA
[15:04:57.663] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 2 Vana 82 Ia 23.8187 mA
[15:04:57.764] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 3 Vana 83 Ia 23.8187 mA
[15:04:57.865] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 4 Vana 84 Ia 24.6187 mA
[15:04:57.966] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 5 Vana 81 Ia 23.8187 mA
[15:04:58.066] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 6 Vana 82 Ia 23.8187 mA
[15:04:58.167] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 7 Vana 83 Ia 23.8187 mA
[15:04:58.268] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 8 Vana 84 Ia 24.6187 mA
[15:04:58.369] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 9 Vana 81 Ia 23.8187 mA
[15:04:58.470] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 10 Vana 82 Ia 23.8187 mA
[15:04:58.571] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 11 Vana 83 Ia 24.6187 mA
[15:04:58.673] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 6 iter 0 Vana 78 Ia 22.2188 mA
[15:04:58.774] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 1 Vana 89 Ia 24.6187 mA
[15:04:58.875] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 2 Vana 86 Ia 23.8187 mA
[15:04:58.976] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 3 Vana 87 Ia 23.8187 mA
[15:04:59.077] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 4 Vana 88 Ia 24.6187 mA
[15:04:59.178] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 5 Vana 85 Ia 23.8187 mA
[15:04:59.279] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 6 Vana 86 Ia 23.8187 mA
[15:04:59.380] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 7 Vana 87 Ia 24.6187 mA
[15:04:59.482] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 8 Vana 84 Ia 23.8187 mA
[15:04:59.583] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 9 Vana 85 Ia 23.8187 mA
[15:04:59.684] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 10 Vana 86 Ia 23.8187 mA
[15:04:59.785] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 11 Vana 87 Ia 24.6187 mA
[15:04:59.888] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 7 iter 0 Vana 78 Ia 20.6188 mA
[15:04:59.989] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 7 iter 1 Vana 98 Ia 24.6187 mA
[15:05:00.090] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 7 iter 2 Vana 95 Ia 24.6187 mA
[15:05:00.190] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 7 iter 3 Vana 92 Ia 23.8187 mA
[15:05:00.291] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 7 iter 4 Vana 93 Ia 23.8187 mA
[15:05:00.392] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 7 iter 5 Vana 94 Ia 23.8187 mA
[15:05:00.493] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 7 iter 6 Vana 95 Ia 24.6187 mA
[15:05:00.593] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 7 iter 7 Vana 92 Ia 23.8187 mA
[15:05:00.695] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 7 iter 8 Vana 93 Ia 23.8187 mA
[15:05:00.796] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 7 iter 9 Vana 94 Ia 24.6187 mA
[15:05:00.896] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 7 iter 10 Vana 91 Ia 23.8187 mA
[15:05:00.997] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 7 iter 11 Vana 92 Ia 23.8187 mA
[15:05:01.099] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 8 iter 0 Vana 78 Ia 19.8187 mA
[15:05:01.200] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 8 iter 1 Vana 103 Ia 24.6187 mA
[15:05:01.302] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 8 iter 2 Vana 100 Ia 23.8187 mA
[15:05:01.402] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 8 iter 3 Vana 101 Ia 24.6187 mA
[15:05:01.503] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 8 iter 4 Vana 98 Ia 23.8187 mA
[15:05:01.604] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 8 iter 5 Vana 99 Ia 24.6187 mA
[15:05:01.705] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 8 iter 6 Vana 96 Ia 23.8187 mA
[15:05:01.806] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 8 iter 7 Vana 97 Ia 23.8187 mA
[15:05:01.907] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 8 iter 8 Vana 98 Ia 23.8187 mA
[15:05:02.008] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 8 iter 9 Vana 99 Ia 23.8187 mA
[15:05:02.109] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 8 iter 10 Vana 100 Ia 23.8187 mA
[15:05:02.209] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 8 iter 11 Vana 101 Ia 24.6187 mA
[15:05:02.311] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 9 iter 0 Vana 78 Ia 23.0188 mA
[15:05:02.412] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 9 iter 1 Vana 84 Ia 24.6187 mA
[15:05:02.513] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 9 iter 2 Vana 81 Ia 23.8187 mA
[15:05:02.614] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 9 iter 3 Vana 82 Ia 23.8187 mA
[15:05:02.715] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 9 iter 4 Vana 83 Ia 24.6187 mA
[15:05:02.816] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 9 iter 5 Vana 80 Ia 23.8187 mA
[15:05:02.917] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 9 iter 6 Vana 81 Ia 23.8187 mA
[15:05:03.018] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 9 iter 7 Vana 82 Ia 23.8187 mA
[15:05:03.118] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 9 iter 8 Vana 83 Ia 23.8187 mA
[15:05:03.219] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 9 iter 9 Vana 84 Ia 23.8187 mA
[15:05:03.319] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 9 iter 10 Vana 85 Ia 24.6187 mA
[15:05:03.420] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 9 iter 11 Vana 82 Ia 23.8187 mA
[15:05:03.522] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 10 iter 0 Vana 78 Ia 22.2188 mA
[15:05:03.622] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 1 Vana 89 Ia 25.4188 mA
[15:05:03.724] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 2 Vana 82 Ia 23.8187 mA
[15:05:03.825] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 3 Vana 83 Ia 23.8187 mA
[15:05:03.925] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 4 Vana 84 Ia 24.6187 mA
[15:05:04.027] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 5 Vana 81 Ia 23.8187 mA
[15:05:04.127] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 6 Vana 82 Ia 23.8187 mA
[15:05:04.228] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 7 Vana 83 Ia 23.8187 mA
[15:05:04.329] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 8 Vana 84 Ia 24.6187 mA
[15:05:04.430] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 9 Vana 81 Ia 23.8187 mA
[15:05:04.531] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 10 Vana 82 Ia 23.8187 mA
[15:05:04.632] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 11 Vana 83 Ia 24.6187 mA
[15:05:04.734] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 11 iter 0 Vana 78 Ia 21.4188 mA
[15:05:04.835] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter 1 Vana 94 Ia 25.4188 mA
[15:05:04.935] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter 2 Vana 87 Ia 23.8187 mA
[15:05:05.037] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter 3 Vana 88 Ia 23.8187 mA
[15:05:05.138] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter 4 Vana 89 Ia 23.8187 mA
[15:05:05.239] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter 5 Vana 90 Ia 23.8187 mA
[15:05:05.339] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter 6 Vana 91 Ia 24.6187 mA
[15:05:05.440] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter 7 Vana 88 Ia 23.8187 mA
[15:05:05.541] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter 8 Vana 89 Ia 23.8187 mA
[15:05:05.642] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter 9 Vana 90 Ia 23.8187 mA
[15:05:05.742] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter 10 Vana 91 Ia 24.6187 mA
[15:05:05.843] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter 11 Vana 88 Ia 23.8187 mA
[15:05:05.948] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 12 iter 0 Vana 78 Ia 21.4188 mA
[15:05:06.049] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter 1 Vana 94 Ia 24.6187 mA
[15:05:06.150] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter 2 Vana 91 Ia 24.6187 mA
[15:05:06.250] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter 3 Vana 88 Ia 23.8187 mA
[15:05:06.352] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter 4 Vana 89 Ia 24.6187 mA
[15:05:06.452] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter 5 Vana 86 Ia 23.8187 mA
[15:05:06.553] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter 6 Vana 87 Ia 23.8187 mA
[15:05:06.654] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter 7 Vana 88 Ia 23.8187 mA
[15:05:06.755] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter 8 Vana 89 Ia 23.8187 mA
[15:05:06.858] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter 9 Vana 90 Ia 24.6187 mA
[15:05:06.959] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter 10 Vana 87 Ia 23.8187 mA
[15:05:07.060] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter 11 Vana 88 Ia 23.8187 mA
[15:05:07.162] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 13 iter 0 Vana 78 Ia 24.6187 mA
[15:05:07.263] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 1 Vana 75 Ia 23.8187 mA
[15:05:07.364] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 2 Vana 76 Ia 23.8187 mA
[15:05:07.465] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 3 Vana 77 Ia 23.8187 mA
[15:05:07.566] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 4 Vana 78 Ia 24.6187 mA
[15:05:07.667] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 5 Vana 75 Ia 23.8187 mA
[15:05:07.768] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 6 Vana 76 Ia 23.8187 mA
[15:05:07.869] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 7 Vana 77 Ia 24.6187 mA
[15:05:07.969] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 8 Vana 74 Ia 23.8187 mA
[15:05:08.071] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 9 Vana 75 Ia 23.8187 mA
[15:05:08.172] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 10 Vana 76 Ia 23.8187 mA
[15:05:08.273] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 11 Vana 77 Ia 23.8187 mA
[15:05:08.374] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 14 iter 0 Vana 78 Ia 22.2188 mA
[15:05:08.475] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 1 Vana 89 Ia 25.4188 mA
[15:05:08.576] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 2 Vana 82 Ia 23.8187 mA
[15:05:08.677] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 3 Vana 83 Ia 23.8187 mA
[15:05:08.778] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 4 Vana 84 Ia 23.8187 mA
[15:05:08.878] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 5 Vana 85 Ia 24.6187 mA
[15:05:08.980] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 6 Vana 82 Ia 23.8187 mA
[15:05:09.081] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 7 Vana 83 Ia 23.8187 mA
[15:05:09.182] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 8 Vana 84 Ia 24.6187 mA
[15:05:09.283] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 9 Vana 81 Ia 23.8187 mA
[15:05:09.383] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 10 Vana 82 Ia 23.8187 mA
[15:05:09.484] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 11 Vana 83 Ia 23.8187 mA
[15:05:09.590] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 15 iter 0 Vana 78 Ia 23.0188 mA
[15:05:09.691] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 1 Vana 84 Ia 25.4188 mA
[15:05:09.792] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 2 Vana 77 Ia 23.0188 mA
[15:05:09.893] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 3 Vana 83 Ia 24.6187 mA
[15:05:09.994] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 4 Vana 80 Ia 24.6187 mA
[15:05:10.095] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 5 Vana 77 Ia 23.0188 mA
[15:05:10.196] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 6 Vana 83 Ia 25.4188 mA
[15:05:10.297] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 7 Vana 76 Ia 23.0188 mA
[15:05:10.398] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 8 Vana 82 Ia 24.6187 mA
[15:05:10.499] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 9 Vana 79 Ia 23.8187 mA
[15:05:10.600] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 10 Vana 80 Ia 23.8187 mA
[15:05:10.701] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 11 Vana 81 Ia 24.6187 mA
[15:05:10.764] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 0 Vana 87
[15:05:10.764] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 1 Vana 87
[15:05:10.764] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 2 Vana 79
[15:05:10.764] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 3 Vana 87
[15:05:10.764] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 4 Vana 88
[15:05:10.765] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 5 Vana 83
[15:05:10.765] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 6 Vana 87
[15:05:10.766] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 7 Vana 92
[15:05:10.766] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 8 Vana 101
[15:05:10.769] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 9 Vana 82
[15:05:10.769] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 10 Vana 83
[15:05:10.769] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 11 Vana 88
[15:05:10.770] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 12 Vana 88
[15:05:10.770] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 13 Vana 77
[15:05:10.770] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 14 Vana 83
[15:05:10.770] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 15 Vana 81
[15:05:10.873] INFO: PixTestPretest::setVana() done, Module Ia 396.3 mA = 24.7688 mA/ROC
[15:05:10.875] INFO: ----------------------------------------------------------------------
[15:05:10.875] INFO: PixTestPreTest::setTimings()
[15:05:10.875] INFO: ----------------------------------------------------------------------
[15:05:10.875] DEBUG: <PixTestPretest.cc/setTimings:L392> Testing Timing: Attempt #1
[15:05:11.841] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:05:11.841] INFO: Decoding statistics:
[15:05:11.841] INFO: General information:
[15:05:11.841] INFO: 16bit words read: 120
[15:05:11.841] INFO: valid events total: 10
[15:05:11.841] INFO: empty events: 10
[15:05:11.841] INFO: valid events with pixels: 0
[15:05:11.841] INFO: valid pixel hits: 0
[15:05:11.842] INFO: Event errors: 0
[15:05:11.842] INFO: start marker: 0
[15:05:11.842] INFO: stop marker: 0
[15:05:11.842] INFO: overflow: 0
[15:05:11.842] INFO: invalid 5bit words: 0
[15:05:11.842] INFO: invalid XOR eye diagram: 0
[15:05:11.842] INFO: TBM errors: 0
[15:05:11.842] INFO: flawed TBM headers: 0
[15:05:11.842] INFO: flawed TBM trailers: 0
[15:05:11.842] INFO: event ID mismatches: 0
[15:05:11.842] INFO: ROC errors: 0
[15:05:11.842] INFO: missing ROC header(s): 0
[15:05:11.842] INFO: misplaced readback start: 0
[15:05:11.842] INFO: Pixel decoding errors: 0
[15:05:11.842] INFO: pixel data incomplete: 0
[15:05:11.842] INFO: pixel address: 0
[15:05:11.842] INFO: pulse height fill bit: 0
[15:05:11.842] INFO: buffer corruption: 0
[15:05:11.842] INFO: ----------------------------------------------------------------------
[15:05:11.842] INFO: Default timings are good. No timing scan needed.
[15:05:11.842] INFO: ----------------------------------------------------------------------
[15:05:11.842] INFO: Test took 967 ms.
[15:05:11.842] INFO: PixTestPretest::setTimings() done.
[15:05:12.034] INFO: ----------------------------------------------------------------------
[15:05:12.035] INFO: PixTestPretest::findWorkingPixel()
[15:05:12.035] INFO: ----------------------------------------------------------------------
[15:05:19.404] INFO: Test took 7366ms.
[15:05:19.635] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C0 OK, with vthrComp = 111 and Delta(CalDel) = 63
[15:05:19.638] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C1 OK, with vthrComp = 101 and Delta(CalDel) = 62
[15:05:19.641] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C2 OK, with vthrComp = 89 and Delta(CalDel) = 60
[15:05:19.644] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C3 OK, with vthrComp = 98 and Delta(CalDel) = 61
[15:05:19.646] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C4 OK, with vthrComp = 64 and Delta(CalDel) = 61
[15:05:19.648] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C5 OK, with vthrComp = 115 and Delta(CalDel) = 63
[15:05:19.651] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C6 OK, with vthrComp = 111 and Delta(CalDel) = 59
[15:05:19.653] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C7 OK, with vthrComp = 73 and Delta(CalDel) = 60
[15:05:19.658] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C8 OK, with vthrComp = 111 and Delta(CalDel) = 62
[15:05:19.661] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C9 OK, with vthrComp = 95 and Delta(CalDel) = 59
[15:05:19.663] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C10 OK, with vthrComp = 112 and Delta(CalDel) = 60
[15:05:19.666] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C11 OK, with vthrComp = 99 and Delta(CalDel) = 62
[15:05:19.668] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C12 OK, with vthrComp = 105 and Delta(CalDel) = 62
[15:05:19.671] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C13 OK, with vthrComp = 110 and Delta(CalDel) = 58
[15:05:19.675] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C14 OK, with vthrComp = 84 and Delta(CalDel) = 64
[15:05:19.677] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C15 OK, with vthrComp = 111 and Delta(CalDel) = 59
[15:05:19.702] INFO: Found working pixel in all ROCs: col/row = 12/22
[15:05:19.750] INFO: ----------------------------------------------------------------------
[15:05:19.750] INFO: PixTestPretest::setVthrCompCalDel()
[15:05:19.750] INFO: ----------------------------------------------------------------------









[15:05:27.128] INFO: Test took 7371ms.
[15:05:27.184] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 133 +/- 31.5
[15:05:27.360] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 143 +/- 31
[15:05:27.363] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 126 +/- 30
[15:05:27.365] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 131 +/- 30.5
[15:05:27.367] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 146 +/- 31
[15:05:27.370] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 134 +/- 32
[15:05:27.372] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 123 +/- 29.5
[15:05:27.374] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 132 +/- 30
[15:05:27.379] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 129 +/- 31.5
[15:05:27.382] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 120 +/- 29
[15:05:27.384] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 122 +/- 29.5
[15:05:27.386] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 126 +/- 30.5
[15:05:27.389] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 137 +/- 31
[15:05:27.391] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 131 +/- 28.5
[15:05:27.394] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 144 +/- 32.5
[15:05:27.396] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 130 +/- 30
[15:05:27.451] INFO: PixTestPretest::setVthrCompCalDel() done
[15:05:27.451] INFO: CalDel: 133 143 126 131 146 134 123 132 129 120 122 126 137 131 144 130
[15:05:27.451] INFO: VthrComp: 52 51 51 51 51 57 53 51 55 51 51 51 51 51 51 51
[15:05:27.455] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//dacParameters_C0.dat
[15:05:27.456] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//dacParameters_C1.dat
[15:05:27.456] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//dacParameters_C2.dat
[15:05:27.456] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//dacParameters_C3.dat
[15:05:27.456] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//dacParameters_C4.dat
[15:05:27.456] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//dacParameters_C5.dat
[15:05:27.456] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//dacParameters_C6.dat
[15:05:27.456] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//dacParameters_C7.dat
[15:05:27.456] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//dacParameters_C8.dat
[15:05:27.457] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//dacParameters_C9.dat
[15:05:27.457] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//dacParameters_C10.dat
[15:05:27.457] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//dacParameters_C11.dat
[15:05:27.457] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//dacParameters_C12.dat
[15:05:27.457] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//dacParameters_C13.dat
[15:05:27.457] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//dacParameters_C14.dat
[15:05:27.457] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//dacParameters_C15.dat
[15:05:27.457] INFO: PixTestPretest::doTest() done, duration: 54 seconds
[15:05:27.457] DEBUG: <PixTestPretest.cc/~PixTestPretest:L134> PixTestPretest dtor
[15:05:27.535] INFO: enter test to run
[15:05:27.535] INFO: test: Fulltest no parameter change
[15:05:27.535] INFO: running: fulltest
[15:05:27.535] DEBUG: <PixTestFullTest.cc/init:L49> PixTestFullTest::init()
[15:05:27.535] DEBUG: <PixTestFullTest.cc/PixTestFullTest:L20> PixTestFullTest ctor(PixSetup &a, string, TGTab *)
[15:05:27.535] INFO: ######################################################################
[15:05:27.535] INFO: PixTestFullTest::doTest()
[15:05:27.535] INFO: ######################################################################
[15:05:27.535] DEBUG: <PixTestAlive.cc/init:L77> PixTestAlive::init()
[15:05:27.535] DEBUG: <PixTestAlive.cc/PixTestAlive:L21> PixTestAlive ctor(PixSetup &a, string, TGTab *)
[15:05:27.537] INFO: ######################################################################
[15:05:27.537] INFO: PixTestAlive::doTest()
[15:05:27.537] INFO: ######################################################################
[15:05:27.540] INFO: ----------------------------------------------------------------------
[15:05:27.540] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[15:05:27.540] INFO: ----------------------------------------------------------------------
[15:05:27.542] DEBUG: <PixTest.cc/efficiencyMaps:L328> attempt #0
[15:05:31.281] INFO: Test took 3739ms.
[15:05:31.303] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:05:31.303] DEBUG: <PixTest.cc/efficiencyMaps:L339> eff result size = 66556
[15:05:31.303] DEBUG: <PixTest.cc/efficiencyMaps:L344> Create hists PixelAlive_C0 .. PixelAlive_C15
[15:05:31.544] INFO: PixTestAlive::aliveTest() done
[15:05:31.544] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 1 0 0 0 0 1 0 0 0 2
[15:05:31.544] DEBUG: <PixTestAlive.cc/aliveTest:L188> number of red-efficiency pixels: 0 0 0 0 0 0 1 0 0 0 0 1 0 0 0 3
[15:05:31.546] INFO: ----------------------------------------------------------------------
[15:05:31.546] INFO: PixTestAlive::maskTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[15:05:31.546] INFO: ----------------------------------------------------------------------
[15:05:31.549] DEBUG: <PixTest.cc/efficiencyMaps:L328> attempt #0
[15:05:34.218] INFO: Test took 2669ms.
[15:05:34.220] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:05:34.220] DEBUG: <PixTest.cc/efficiencyMaps:L339> eff result size = 0
[15:05:34.220] DEBUG: <PixTest.cc/efficiencyMaps:L344> Create hists MaskTest_C0 .. MaskTest_C15
[15:05:34.221] INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[15:05:34.460] INFO: PixTestAlive::maskTest() done
[15:05:34.460] INFO: number of mask-defect pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:05:34.462] INFO: ----------------------------------------------------------------------
[15:05:34.462] INFO: PixTestAlive::addressDecodingTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[15:05:34.462] INFO: ----------------------------------------------------------------------
[15:05:34.464] DEBUG: <PixTest.cc/efficiencyMaps:L328> attempt #0
[15:05:38.213] INFO: Test took 3749ms.
[15:05:38.234] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:05:38.234] DEBUG: <PixTest.cc/efficiencyMaps:L339> eff result size = 66556
[15:05:38.234] DEBUG: <PixTest.cc/efficiencyMaps:L344> Create hists AddressDecodingTest_C0 .. AddressDecodingTest_C15
[15:05:38.477] INFO: PixTestAlive::addressDecodingTest() done
[15:05:38.477] INFO: number of address-decoding pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:05:38.477] INFO: PixTestAlive::doTest() done, duration: 10 seconds
[15:05:38.477] DEBUG: <PixTestAlive.cc/~PixTestAlive:L109> PixTestAlive dtor
[15:05:38.482] DEBUG: <PixTestBBMap.cc/init:L79> PixTestBBMap::init()
[15:05:38.482] DEBUG: <PixTestBBMap.cc/PixTestBBMap:L27> PixTestBBMap ctor(PixSetup &a, string, TGTab *)
[15:05:38.484] INFO: ######################################################################
[15:05:38.484] INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[15:05:38.484] INFO: ######################################################################
[15:05:38.488] INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (30) hits flags = 2 (plus default)
[15:05:38.506] INFO: dacScan step from 0 .. 29
[15:05:38.506] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:05:56.493] INFO: Test took 17987ms.
[15:05:56.529] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:05:56.529] INFO: dacScan step from 30 .. 59
[15:05:56.529] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:06:15.412] INFO: Test took 18883ms.
[15:06:15.513] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:06:15.529] INFO: dacScan step from 60 .. 89
[15:06:15.529] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:06:39.520] INFO: Test took 23991ms.
[15:06:39.783] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:06:39.863] INFO: dacScan step from 90 .. 119
[15:06:39.864] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:07:04.645] INFO: Test took 24781ms.
[15:07:04.906] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:07:04.994] INFO: dacScan step from 120 .. 149
[15:07:04.994] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:07:28.759] INFO: Test took 23765ms.
[15:07:29.032] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:07:29.095] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[15:07:30.610] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[15:07:32.518] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[15:07:34.122] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[15:07:36.837] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[15:07:38.275] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[15:07:39.655] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[15:07:41.114] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[15:07:42.386] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[15:07:43.781] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[15:07:45.147] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[15:07:46.524] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[15:07:47.847] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[15:07:49.232] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[15:07:50.617] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[15:07:51.913] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[15:07:53.253] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 268271616
[15:07:53.303] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C0_V0
[15:07:53.304] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 101 (obtained for minval = 0) start: 101 .. 123 last peak: 61.1704 last sigma: 6.18377 lcuts[0] = 79.7217 lcuts[1] = 123.008
[15:07:53.304] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C1_V0
[15:07:53.305] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 104 (obtained for minval = 0) start: 104 .. 128 last peak: 61.7303 last sigma: 6.64218 lcuts[0] = 81.6568 lcuts[1] = 128.152
[15:07:53.306] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C2_V0
[15:07:53.307] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 95 (obtained for minval = 0) start: 95 .. 116 last peak: 56.8651 last sigma: 5.91643 lcuts[0] = 74.6144 lcuts[1] = 116.029
[15:07:53.307] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C3_V0
[15:07:53.308] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 93 (obtained for minval = 0) start: 93 .. 114 last peak: 53.4345 last sigma: 6.09072 lcuts[0] = 71.7067 lcuts[1] = 114.342
[15:07:53.309] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C4_V0
[15:07:53.309] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 75 (obtained for minval = 0) start: 75 .. 92 last peak: 44.2475 last sigma: 4.87296 lcuts[0] = 58.8664 lcuts[1] = 92.9771
[15:07:53.310] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C5_V0
[15:07:53.310] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 114 (obtained for minval = 0) start: 114 .. 139 last peak: 69.2898 last sigma: 6.99655 lcuts[0] = 90.2794 lcuts[1] = 139.255
[15:07:53.311] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C6_V0
[15:07:53.312] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 96 (obtained for minval = 0) start: 96 .. 118 last peak: 56.6831 last sigma: 6.18328 lcuts[0] = 75.2329 lcuts[1] = 118.516
[15:07:53.312] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C7_V0
[15:07:53.313] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 79 (obtained for minval = 0) start: 79 .. 95 last peak: 49.8595 last sigma: 4.60259 lcuts[0] = 63.6673 lcuts[1] = 95.8855
[15:07:53.313] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C8_V0
[15:07:53.314] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 109 (obtained for minval = 0) start: 109 .. 135 last peak: 62.261 last sigma: 7.28896 lcuts[0] = 84.1279 lcuts[1] = 135.151
[15:07:53.314] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C9_V0
[15:07:53.315] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 100 (obtained for minval = 0) start: 100 .. 122 last peak: 59.8892 last sigma: 6.25066 lcuts[0] = 78.6412 lcuts[1] = 122.396
[15:07:53.315] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C10_V0
[15:07:53.315] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 102 (obtained for minval = 0) start: 102 .. 125 last peak: 59.5903 last sigma: 6.63773 lcuts[0] = 79.5035 lcuts[1] = 125.968
[15:07:53.316] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C11_V0
[15:07:53.316] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 98 (obtained for minval = 0) start: 98 .. 119 last peak: 57.8051 last sigma: 6.19576 lcuts[0] = 76.3924 lcuts[1] = 119.763
[15:07:53.316] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C12_V0
[15:07:53.317] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 110 (obtained for minval = 0) start: 110 .. 135 last peak: 64.6105 last sigma: 7.12525 lcuts[0] = 85.9862 lcuts[1] = 135.863
[15:07:53.317] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C13_V0
[15:07:53.317] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 109 (obtained for minval = 0) start: 109 .. 132 last peak: 65.8701 last sigma: 6.64479 lcuts[0] = 85.8045 lcuts[1] = 132.318
[15:07:53.318] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C14_V0
[15:07:53.318] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 102 (obtained for minval = 0) start: 102 .. 125 last peak: 60.4442 last sigma: 6.48349 lcuts[0] = 79.8946 lcuts[1] = 125.279
[15:07:53.318] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C15_V0
[15:07:53.319] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 99 (obtained for minval = 0) start: 99 .. 121 last peak: 57.5998 last sigma: 6.43569 lcuts[0] = 76.9069 lcuts[1] = 121.957
[15:07:53.320] INFO: PixTestBBMap::doTest() done, duration: 134 seconds
[15:07:53.320] INFO: number of dead bumps (per ROC): 2 3 1 0 1 0 2 1 0 0 0 1 0 1 2 2
[15:07:53.320] INFO: separation cut (per ROC): 102 105 96 94 76 115 97 80 110 101 103 99 111 110 103 100
[15:07:53.320] DEBUG: <PixTestBBMap.cc/~PixTestBBMap:L97> PixTestBBMap dtor
[15:07:53.393] DEBUG: <PixTestScurves.cc/setParameter:L92> set fOutputFilename =
[15:07:53.395] INFO: ######################################################################
[15:07:53.395] INFO: PixTestScurves::fullTest() ntrig = 50
[15:07:53.395] INFO: ######################################################################
[15:07:53.395] INFO: ----------------------------------------------------------------------
[15:07:53.395] INFO: PixTestScurves::scurves(Vcal), ntrig = 50
[15:07:53.395] INFO: ----------------------------------------------------------------------
[15:07:53.396] INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 0 .. 149 (10) hits flags = 16 (plus default)
[15:07:53.414] INFO: dacScan step from 0 .. 9
[15:07:53.414] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0


[15:08:28.012] INFO: Test took 34598ms.
[15:08:28.083] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:08:28.083] INFO: dacScan step from 10 .. 19
[15:08:28.083] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:09:02.724] INFO: Test took 34641ms.
[15:09:02.793] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:09:02.793] INFO: dacScan step from 20 .. 29
[15:09:02.794] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0


[15:09:37.527] INFO: Test took 34733ms.
[15:09:37.595] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:09:37.595] INFO: dacScan step from 30 .. 39
[15:09:37.595] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0


[15:10:12.274] INFO: Test took 34679ms.
[15:10:12.350] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:10:12.350] INFO: dacScan step from 40 .. 49
[15:10:12.350] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0


[15:10:47.054] INFO: Test took 34704ms.
[15:10:47.122] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:10:47.122] INFO: dacScan step from 50 .. 59
[15:10:47.123] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0






[15:11:21.762] INFO: Test took 34639ms.
[15:11:21.832] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:11:21.832] INFO: dacScan step from 60 .. 69
[15:11:21.832] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:11:56.579] INFO: Test took 34747ms.
[15:11:56.647] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:11:56.648] INFO: dacScan step from 70 .. 79
[15:11:56.648] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:12:31.489] INFO: Test took 34841ms.
[15:12:31.571] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:12:31.571] INFO: dacScan step from 80 .. 89
[15:12:31.571] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0















[15:13:07.486] INFO: Test took 35915ms.
[15:13:07.682] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:13:07.691] INFO: dacScan step from 90 .. 99
[15:13:07.691] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0





[15:13:48.931] INFO: Test took 41240ms.
[15:13:49.238] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:13:49.255] INFO: dacScan step from 100 .. 109
[15:13:49.255] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0


[15:14:38.538] INFO: Test took 49283ms.
[15:14:39.022] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:14:39.050] INFO: dacScan step from 110 .. 119
[15:14:39.050] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0




















[15:15:34.972] INFO: Test took 55922ms.
[15:15:35.572] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:15:35.611] INFO: dacScan step from 120 .. 129
[15:15:35.612] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0







[15:16:33.205] INFO: Test took 57593ms.
[15:16:33.793] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:16:33.829] INFO: dacScan step from 130 .. 139
[15:16:33.829] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0


[15:17:32.614] INFO: Test took 58785ms.
[15:17:33.179] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:17:33.216] INFO: dacScan step from 140 .. 149
[15:17:33.216] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0














[15:18:31.029] INFO: Test took 57813ms.
[15:18:31.595] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:18:31.631] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[15:18:31.631] INFO: dumping ASCII scurve output file: SCurveData
[15:18:32.836] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[15:18:32.837] INFO: dumping ASCII scurve output file: SCurveData
[15:18:34.055] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[15:18:34.055] INFO: dumping ASCII scurve output file: SCurveData
[15:18:35.289] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[15:18:35.289] INFO: dumping ASCII scurve output file: SCurveData
[15:18:36.529] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[15:18:36.529] INFO: dumping ASCII scurve output file: SCurveData
[15:18:37.795] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[15:18:37.795] INFO: dumping ASCII scurve output file: SCurveData
[15:18:38.990] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[15:18:38.990] INFO: dumping ASCII scurve output file: SCurveData
[15:18:40.240] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[15:18:40.240] INFO: dumping ASCII scurve output file: SCurveData
[15:18:41.507] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[15:18:41.507] INFO: dumping ASCII scurve output file: SCurveData
[15:18:42.733] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[15:18:42.733] INFO: dumping ASCII scurve output file: SCurveData
[15:18:43.967] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[15:18:43.967] INFO: dumping ASCII scurve output file: SCurveData
[15:18:45.185] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[15:18:45.185] INFO: dumping ASCII scurve output file: SCurveData
[15:18:46.430] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[15:18:46.430] INFO: dumping ASCII scurve output file: SCurveData
[15:18:47.656] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[15:18:47.656] INFO: dumping ASCII scurve output file: SCurveData
[15:18:48.875] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[15:18:48.875] INFO: dumping ASCII scurve output file: SCurveData
[15:18:50.095] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[15:18:50.095] INFO: dumping ASCII scurve output file: SCurveData
[15:18:51.316] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 618405888
[15:18:51.367] INFO: PixTestScurves::scurves() done
[15:18:51.367] INFO: Vcal mean: 108.73 100.98 93.32 90.37 91.81 117.91 101.49 82.94 110.84 105.13 107.60 102.15 107.10 97.57 99.85 98.75
[15:18:51.367] INFO: Vcal RMS: 5.56 5.99 6.13 5.49 6.46 6.23 6.24 4.61 6.24 5.99 5.82 6.76 5.77 6.00 6.00 6.37
[15:18:51.367] INFO: PixTestScurves::fullTest() done, duration: 657 seconds
[15:18:51.367] DEBUG: <PixTestScurves.cc/~PixTestScurves:L141> PixTestScurves dtor
[15:18:51.431] INFO: ######################################################################
[15:18:51.431] INFO: PixTestTrim::doTest()
[15:18:51.431] INFO: ######################################################################
[15:18:51.433] INFO: ----------------------------------------------------------------------
[15:18:51.433] INFO: PixTestTrim::trimTest() ntrig = 10, vcal = 35
[15:18:51.433] INFO: ----------------------------------------------------------------------
[15:18:51.501] INFO: ---> VthrComp thr map (minimal VthrComp)
[15:18:51.501] INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 5 dacrange: 0 .. 159 (20) hits flags = 16 (plus default)
[15:18:51.513] INFO: dacScan step from 0 .. 19
[15:18:51.514] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:19:03.966] INFO: Test took 12452ms.
[15:19:03.997] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:19:03.997] INFO: dacScan step from 20 .. 39
[15:19:03.997] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:19:16.428] INFO: Test took 12431ms.
[15:19:16.453] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:19:16.453] INFO: dacScan step from 40 .. 59
[15:19:16.453] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:19:29.108] INFO: Test took 12655ms.
[15:19:29.135] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:19:29.135] INFO: dacScan step from 60 .. 79
[15:19:29.135] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:19:41.788] INFO: Test took 12653ms.
[15:19:41.813] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:19:41.813] INFO: dacScan step from 80 .. 99
[15:19:41.814] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:19:54.595] INFO: Test took 12781ms.
[15:19:54.637] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:19:54.640] INFO: dacScan step from 100 .. 119
[15:19:54.640] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:20:09.024] INFO: Test took 14384ms.
[15:20:09.154] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:20:09.179] INFO: dacScan step from 120 .. 139
[15:20:09.179] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:20:26.534] INFO: Test took 17355ms.
[15:20:26.698] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:20:26.740] INFO: dacScan step from 140 .. 159
[15:20:26.740] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:20:40.526] INFO: Test took 13786ms.
[15:20:40.615] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:20:40.632] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[15:20:41.831] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[15:20:42.998] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[15:20:44.137] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[15:20:45.299] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[15:20:46.355] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[15:20:47.546] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[15:20:48.708] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[15:20:49.813] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[15:20:51.003] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[15:20:52.195] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[15:20:53.394] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[15:20:54.567] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[15:20:55.793] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[15:20:57.016] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[15:20:58.178] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[15:20:59.389] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 618528768
[15:20:59.391] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 104.525 minThrLimit = 104.51 minThrNLimit = 129.317 -> result = 104.525 -> 104
[15:20:59.391] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 99.7574 minThrLimit = 99.7568 minThrNLimit = 119.104 -> result = 99.7574 -> 99
[15:20:59.392] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 93.0791 minThrLimit = 92.9642 minThrNLimit = 112.874 -> result = 93.0791 -> 93
[15:20:59.393] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 95.4197 minThrLimit = 95.4196 minThrNLimit = 118.07 -> result = 95.4197 -> 95
[15:20:59.393] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 81.7439 minThrLimit = 81.6835 minThrNLimit = 99.058 -> result = 81.7439 -> 81
[15:20:59.394] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 110.299 minThrLimit = 110.222 minThrNLimit = 135.979 -> result = 110.299 -> 110
[15:20:59.394] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 99.7687 minThrLimit = 99.7411 minThrNLimit = 119.32 -> result = 99.7687 -> 99
[15:20:59.394] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 85.4868 minThrLimit = 85.4864 minThrNLimit = 106.293 -> result = 85.4868 -> 85
[15:20:59.394] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 106.05 minThrLimit = 106.006 minThrNLimit = 129.539 -> result = 106.05 -> 106
[15:20:59.395] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 101.283 minThrLimit = 101.275 minThrNLimit = 123.6 -> result = 101.283 -> 101
[15:20:59.395] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 103.032 minThrLimit = 102.96 minThrNLimit = 125.97 -> result = 103.032 -> 103
[15:20:59.395] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 97.8552 minThrLimit = 97.8006 minThrNLimit = 118.022 -> result = 97.8552 -> 97
[15:20:59.396] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 103.611 minThrLimit = 103.584 minThrNLimit = 127.083 -> result = 103.611 -> 103
[15:20:59.396] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 100.799 minThrLimit = 100.755 minThrNLimit = 128.577 -> result = 100.799 -> 100
[15:20:59.396] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 99.3078 minThrLimit = 99.2563 minThrNLimit = 120.531 -> result = 99.3078 -> 99
[15:20:59.397] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 100.86 minThrLimit = 100.839 minThrNLimit = 126.754 -> result = 100.86 -> 100
[15:20:59.397] INFO: ROC 0 VthrComp = 104
[15:20:59.397] INFO: ROC 1 VthrComp = 99
[15:20:59.397] INFO: ROC 2 VthrComp = 93
[15:20:59.397] INFO: ROC 3 VthrComp = 95
[15:20:59.398] INFO: ROC 4 VthrComp = 81
[15:20:59.398] INFO: ROC 5 VthrComp = 110
[15:20:59.398] INFO: ROC 6 VthrComp = 99
[15:20:59.398] INFO: ROC 7 VthrComp = 85
[15:20:59.399] INFO: ROC 8 VthrComp = 106
[15:20:59.399] INFO: ROC 9 VthrComp = 101
[15:20:59.399] INFO: ROC 10 VthrComp = 103
[15:20:59.399] INFO: ROC 11 VthrComp = 97
[15:20:59.399] INFO: ROC 12 VthrComp = 103
[15:20:59.400] INFO: ROC 13 VthrComp = 100
[15:20:59.400] INFO: ROC 14 VthrComp = 99
[15:20:59.400] INFO: ROC 15 VthrComp = 100
[15:20:59.400] INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[15:20:59.400] INFO: ---> dac: vcal name: TrimThr1 ntrig: 5 dacrange: 0 .. 159 (20) hits flags = 16 (plus default)
[15:20:59.418] INFO: dacScan step from 0 .. 19
[15:20:59.418] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:21:11.824] INFO: Test took 12406ms.
[15:21:11.851] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:21:11.852] INFO: dacScan step from 20 .. 39
[15:21:11.852] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:21:24.394] INFO: Test took 12542ms.
[15:21:24.426] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:21:24.428] INFO: dacScan step from 40 .. 59
[15:21:24.429] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:21:39.307] INFO: Test took 14878ms.
[15:21:39.454] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:21:39.498] INFO: dacScan step from 60 .. 79
[15:21:39.498] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:21:56.658] INFO: Test took 17160ms.
[15:21:56.828] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:21:56.895] INFO: dacScan step from 80 .. 99
[15:21:56.895] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:22:14.065] INFO: Test took 17170ms.
[15:22:14.230] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:22:14.293] INFO: dacScan step from 100 .. 119
[15:22:14.293] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:22:31.575] INFO: Test took 17282ms.
[15:22:31.743] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:22:31.804] INFO: dacScan step from 120 .. 139
[15:22:31.804] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:22:50.527] INFO: Test took 18723ms.
[15:22:50.693] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:22:50.754] INFO: dacScan step from 140 .. 159
[15:22:50.754] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:23:07.894] INFO: Test took 17140ms.
[15:23:08.062] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:23:08.125] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[15:23:09.541] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[15:23:10.946] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[15:23:12.337] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[15:23:13.723] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[15:23:15.187] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[15:23:16.648] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[15:23:18.101] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[15:23:19.511] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[15:23:20.991] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[15:23:22.590] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[15:23:24.368] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[15:23:25.884] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[15:23:27.353] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[15:23:28.753] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[15:23:30.143] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[15:23:31.556] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 618528768
[15:23:31.563] INFO: roc 0 with ID = 0 has maximal Vcal 64.8183 for pixel 0/63 mean/min/max = 49.2766/33.678/64.8751
[15:23:31.563] INFO: roc 1 with ID = 1 has maximal Vcal 61.6791 for pixel 1/79 mean/min/max = 46.707/31.6258/61.7882
[15:23:31.564] INFO: roc 2 with ID = 2 has maximal Vcal 61.9249 for pixel 25/23 mean/min/max = 46.4168/30.8542/61.9793
[15:23:31.564] INFO: roc 3 with ID = 3 has maximal Vcal 58.5833 for pixel 25/6 mean/min/max = 45.1706/31.6692/58.6721
[15:23:31.565] INFO: roc 4 with ID = 4 has maximal Vcal 67.9425 for pixel 9/13 mean/min/max = 51.5723/34.9326/68.212
[15:23:31.565] INFO: roc 5 with ID = 5 has maximal Vcal 70.006 for pixel 48/57 mean/min/max = 52.4751/34.8883/70.0619
[15:23:31.565] INFO: roc 6 with ID = 6 has maximal Vcal 62.6916 for pixel 0/5 mean/min/max = 47.236/31.7421/62.7298
[15:23:31.566] INFO: roc 7 with ID = 7 has maximal Vcal 57.8263 for pixel 25/1 mean/min/max = 45.0602/32.2711/57.8494
[15:23:31.566] INFO: roc 8 with ID = 8 has maximal Vcal 68.853 for pixel 24/66 mean/min/max = 51.0267/33.1776/68.8757
[15:23:31.566] INFO: roc 9 with ID = 9 has maximal Vcal 64.3121 for pixel 1/2 mean/min/max = 48.0155/31.5917/64.4393
[15:23:31.567] INFO: roc 10 with ID = 10 has maximal Vcal 64.5496 for pixel 0/79 mean/min/max = 48.1803/31.7046/64.656
[15:23:31.567] INFO: roc 11 with ID = 11 has maximal Vcal 65.3331 for pixel 6/24 mean/min/max = 48.4789/31.4542/65.5037
[15:23:31.567] INFO: roc 12 with ID = 12 has maximal Vcal 63.5575 for pixel 18/76 mean/min/max = 48.0187/32.4238/63.6135
[15:23:31.568] INFO: roc 13 with ID = 13 has maximal Vcal 61.6791 for pixel 18/1 mean/min/max = 46.8793/31.8466/61.912
[15:23:31.568] INFO: roc 14 with ID = 14 has maximal Vcal 60.8033 for pixel 44/79 mean/min/max = 46.0186/31.0004/61.0369
[15:23:31.568] INFO: roc 15 with ID = 15 has maximal Vcal 62.0279 for pixel 0/11 mean/min/max = 47.0445/32.0091/62.0798
[15:23:31.569] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.


[15:24:47.335] INFO: Test took 75766ms.
[15:24:48.121] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.6651 < 35 for itrim = 109; old thr = 33.3555 ... break
[15:24:48.146] DEBUG: <PixTestTrim.cc/trimTest:L309> vtrim: vcal = 35.6165 < 35 for itrim+1 = 120; old thr = 34.9613 ... break
[15:24:48.171] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.8195 < 35 for itrim = 109; old thr = 33.0539 ... break
[15:24:48.198] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.153 < 35 for itrim = 102; old thr = 31.7805 ... break
[15:24:48.219] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.3065 < 35 for itrim = 113; old thr = 34.0225 ... break
[15:24:48.240] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.1944 < 35 for itrim = 131; old thr = 33.1982 ... break
[15:24:48.262] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.7094 < 35 for itrim = 108; old thr = 34.251 ... break
[15:24:48.295] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.7258 < 35 for itrim = 115; old thr = 33.2669 ... break
[15:24:48.319] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 36.497 < 35 for itrim = 136; old thr = 32.9419 ... break
[15:24:48.349] DEBUG: <PixTestTrim.cc/trimTest:L309> vtrim: vcal = 36.0208 < 35 for itrim+1 = 127; old thr = 34.0848 ... break
[15:24:48.368] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.6412 < 35 for itrim = 113; old thr = 34.2899 ... break
[15:24:48.396] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.4514 < 35 for itrim = 128; old thr = 34.5231 ... break
[15:24:48.424] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.1207 < 35 for itrim = 127; old thr = 32.9631 ... break
[15:24:48.459] DEBUG: <PixTestTrim.cc/trimTest:L309> vtrim: vcal = 35.234 < 35 for itrim+1 = 127; old thr = 34.8413 ... break
[15:24:48.492] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.6739 < 35 for itrim = 113; old thr = 33.2068 ... break
[15:24:48.519] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.2047 < 35 for itrim = 113; old thr = 34.5996 ... break
[15:24:48.582] INFO: ---> dac: vcal name: TrimThr2 ntrig: 10 dacrange: 0 .. 199 (20) hits flags = 16 (plus default)
[15:24:48.595] INFO: dacScan step from 0 .. 19
[15:24:48.596] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0


[15:25:07.367] INFO: Test took 18771ms.
[15:25:07.423] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:25:07.425] INFO: dacScan step from 20 .. 39
[15:25:07.425] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:25:30.350] INFO: Test took 22925ms.
[15:25:30.586] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:25:30.624] INFO: dacScan step from 40 .. 59
[15:25:30.624] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:25:58.295] INFO: Test took 27671ms.
[15:25:58.589] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:25:58.653] INFO: dacScan step from 60 .. 79
[15:25:58.653] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:26:26.462] INFO: Test took 27809ms.
[15:26:26.749] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:26:26.820] INFO: dacScan step from 80 .. 99
[15:26:26.820] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:26:54.551] INFO: Test took 27731ms.
[15:26:54.832] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:26:54.897] INFO: dacScan step from 100 .. 119
[15:26:54.897] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:27:22.766] INFO: Test took 27869ms.
[15:27:23.050] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:27:23.113] INFO: dacScan step from 120 .. 139
[15:27:23.113] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0









[15:27:52.360] INFO: Test took 29247ms.
[15:27:52.652] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:27:52.715] INFO: dacScan step from 140 .. 159
[15:27:52.715] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:28:20.802] INFO: Test took 28087ms.
[15:28:21.085] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:28:21.149] INFO: dacScan step from 160 .. 179
[15:28:21.149] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:28:49.108] INFO: Test took 27959ms.
[15:28:49.394] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:28:49.462] INFO: dacScan step from 180 .. 199
[15:28:49.462] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:29:17.994] INFO: Test took 28532ms.
[15:29:18.289] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:29:18.352] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[15:29:19.832] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[15:29:21.269] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[15:29:22.733] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[15:29:24.151] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[15:29:25.718] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[15:29:27.204] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[15:29:28.651] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[15:29:30.106] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[15:29:31.627] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[15:29:33.108] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[15:29:34.607] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[15:29:36.099] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[15:29:37.572] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[15:29:38.946] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[15:29:40.372] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[15:29:41.794] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 618561536
[15:29:41.796] INFO: ---> TrimStepCorr4 extremal thresholds: 0.009605 .. 255.000000
[15:29:41.859] INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 4 dacrange: 0 .. 255 (20) hits flags = 16 (plus default)
[15:29:41.875] INFO: dacScan step from 0 .. 19
[15:29:41.876] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:29:53.166] INFO: Test took 11290ms.
[15:29:53.191] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:29:53.191] INFO: dacScan step from 20 .. 39
[15:29:53.191] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:30:05.555] INFO: Test took 12364ms.
[15:30:05.644] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:30:05.664] INFO: dacScan step from 40 .. 59
[15:30:05.665] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:30:20.561] INFO: Test took 14896ms.
[15:30:20.721] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:30:20.784] INFO: dacScan step from 60 .. 79
[15:30:20.784] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0


[15:30:35.539] INFO: Test took 14755ms.
[15:30:35.699] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:30:35.762] INFO: dacScan step from 80 .. 99
[15:30:35.762] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:30:50.818] INFO: Test took 15056ms.
[15:30:50.969] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:30:51.032] INFO: dacScan step from 100 .. 119
[15:30:51.032] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:31:06.220] INFO: Test took 15188ms.
[15:31:06.369] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:31:06.436] INFO: dacScan step from 120 .. 139
[15:31:06.436] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:31:23.061] INFO: Test took 16625ms.
[15:31:23.211] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:31:23.273] INFO: dacScan step from 140 .. 159
[15:31:23.273] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:31:38.589] INFO: Test took 15316ms.
[15:31:38.740] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:31:38.803] INFO: dacScan step from 160 .. 179
[15:31:38.803] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:31:54.109] INFO: Test took 15306ms.
[15:31:54.259] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:31:54.323] INFO: dacScan step from 180 .. 199
[15:31:54.323] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:32:10.349] INFO: Test took 16026ms.
[15:32:10.497] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:32:10.561] INFO: dacScan step from 200 .. 219
[15:32:10.561] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:32:25.677] INFO: Test took 15116ms.
[15:32:25.828] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:32:25.894] INFO: dacScan step from 220 .. 239
[15:32:25.894] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:32:40.987] INFO: Test took 15093ms.
[15:32:41.141] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:32:41.205] INFO: dacScan step from 240 .. 255
[15:32:41.205] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:32:53.567] INFO: Test took 12361ms.
[15:32:53.687] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:32:53.742] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[15:32:55.454] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[15:32:57.168] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[15:32:58.905] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[15:33:00.652] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[15:33:02.489] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[15:33:04.285] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[15:33:06.116] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[15:33:07.935] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[15:33:09.757] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[15:33:11.605] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[15:33:13.416] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[15:33:15.205] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[15:33:17.002] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[15:33:18.694] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[15:33:20.396] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[15:33:22.111] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 618561536
[15:33:22.179] INFO: ---> TrimStepCorr2 extremal thresholds: 12.953810 .. 47.983223
[15:33:22.243] INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 4 dacrange: 2 .. 57 (20) hits flags = 16 (plus default)
[15:33:22.257] INFO: dacScan step from 2 .. 21
[15:33:22.257] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:33:33.465] INFO: Test took 11208ms.
[15:33:33.490] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:33.490] INFO: dacScan step from 22 .. 41
[15:33:33.490] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:33:46.082] INFO: Test took 12592ms.
[15:33:46.186] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:46.216] INFO: dacScan step from 42 .. 57
[15:33:46.216] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:33:58.752] INFO: Test took 12536ms.
[15:33:58.876] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:58.930] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[15:33:59.805] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[15:34:00.684] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[15:34:01.565] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[15:34:02.453] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[15:34:03.334] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[15:34:04.208] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[15:34:05.089] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[15:34:05.981] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[15:34:06.873] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[15:34:07.771] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[15:34:08.684] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[15:34:09.583] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[15:34:10.502] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[15:34:11.540] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[15:34:12.691] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[15:34:13.582] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 618676224
[15:34:13.649] INFO: ---> TrimStepCorr1a extremal thresholds: 1.798790 .. 47.344125
[15:34:13.721] INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 4 dacrange: 1 .. 57 (20) hits flags = 16 (plus default)
[15:34:13.740] INFO: dacScan step from 1 .. 20
[15:34:13.740] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:34:25.026] INFO: Test took 11285ms.
[15:34:25.050] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:34:25.050] INFO: dacScan step from 21 .. 40
[15:34:25.050] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0









[15:34:37.234] INFO: Test took 12184ms.
[15:34:37.321] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:34:37.349] INFO: dacScan step from 41 .. 57
[15:34:37.349] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:34:50.555] INFO: Test took 13206ms.
[15:34:50.685] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:34:50.747] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[15:34:51.634] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[15:34:52.520] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[15:34:53.405] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[15:34:54.296] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[15:34:55.192] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[15:34:56.091] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[15:34:56.990] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[15:34:57.862] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[15:34:58.731] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[15:34:59.595] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[15:35:00.458] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[15:35:01.323] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[15:35:02.189] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[15:35:03.058] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[15:35:03.920] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[15:35:04.787] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 618676224
[15:35:04.854] INFO: ---> TrimStepCorr1b extremal thresholds: 1.798790 .. 45.054017
[15:35:04.916] INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 4 dacrange: 1 .. 55 (20) hits flags = 16 (plus default)
[15:35:04.929] INFO: dacScan step from 1 .. 20
[15:35:04.930] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:35:16.150] INFO: Test took 11220ms.
[15:35:16.173] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:35:16.173] INFO: dacScan step from 21 .. 40
[15:35:16.173] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:35:28.415] INFO: Test took 12242ms.
[15:35:28.502] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:35:28.533] INFO: dacScan step from 41 .. 55
[15:35:28.533] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:35:40.278] INFO: Test took 11745ms.
[15:35:40.398] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:35:40.445] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[15:35:41.304] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[15:35:42.165] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[15:35:43.031] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[15:35:43.899] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[15:35:44.767] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[15:35:45.634] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[15:35:46.501] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[15:35:47.371] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[15:35:48.233] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[15:35:49.095] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[15:35:49.991] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[15:35:50.859] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[15:35:51.726] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[15:35:52.625] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[15:35:53.491] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[15:35:54.360] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 618680320
[15:35:54.428] INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[15:35:54.428] INFO: ---> dac: vcal name: TrimThrFinal ntrig: 10 dacrange: 15 .. 55 (20) hits flags = 16 (plus default)
[15:35:54.443] INFO: dacScan step from 15 .. 34
[15:35:54.443] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:36:13.142] INFO: Test took 18699ms.
[15:36:13.222] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:36:13.237] INFO: dacScan step from 35 .. 54
[15:36:13.237] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0


[15:36:39.921] INFO: Test took 26684ms.
[15:36:40.227] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:36:40.290] INFO: dacScan step from 55 .. 55
[15:36:40.290] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:36:44.041] INFO: Test took 3751ms.
[15:36:44.062] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:36:44.066] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[15:36:44.802] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[15:36:45.539] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[15:36:46.276] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[15:36:47.016] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[15:36:47.748] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[15:36:48.479] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[15:36:49.215] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[15:36:49.953] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[15:36:50.685] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[15:36:51.422] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[15:36:52.156] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[15:36:52.891] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[15:36:53.631] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[15:36:54.371] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[15:36:55.108] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[15:36:55.849] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 618680320
[15:36:55.906] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//dacParameters35_C0.dat
[15:36:55.906] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//dacParameters35_C1.dat
[15:36:55.906] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//dacParameters35_C2.dat
[15:36:55.906] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//dacParameters35_C3.dat
[15:36:55.907] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//dacParameters35_C4.dat
[15:36:55.907] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//dacParameters35_C5.dat
[15:36:55.907] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//dacParameters35_C6.dat
[15:36:55.907] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//dacParameters35_C7.dat
[15:36:55.907] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//dacParameters35_C8.dat
[15:36:55.907] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//dacParameters35_C9.dat
[15:36:55.907] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//dacParameters35_C10.dat
[15:36:55.907] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//dacParameters35_C11.dat
[15:36:55.907] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//dacParameters35_C12.dat
[15:36:55.907] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//dacParameters35_C13.dat
[15:36:55.907] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//dacParameters35_C14.dat
[15:36:55.907] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//dacParameters35_C15.dat
[15:36:55.907] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//trimParameters35_C0.dat
[15:36:55.913] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//trimParameters35_C1.dat
[15:36:55.919] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//trimParameters35_C2.dat
[15:36:55.925] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//trimParameters35_C3.dat
[15:36:55.931] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//trimParameters35_C4.dat
[15:36:55.937] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//trimParameters35_C5.dat
[15:36:55.942] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//trimParameters35_C6.dat
[15:36:55.948] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//trimParameters35_C7.dat
[15:36:55.954] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//trimParameters35_C8.dat
[15:36:55.960] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//trimParameters35_C9.dat
[15:36:55.965] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//trimParameters35_C10.dat
[15:36:55.971] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//trimParameters35_C11.dat
[15:36:55.977] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//trimParameters35_C12.dat
[15:36:55.982] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//trimParameters35_C13.dat
[15:36:55.988] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//trimParameters35_C14.dat
[15:36:55.994] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//trimParameters35_C15.dat
[15:36:55.000] INFO: PixTestTrim::trimTest() done
[15:36:55.000] INFO: vtrim: 109 120 109 102 113 131 108 115 136 127 113 128 127 127 113 113
[15:36:55.000] INFO: vthrcomp: 104 99 93 95 81 110 99 85 106 101 103 97 103 100 99 100
[15:36:55.000] INFO: vcal mean: 35.19 35.12 35.08 35.05 35.18 35.18 35.09 35.05 35.10 35.06 35.10 35.07 35.03 35.05 34.96 35.02
[15:36:55.000] INFO: vcal RMS: 1.13 1.10 1.19 1.07 1.39 1.22 1.24 1.08 1.35 1.15 1.11 1.45 1.30 1.04 1.09 1.34
[15:36:55.000] INFO: bits mean: 8.57 9.70 10.09 9.81 8.70 8.60 9.39 10.23 9.12 9.55 8.94 9.43 9.62 9.81 9.47 9.22
[15:36:55.000] INFO: bits RMS: 2.61 2.59 2.48 2.64 2.24 2.24 2.65 2.34 2.32 2.56 2.84 2.59 2.39 2.44 2.80 2.69
[15:36:56.018] INFO: ----------------------------------------------------------------------
[15:36:56.018] INFO: PixTestTrim::trimBitTest() ntrig = 10, vtrims = 254 126 63 32
[15:36:56.018] INFO: ----------------------------------------------------------------------
[15:36:56.022] DEBUG: <PixTestTrim.cc/trimBitTest:L518> trimBitTest determine threshold map without trims
[15:36:56.023] INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 10 dacrange: 0 .. 199 (20) hits flags = 16 (plus default)
[15:36:56.036] INFO: dacScan step from 0 .. 19
[15:36:56.037] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:37:14.155] INFO: Test took 18118ms.
[15:37:14.197] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:37:14.197] INFO: dacScan step from 20 .. 39
[15:37:14.197] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:37:32.835] INFO: Test took 18638ms.
[15:37:32.876] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:37:32.877] INFO: dacScan step from 40 .. 59
[15:37:32.877] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:37:51.524] INFO: Test took 18647ms.
[15:37:51.565] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:37:51.565] INFO: dacScan step from 60 .. 79
[15:37:51.565] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0




[15:38:10.105] INFO: Test took 18540ms.
[15:38:10.147] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:38:10.147] INFO: dacScan step from 80 .. 99
[15:38:10.147] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:38:28.394] INFO: Test took 18247ms.
[15:38:28.436] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:38:28.436] INFO: dacScan step from 100 .. 119
[15:38:28.436] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0


[15:38:47.746] INFO: Test took 19310ms.
[15:38:47.852] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:38:47.859] INFO: dacScan step from 120 .. 139
[15:38:47.860] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:39:12.489] INFO: Test took 24629ms.
[15:39:12.716] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:39:12.745] INFO: dacScan step from 140 .. 159
[15:39:12.745] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:39:40.081] INFO: Test took 27336ms.
[15:39:40.367] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:39:40.424] INFO: dacScan step from 160 .. 179
[15:39:40.424] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:40:08.435] INFO: Test took 28011ms.
[15:40:08.723] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:40:08.782] INFO: dacScan step from 180 .. 199
[15:40:08.782] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:40:37.618] INFO: Test took 28835ms.
[15:40:37.899] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:40:37.960] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[15:40:39.313] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[15:40:40.677] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[15:40:42.082] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[15:40:43.474] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[15:40:44.861] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[15:40:46.149] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[15:40:47.507] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[15:40:48.908] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[15:40:50.238] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[15:40:51.635] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[15:40:52.988] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[15:40:54.358] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[15:40:55.705] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[15:40:57.076] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[15:40:58.463] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[15:40:59.843] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 618696704
[15:40:59.843] DEBUG: <PixTestTrim.cc/trimBitTest:L533> trimBitTest initDUT with trim bits = 14
[15:40:59.908] DEBUG: <PixTestTrim.cc/trimBitTest:L539> trimBitTest threshold map with trim = 14
[15:40:59.908] INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 10 dacrange: 0 .. 194 (20) hits flags = 16 (plus default)
[15:40:59.920] INFO: dacScan step from 0 .. 19
[15:40:59.920] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0


[15:41:18.060] INFO: Test took 18140ms.
[15:41:18.098] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:41:18.098] INFO: dacScan step from 20 .. 39
[15:41:18.098] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:41:36.477] INFO: Test took 18379ms.
[15:41:36.517] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:41:36.517] INFO: dacScan step from 40 .. 59
[15:41:36.517] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0




[15:41:55.138] INFO: Test took 18621ms.
[15:41:55.179] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:41:55.179] INFO: dacScan step from 60 .. 79
[15:41:55.179] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0






[15:42:13.856] INFO: Test took 18677ms.
[15:42:13.896] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:13.896] INFO: dacScan step from 80 .. 99
[15:42:13.896] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0









[15:42:32.194] INFO: Test took 18298ms.
[15:42:32.244] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:32.245] INFO: dacScan step from 100 .. 119
[15:42:32.245] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:42:52.643] INFO: Test took 20398ms.
[15:42:52.801] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:52.820] INFO: dacScan step from 120 .. 139
[15:42:52.820] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:43:19.983] INFO: Test took 27163ms.
[15:43:20.252] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:43:20.298] INFO: dacScan step from 140 .. 159
[15:43:20.298] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:43:48.202] INFO: Test took 27904ms.
[15:43:48.490] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:43:48.552] INFO: dacScan step from 160 .. 179
[15:43:48.552] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0









[15:44:16.568] INFO: Test took 28016ms.
[15:44:16.851] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:44:16.913] INFO: dacScan step from 180 .. 194
[15:44:16.913] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:44:38.989] INFO: Test took 22076ms.
[15:44:39.196] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:44:39.247] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[15:44:40.617] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[15:44:42.007] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[15:44:43.415] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[15:44:44.834] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[15:44:46.262] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[15:44:47.601] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[15:44:48.987] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[15:44:50.413] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[15:44:51.770] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[15:44:53.168] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[15:44:54.541] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[15:44:55.937] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[15:44:57.320] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[15:44:58.713] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[15:45:00.111] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[15:45:01.505] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 618696704
[15:45:01.506] DEBUG: <PixTestTrim.cc/trimBitTest:L533> trimBitTest initDUT with trim bits = 13
[15:45:01.571] DEBUG: <PixTestTrim.cc/trimBitTest:L539> trimBitTest threshold map with trim = 13
[15:45:01.571] INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 10 dacrange: 0 .. 181 (20) hits flags = 16 (plus default)
[15:45:01.585] INFO: dacScan step from 0 .. 19
[15:45:01.585] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0


[15:45:19.789] INFO: Test took 18204ms.
[15:45:19.832] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:45:19.833] INFO: dacScan step from 20 .. 39
[15:45:19.833] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:45:38.243] INFO: Test took 18409ms.
[15:45:38.287] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:45:38.287] INFO: dacScan step from 40 .. 59
[15:45:38.287] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:45:56.902] INFO: Test took 18615ms.
[15:45:56.942] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:45:56.942] INFO: dacScan step from 60 .. 79
[15:45:56.942] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:46:15.510] INFO: Test took 18568ms.
[15:46:15.547] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:46:15.548] INFO: dacScan step from 80 .. 99
[15:46:15.548] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:46:34.160] INFO: Test took 18612ms.
[15:46:34.208] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:46:34.209] INFO: dacScan step from 100 .. 119
[15:46:34.209] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0


[15:46:54.529] INFO: Test took 20320ms.
[15:46:54.697] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:46:54.715] INFO: dacScan step from 120 .. 139
[15:46:54.715] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:47:21.827] INFO: Test took 27112ms.
[15:47:22.095] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:47:22.142] INFO: dacScan step from 140 .. 159
[15:47:22.142] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:47:49.960] INFO: Test took 27818ms.
[15:47:50.245] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:47:50.308] INFO: dacScan step from 160 .. 179
[15:47:50.308] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0











[15:48:17.769] INFO: Test took 27461ms.
[15:48:18.082] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:48:18.145] INFO: dacScan step from 180 .. 181
[15:48:18.145] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:48:23.092] INFO: Test took 4947ms.
[15:48:23.121] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:48:23.131] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[15:48:24.400] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[15:48:25.694] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[15:48:27.091] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[15:48:28.412] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[15:48:29.726] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[15:48:30.954] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[15:48:32.232] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[15:48:33.550] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[15:48:34.796] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[15:48:36.073] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[15:48:37.342] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[15:48:38.630] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[15:48:39.907] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[15:48:41.204] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[15:48:42.502] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[15:48:43.808] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 618696704
[15:48:43.809] DEBUG: <PixTestTrim.cc/trimBitTest:L533> trimBitTest initDUT with trim bits = 11
[15:48:43.875] DEBUG: <PixTestTrim.cc/trimBitTest:L539> trimBitTest threshold map with trim = 11
[15:48:43.875] INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 10 dacrange: 0 .. 182 (20) hits flags = 16 (plus default)
[15:48:43.891] INFO: dacScan step from 0 .. 19
[15:48:43.891] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0


[15:49:02.259] INFO: Test took 18368ms.
[15:49:02.303] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:49:02.303] INFO: dacScan step from 20 .. 39
[15:49:02.303] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0




[15:49:20.592] INFO: Test took 18289ms.
[15:49:20.631] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:49:20.631] INFO: dacScan step from 40 .. 59
[15:49:20.631] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:49:39.263] INFO: Test took 18632ms.
[15:49:39.306] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:49:39.306] INFO: dacScan step from 60 .. 79
[15:49:39.306] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:49:57.928] INFO: Test took 18622ms.
[15:49:57.968] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:49:57.968] INFO: dacScan step from 80 .. 99
[15:49:57.968] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:50:16.598] INFO: Test took 18630ms.
[15:50:16.649] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:50:16.650] INFO: dacScan step from 100 .. 119
[15:50:16.651] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:50:37.079] INFO: Test took 20428ms.
[15:50:37.235] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:50:37.252] INFO: dacScan step from 120 .. 139
[15:50:37.252] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:51:04.383] INFO: Test took 27131ms.
[15:51:04.662] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:51:04.711] INFO: dacScan step from 140 .. 159
[15:51:04.711] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0









[15:51:32.622] INFO: Test took 27911ms.
[15:51:32.919] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:51:32.982] INFO: dacScan step from 160 .. 179
[15:51:32.983] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0









[15:52:00.468] INFO: Test took 27485ms.
[15:52:00.753] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:52:00.816] INFO: dacScan step from 180 .. 182
[15:52:00.816] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:52:07.268] INFO: Test took 6452ms.
[15:52:07.315] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:52:07.328] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[15:52:08.643] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[15:52:09.980] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[15:52:11.351] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[15:52:12.713] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[15:52:14.059] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[15:52:15.313] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[15:52:16.618] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[15:52:17.967] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[15:52:19.242] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[15:52:20.546] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[15:52:21.846] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[15:52:23.157] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[15:52:24.463] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[15:52:25.806] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[15:52:27.146] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[15:52:28.495] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 618696704
[15:52:28.496] DEBUG: <PixTestTrim.cc/trimBitTest:L533> trimBitTest initDUT with trim bits = 7
[15:52:28.562] DEBUG: <PixTestTrim.cc/trimBitTest:L539> trimBitTest threshold map with trim = 7
[15:52:28.562] INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 10 dacrange: 0 .. 181 (20) hits flags = 16 (plus default)
[15:52:28.577] INFO: dacScan step from 0 .. 19
[15:52:28.577] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:52:46.988] INFO: Test took 18411ms.
[15:52:47.026] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:52:47.026] INFO: dacScan step from 20 .. 39
[15:52:47.026] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:53:05.224] INFO: Test took 18198ms.
[15:53:05.263] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:53:05.263] INFO: dacScan step from 40 .. 59
[15:53:05.263] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:53:23.878] INFO: Test took 18615ms.
[15:53:23.929] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:53:23.929] INFO: dacScan step from 60 .. 79
[15:53:23.929] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0


[15:53:42.537] INFO: Test took 18608ms.
[15:53:42.577] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:53:42.577] INFO: dacScan step from 80 .. 99
[15:53:42.577] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:54:00.826] INFO: Test took 18249ms.
[15:54:00.877] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:54:00.878] INFO: dacScan step from 100 .. 119
[15:54:00.878] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:54:21.707] INFO: Test took 20829ms.
[15:54:21.866] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:54:21.885] INFO: dacScan step from 120 .. 139
[15:54:21.885] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0


[15:54:49.090] INFO: Test took 27205ms.
[15:54:49.359] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:54:49.407] INFO: dacScan step from 140 .. 159
[15:54:49.407] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:55:16.358] INFO: Test took 26951ms.
[15:55:16.640] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:55:16.697] INFO: dacScan step from 160 .. 179
[15:55:16.698] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:55:44.907] INFO: Test took 28209ms.
[15:55:45.182] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:55:45.243] INFO: dacScan step from 180 .. 181
[15:55:45.243] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[15:55:50.325] INFO: Test took 5081ms.
[15:55:50.358] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:55:50.368] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[15:55:51.638] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[15:55:52.931] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[15:55:54.248] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[15:55:55.568] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[15:55:56.888] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[15:55:58.114] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[15:55:59.393] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[15:56:00.714] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[15:56:01.964] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[15:56:03.243] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[15:56:04.515] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[15:56:05.807] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[15:56:07.087] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[15:56:08.388] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[15:56:09.686] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[15:56:10.997] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 618696704
[15:56:10.997] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 0 step 0: thr difference mean: 11.779, thr difference RMS: 1.27434
[15:56:10.998] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 1 step 0: thr difference mean: 10.6522, thr difference RMS: 1.10935
[15:56:10.998] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 2 step 0: thr difference mean: 10.0844, thr difference RMS: 1.46038
[15:56:10.998] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 3 step 0: thr difference mean: 8.57305, thr difference RMS: 1.29409
[15:56:10.998] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 4 step 0: thr difference mean: 10.365, thr difference RMS: 1.3301
[15:56:10.998] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 5 step 0: thr difference mean: 12.5202, thr difference RMS: 1.304
[15:56:10.998] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 6 step 0: thr difference mean: 11.3181, thr difference RMS: 1.00565
[15:56:10.999] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 7 step 0: thr difference mean: 8.78061, thr difference RMS: 1.12134
[15:56:10.999] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 8 step 0: thr difference mean: 10.7956, thr difference RMS: 1.22565
[15:56:10.999] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 9 step 0: thr difference mean: 11.3808, thr difference RMS: 1.07663
[15:56:10.999] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 10 step 0: thr difference mean: 10.7158, thr difference RMS: 0.963471
[15:56:10.999] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 11 step 0: thr difference mean: 10.8138, thr difference RMS: 1.11871
[15:56:10.999] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 12 step 0: thr difference mean: 11.902, thr difference RMS: 1.2785
[15:56:10.000] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 13 step 0: thr difference mean: 9.44335, thr difference RMS: 1.41091
[15:56:10.000] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 14 step 0: thr difference mean: 9.65098, thr difference RMS: 1.09523
[15:56:10.000] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 15 step 0: thr difference mean: 9.93456, thr difference RMS: 1.26488
[15:56:10.001] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 0 step 1: thr difference mean: 11.9765, thr difference RMS: 1.26526
[15:56:10.001] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 1 step 1: thr difference mean: 10.6995, thr difference RMS: 1.11342
[15:56:10.001] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 2 step 1: thr difference mean: 10.3719, thr difference RMS: 1.4652
[15:56:10.001] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 3 step 1: thr difference mean: 8.73503, thr difference RMS: 1.29528
[15:56:10.001] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 4 step 1: thr difference mean: 10.296, thr difference RMS: 1.30707
[15:56:10.001] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 5 step 1: thr difference mean: 12.6204, thr difference RMS: 1.31687
[15:56:10.002] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 6 step 1: thr difference mean: 11.4147, thr difference RMS: 1.0161
[15:56:10.002] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 7 step 1: thr difference mean: 8.80419, thr difference RMS: 1.08805
[15:56:10.002] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 8 step 1: thr difference mean: 10.9245, thr difference RMS: 1.22034
[15:56:10.002] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 9 step 1: thr difference mean: 11.5198, thr difference RMS: 1.05857
[15:56:11.002] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 10 step 1: thr difference mean: 10.8112, thr difference RMS: 0.967716
[15:56:11.002] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 11 step 1: thr difference mean: 10.9341, thr difference RMS: 1.11872
[15:56:11.003] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 12 step 1: thr difference mean: 12.0306, thr difference RMS: 1.28133
[15:56:11.003] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 13 step 1: thr difference mean: 9.60309, thr difference RMS: 1.44077
[15:56:11.003] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 14 step 1: thr difference mean: 9.68733, thr difference RMS: 1.09366
[15:56:11.003] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 15 step 1: thr difference mean: 9.8633, thr difference RMS: 1.2582
[15:56:11.003] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 0 step 2: thr difference mean: 12.1643, thr difference RMS: 1.22559
[15:56:11.004] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 1 step 2: thr difference mean: 10.909, thr difference RMS: 1.12533
[15:56:11.004] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 2 step 2: thr difference mean: 10.6431, thr difference RMS: 1.4786
[15:56:11.004] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 3 step 2: thr difference mean: 8.85176, thr difference RMS: 1.28426
[15:56:11.004] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 4 step 2: thr difference mean: 10.3707, thr difference RMS: 1.33009
[15:56:11.004] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 5 step 2: thr difference mean: 12.7101, thr difference RMS: 1.30966
[15:56:11.004] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 6 step 2: thr difference mean: 11.2797, thr difference RMS: 0.996018
[15:56:11.005] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 7 step 2: thr difference mean: 8.76273, thr difference RMS: 1.10674
[15:56:11.005] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 8 step 2: thr difference mean: 11.1126, thr difference RMS: 1.21873
[15:56:11.005] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 9 step 2: thr difference mean: 11.6169, thr difference RMS: 1.04351
[15:56:11.005] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 10 step 2: thr difference mean: 10.9689, thr difference RMS: 0.977782
[15:56:11.005] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 11 step 2: thr difference mean: 10.9972, thr difference RMS: 1.10523
[15:56:11.006] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 12 step 2: thr difference mean: 12.2623, thr difference RMS: 1.2794
[15:56:11.006] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 13 step 2: thr difference mean: 9.68328, thr difference RMS: 1.464
[15:56:11.006] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 14 step 2: thr difference mean: 9.80041, thr difference RMS: 1.10846
[15:56:11.006] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 15 step 2: thr difference mean: 9.97547, thr difference RMS: 1.25723
[15:56:11.006] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 0 step 3: thr difference mean: 12.5165, thr difference RMS: 1.22992
[15:56:11.007] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 1 step 3: thr difference mean: 11.0452, thr difference RMS: 1.13196
[15:56:11.007] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 2 step 3: thr difference mean: 10.8974, thr difference RMS: 1.47578
[15:56:11.007] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 3 step 3: thr difference mean: 9.10159, thr difference RMS: 1.28091
[15:56:11.007] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 4 step 3: thr difference mean: 10.3238, thr difference RMS: 1.31136
[15:56:11.007] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 5 step 3: thr difference mean: 12.6586, thr difference RMS: 1.29229
[15:56:11.008] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 6 step 3: thr difference mean: 11.5516, thr difference RMS: 1.00502
[15:56:11.008] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 7 step 3: thr difference mean: 8.83931, thr difference RMS: 1.11979
[15:56:11.008] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 8 step 3: thr difference mean: 11.2855, thr difference RMS: 1.20688
[15:56:11.008] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 9 step 3: thr difference mean: 11.6049, thr difference RMS: 1.03461
[15:56:11.008] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 10 step 3: thr difference mean: 11.2807, thr difference RMS: 0.990409
[15:56:11.008] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 11 step 3: thr difference mean: 11.1433, thr difference RMS: 1.11384
[15:56:11.009] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 12 step 3: thr difference mean: 12.4992, thr difference RMS: 1.26819
[15:56:11.009] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 13 step 3: thr difference mean: 9.77621, thr difference RMS: 1.47367
[15:56:11.009] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 14 step 3: thr difference mean: 9.83584, thr difference RMS: 1.10662
[15:56:11.009] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 15 step 3: thr difference mean: 9.82557, thr difference RMS: 1.26471
[15:56:11.125] INFO: PixTestTrim::trimBitTest() done
[15:56:11.128] INFO: PixTestTrim::doTest() done, duration: 2239 seconds
[15:56:11.128] DEBUG: <PixTestTrim.cc/~PixTestTrim:L104> PixTestTrim dtor
[15:56:11.717] DEBUG: <PixTest.cc/setTestParameter:L569> setting ntrig to new value 10
[15:56:11.717] DEBUG: <PixTestPhOptimization.cc/setParameter:L37> setting fParNtrig ->10<- from sval = 10
[15:56:11.717] DEBUG: <PixTestPhOptimization.cc/setParameter:L42> setting fSafetyMarginLow ->20<- from sval = 20
[15:56:11.717] DEBUG: <PixTestPhOptimization.cc/setParameter:L48> setting fVcalMax ->100<- from sval = 100
[15:56:11.717] DEBUG: <PixTestPhOptimization.cc/setParameter:L53> setting fQuantMax ->0.98<- from sval = 0.98
[15:56:11.717] INFO: ######################################################################
[15:56:11.717] INFO: PixTestPhOptimization::doTest() Ntrig = 10
[15:56:11.717] INFO: ######################################################################
[15:56:11.719] DEBUG: <PixTest.cc/efficiencyMaps:L328> attempt #0
[15:56:15.449] INFO: Test took 3730ms.
[15:56:15.472] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:56:15.472] DEBUG: <PixTest.cc/efficiencyMaps:L339> eff result size = 66548
[15:56:15.472] DEBUG: <PixTest.cc/efficiencyMaps:L344> Create hists PixelAlive_C0 .. PixelAlive_C15
[15:56:15.476] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [2, 50, 52] has eff 0/10
[15:56:15.476] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [2, 50, 52]
[15:56:15.476] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [4, 3, 23] has eff 0/10
[15:56:15.476] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [4, 3, 23]
[15:56:15.476] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [4, 34, 29] has eff 0/10
[15:56:15.476] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [4, 34, 29]
[15:56:15.476] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [4, 0, 40] has eff 9/10
[15:56:15.476] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [4, 0, 40]
[15:56:15.476] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [6, 6, 11] has eff 0/10
[15:56:15.476] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [6, 6, 11]
[15:56:15.477] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [8, 47, 13] has eff 0/10
[15:56:15.477] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [8, 47, 13]
[15:56:15.477] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [11, 43, 22] has eff 0/10
[15:56:15.477] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [11, 43, 22]
[15:56:15.477] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [11, 48, 32] has eff 0/10
[15:56:15.477] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [11, 48, 32]
[15:56:15.477] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [11, 36, 43] has eff 0/10
[15:56:15.477] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [11, 36, 43]
[15:56:15.477] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [12, 26, 14] has eff 0/10
[15:56:15.477] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [12, 26, 14]
[15:56:15.477] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [12, 36, 51] has eff 0/10
[15:56:15.477] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [12, 36, 51]
[15:56:15.477] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [15, 43, 9] has eff 0/10
[15:56:15.477] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [15, 43, 9]
[15:56:15.477] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [15, 43, 10] has eff 0/10
[15:56:15.477] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [15, 43, 10]
[15:56:15.478] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [15, 37, 52] has eff 8/10
[15:56:15.478] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [15, 37, 52]
[15:56:15.482] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L239> Number of bad pixels found: 14
[15:56:15.482] DEBUG: <PixTestPhOptimization.cc/doTest:L124> **********Ph range will be optimised on the whole ROC***********
[15:56:15.482] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L276> ROC type is newer than digv2
[15:56:15.482] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L277> ROC type is psi46digv21respin
[15:56:15.672] DEBUG: <PixTest.cc/phMaps:L264> attempt #0
[15:56:19.406] INFO: Test took 3734ms.
[15:56:19.469] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:56:19.469] DEBUG: <PixTest.cc/phMaps:L275> eff result size = 66548
[15:56:19.469] DEBUG: <PixTest.cc/phMaps:L282> Create hists maxphmap_C0 .. maxphmap_C15
[15:56:19.473] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 210.077
[15:56:19.473] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,5] phvalue 211
[15:56:19.473] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 210.447
[15:56:19.473] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,5] phvalue 210
[15:56:19.473] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 187.797
[15:56:19.473] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,5] phvalue 188
[15:56:19.473] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 220.551
[15:56:19.473] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,5] phvalue 220
[15:56:19.474] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 196.916
[15:56:19.474] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [4 ,15] phvalue 196
[15:56:19.474] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 205.866
[15:56:19.474] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,6] phvalue 206
[15:56:19.474] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 208.75
[15:56:19.474] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,15] phvalue 208
[15:56:19.474] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 215.349
[15:56:19.474] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,5] phvalue 215
[15:56:19.474] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 199.233
[15:56:19.474] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [4 ,6] phvalue 200
[15:56:19.474] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 198.497
[15:56:19.474] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,5] phvalue 199
[15:56:19.474] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 212.671
[15:56:19.474] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,6] phvalue 213
[15:56:19.474] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 196.069
[15:56:19.474] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,15] phvalue 196
[15:56:19.475] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 195.759
[15:56:19.475] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,5] phvalue 196
[15:56:19.475] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 211.448
[15:56:19.475] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [4 ,5] phvalue 212
[15:56:19.475] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 204.148
[15:56:19.475] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [4 ,5] phvalue 204
[15:56:19.475] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 196.406
[15:56:19.475] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,5] phvalue 197
[15:56:19.475] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L427> ROC type is newer than digv2
[15:56:19.475] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L428> ROC type is psi46digv21respin
[15:56:19.475] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L450> init_phScale=150, flag_minPh = 0, minph = 0
[15:56:19.484] DEBUG: <PixTest.cc/phMaps:L264> attempt #0
[15:56:23.227] INFO: Test took 3743ms.
[15:56:23.292] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:56:23.292] DEBUG: <PixTest.cc/phMaps:L275> eff result size = 66549
[15:56:23.292] DEBUG: <PixTest.cc/phMaps:L282> Create hists minphmap_C0 .. minphmap_C15
[15:56:23.295] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L457> result size 0

[15:56:23.296] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L484> done. init_phScale=155, flag_minPh = 1, minph = 69minph_roc = 5
[15:56:23.296] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 97.0411
[15:56:23.296] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [5 ,50] phvalue 98
[15:56:23.296] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 80.5217
[15:56:23.296] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [4 ,12] phvalue 80
[15:56:23.297] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 67.4389
[15:56:23.297] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,12] phvalue 68
[15:56:23.297] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 107.807
[15:56:23.297] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,62] phvalue 108
[15:56:23.297] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 75.0973
[15:56:23.297] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,50] phvalue 76
[15:56:23.297] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 74.9062
[15:56:23.297] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [4 ,6] phvalue 75
[15:56:23.297] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 97.0001
[15:56:23.297] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [4 ,31] phvalue 98
[15:56:23.297] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 97.9286
[15:56:23.297] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,13] phvalue 98
[15:56:23.297] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 77.7603
[15:56:23.297] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,25] phvalue 77
[15:56:23.297] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 80.0591
[15:56:23.297] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,14] phvalue 81
[15:56:23.298] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 91.9632
[15:56:23.298] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [4 ,60] phvalue 92
[15:56:23.298] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 79.1667
[15:56:23.298] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [4 ,50] phvalue 80
[15:56:23.298] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 82.3271
[15:56:23.298] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [10 ,6] phvalue 82
[15:56:23.298] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 98.8932
[15:56:23.298] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,24] phvalue 99
[15:56:23.298] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 79.3095
[15:56:23.298] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [4 ,60] phvalue 80
[15:56:23.298] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 69.5793
[15:56:23.298] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,67] phvalue 70
[15:56:23.300] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 5, 50, 0 0
[15:56:23.301] INFO: The DUT currently contains the following objects:
[15:56:23.301] INFO: 2 TBM Cores tbm08c (2 ON)
[15:56:23.301] INFO: TBM Core alpha (0): 7 registers set
[15:56:23.301] INFO: TBM Core beta (1): 7 registers set
[15:56:23.301] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:56:23.301] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:23.301] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:23.301] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:23.301] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:23.301] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:23.301] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:23.301] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:23.301] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:23.301] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:23.301] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:23.301] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:23.301] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:23.301] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:23.301] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:23.301] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:23.301] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:24.394] INFO: Test took 1093ms.
[15:56:24.395] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[15:56:24.395] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 4, 12, 1 1
[15:56:24.395] INFO: The DUT currently contains the following objects:
[15:56:24.395] INFO: 2 TBM Cores tbm08c (2 ON)
[15:56:24.395] INFO: TBM Core alpha (0): 7 registers set
[15:56:24.395] INFO: TBM Core beta (1): 7 registers set
[15:56:24.395] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:56:24.395] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:24.395] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:24.395] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:24.395] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:24.395] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:24.395] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:24.395] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:24.395] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:24.395] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:24.395] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:24.395] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:24.395] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:24.395] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:24.395] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:24.395] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:24.395] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:25.489] INFO: Test took 1094ms.
[15:56:25.489] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[15:56:25.490] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 12, 2 2
[15:56:25.490] INFO: The DUT currently contains the following objects:
[15:56:25.490] INFO: 2 TBM Cores tbm08c (2 ON)
[15:56:25.490] INFO: TBM Core alpha (0): 7 registers set
[15:56:25.490] INFO: TBM Core beta (1): 7 registers set
[15:56:25.490] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:56:25.490] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:25.490] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:25.490] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:25.490] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:25.490] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:25.490] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:25.490] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:25.490] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:25.490] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:25.490] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:25.490] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:25.490] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:25.490] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:25.490] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:25.490] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:25.490] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:26.582] INFO: Test took 1092ms.
[15:56:26.583] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[15:56:26.583] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 62, 3 3
[15:56:26.583] INFO: The DUT currently contains the following objects:
[15:56:26.583] INFO: 2 TBM Cores tbm08c (2 ON)
[15:56:26.583] INFO: TBM Core alpha (0): 7 registers set
[15:56:26.583] INFO: TBM Core beta (1): 7 registers set
[15:56:26.583] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:56:26.583] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:26.583] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:26.583] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:26.583] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:26.583] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:26.583] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:26.583] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:26.583] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:26.583] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:26.583] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:26.584] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:26.584] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:26.584] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:26.584] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:26.584] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:26.584] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:27.678] INFO: Test took 1094ms.
[15:56:27.679] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[15:56:27.679] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 50, 4 4
[15:56:27.679] INFO: The DUT currently contains the following objects:
[15:56:27.679] INFO: 2 TBM Cores tbm08c (2 ON)
[15:56:27.679] INFO: TBM Core alpha (0): 7 registers set
[15:56:27.679] INFO: TBM Core beta (1): 7 registers set
[15:56:27.679] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:56:27.679] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:27.679] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:27.679] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:27.679] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:27.679] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:27.679] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:27.679] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:27.680] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:27.680] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:27.680] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:27.680] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:27.680] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:27.680] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:27.680] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:27.680] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:27.680] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:28.778] INFO: Test took 1098ms.
[15:56:28.779] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[15:56:28.779] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 4, 6, 5 5
[15:56:28.779] INFO: The DUT currently contains the following objects:
[15:56:28.779] INFO: 2 TBM Cores tbm08c (2 ON)
[15:56:28.779] INFO: TBM Core alpha (0): 7 registers set
[15:56:28.779] INFO: TBM Core beta (1): 7 registers set
[15:56:28.779] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:56:28.780] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:28.780] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:28.780] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:28.780] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:28.780] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:28.780] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:28.780] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:28.780] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:28.780] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:28.780] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:28.780] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:28.780] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:28.780] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:28.780] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:28.780] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:28.780] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:29.869] INFO: Test took 1089ms.
[15:56:29.870] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[15:56:29.870] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 4, 31, 6 6
[15:56:29.870] INFO: The DUT currently contains the following objects:
[15:56:29.870] INFO: 2 TBM Cores tbm08c (2 ON)
[15:56:29.870] INFO: TBM Core alpha (0): 7 registers set
[15:56:29.870] INFO: TBM Core beta (1): 7 registers set
[15:56:29.870] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:56:29.870] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:29.870] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:29.870] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:29.870] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:29.870] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:29.870] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:29.870] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:29.870] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:29.870] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:29.870] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:29.870] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:29.870] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:29.870] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:29.870] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:29.870] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:29.870] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:30.959] INFO: Test took 1089ms.
[15:56:30.960] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[15:56:30.960] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 13, 7 7
[15:56:30.960] INFO: The DUT currently contains the following objects:
[15:56:30.960] INFO: 2 TBM Cores tbm08c (2 ON)
[15:56:30.960] INFO: TBM Core alpha (0): 7 registers set
[15:56:30.960] INFO: TBM Core beta (1): 7 registers set
[15:56:30.960] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:56:30.960] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:30.960] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:30.960] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:30.960] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:30.960] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:30.960] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:30.960] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:30.960] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:30.960] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:30.960] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:30.960] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:30.960] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:30.960] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:30.960] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:30.960] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:30.960] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:32.051] INFO: Test took 1091ms.
[15:56:32.051] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[15:56:32.051] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 25, 8 8
[15:56:32.051] INFO: The DUT currently contains the following objects:
[15:56:32.051] INFO: 2 TBM Cores tbm08c (2 ON)
[15:56:32.051] INFO: TBM Core alpha (0): 7 registers set
[15:56:32.051] INFO: TBM Core beta (1): 7 registers set
[15:56:32.051] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:56:32.051] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:32.051] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:32.051] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:32.051] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:32.051] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:32.051] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:32.051] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:32.051] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:32.051] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:32.051] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:32.051] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:32.051] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:32.051] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:32.051] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:32.051] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:32.052] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:33.141] INFO: Test took 1089ms.
[15:56:33.142] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[15:56:33.142] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 14, 9 9
[15:56:33.142] INFO: The DUT currently contains the following objects:
[15:56:33.142] INFO: 2 TBM Cores tbm08c (2 ON)
[15:56:33.142] INFO: TBM Core alpha (0): 7 registers set
[15:56:33.142] INFO: TBM Core beta (1): 7 registers set
[15:56:33.142] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:56:33.142] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:33.142] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:33.142] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:33.142] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:33.142] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:33.142] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:33.142] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:33.142] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:33.142] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:33.142] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:33.142] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:33.142] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:33.142] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:33.142] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:33.142] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:33.142] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:34.234] INFO: Test took 1092ms.
[15:56:34.235] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[15:56:34.235] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 4, 60, 10 10
[15:56:34.235] INFO: The DUT currently contains the following objects:
[15:56:34.235] INFO: 2 TBM Cores tbm08c (2 ON)
[15:56:34.235] INFO: TBM Core alpha (0): 7 registers set
[15:56:34.235] INFO: TBM Core beta (1): 7 registers set
[15:56:34.235] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:56:34.235] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:34.235] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:34.235] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:34.235] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:34.235] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:34.235] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:34.235] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:34.235] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:34.235] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:34.235] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:34.235] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:34.235] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:34.235] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:34.235] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:34.235] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:34.235] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:35.340] INFO: Test took 1105ms.
[15:56:35.340] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[15:56:35.340] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 4, 50, 11 11
[15:56:35.340] INFO: The DUT currently contains the following objects:
[15:56:35.340] INFO: 2 TBM Cores tbm08c (2 ON)
[15:56:35.340] INFO: TBM Core alpha (0): 7 registers set
[15:56:35.340] INFO: TBM Core beta (1): 7 registers set
[15:56:35.340] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:56:35.340] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:35.340] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:35.341] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:35.341] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:35.341] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:35.341] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:35.341] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:35.341] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:35.341] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:35.341] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:35.341] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:35.341] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:35.341] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:35.341] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:35.341] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:35.341] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:36.431] INFO: Test took 1090ms.
[15:56:36.432] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[15:56:36.432] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 10, 6, 12 12
[15:56:36.432] INFO: The DUT currently contains the following objects:
[15:56:36.432] INFO: 2 TBM Cores tbm08c (2 ON)
[15:56:36.432] INFO: TBM Core alpha (0): 7 registers set
[15:56:36.432] INFO: TBM Core beta (1): 7 registers set
[15:56:36.432] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:56:36.432] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:36.432] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:36.432] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:36.432] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:36.432] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:36.432] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:36.432] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:36.432] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:36.432] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:36.432] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:36.432] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:36.432] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:36.432] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:36.432] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:36.432] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:36.432] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:37.525] INFO: Test took 1093ms.
[15:56:37.525] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[15:56:37.525] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 24, 13 13
[15:56:37.526] INFO: The DUT currently contains the following objects:
[15:56:37.526] INFO: 2 TBM Cores tbm08c (2 ON)
[15:56:37.526] INFO: TBM Core alpha (0): 7 registers set
[15:56:37.526] INFO: TBM Core beta (1): 7 registers set
[15:56:37.526] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:56:37.526] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:37.526] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:37.526] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:37.526] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:37.526] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:37.526] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:37.526] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:37.526] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:37.526] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:37.526] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:37.526] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:37.526] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:37.526] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:37.526] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:37.526] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:37.526] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:38.628] INFO: Test took 1102ms.
[15:56:38.628] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[15:56:38.628] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 4, 60, 14 14
[15:56:38.628] INFO: The DUT currently contains the following objects:
[15:56:38.628] INFO: 2 TBM Cores tbm08c (2 ON)
[15:56:38.628] INFO: TBM Core alpha (0): 7 registers set
[15:56:38.628] INFO: TBM Core beta (1): 7 registers set
[15:56:38.628] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:56:38.628] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:38.628] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:38.629] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:38.629] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:38.629] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:38.629] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:38.629] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:38.629] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:38.629] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:38.629] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:38.629] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:38.629] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:38.629] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:38.629] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:38.629] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:38.629] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:39.720] INFO: Test took 1091ms.
[15:56:39.721] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[15:56:39.721] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 67, 15 15
[15:56:39.721] INFO: The DUT currently contains the following objects:
[15:56:39.721] INFO: 2 TBM Cores tbm08c (2 ON)
[15:56:39.721] INFO: TBM Core alpha (0): 7 registers set
[15:56:39.721] INFO: TBM Core beta (1): 7 registers set
[15:56:39.721] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:56:39.721] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:39.721] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:39.721] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:39.721] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:39.721] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:39.721] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:39.721] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:39.721] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:39.721] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:39.721] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:39.721] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:39.721] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:39.721] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:39.721] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:39.721] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:39.721] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:40.812] INFO: Test took 1091ms.
[15:56:40.813] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[15:56:40.813] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 32 on ROC0
[15:56:40.813] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 30 on ROC1
[15:56:40.813] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 32 on ROC2
[15:56:40.813] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 32 on ROC3
[15:56:40.813] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 29 on ROC4
[15:56:40.813] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 28 on ROC5
[15:56:40.813] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 32 on ROC6
[15:56:40.813] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 31 on ROC7
[15:56:40.813] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 30 on ROC8
[15:56:40.813] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 33 on ROC9
[15:56:40.813] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 30 on ROC10
[15:56:40.813] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 28 on ROC11
[15:56:40.813] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 31 on ROC12
[15:56:40.813] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 29 on ROC13
[15:56:40.813] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 28 on ROC14
[15:56:40.813] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 30 on ROC15
[15:56:40.820] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.






















[15:59:36.387] INFO: Test took 175567ms.
[15:59:37.908] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.






















[16:02:33.781] INFO: Test took 175873ms.
[16:02:35.460] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[16:02:35.460] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip0
[16:02:35.460] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[16:02:35.461] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip1
[16:02:35.461] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[16:02:35.461] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip2
[16:02:35.461] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[16:02:35.461] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip3
[16:02:35.461] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[16:02:35.462] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip4
[16:02:35.462] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[16:02:35.462] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip5
[16:02:35.462] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[16:02:35.463] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip6
[16:02:35.463] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[16:02:35.463] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip7
[16:02:35.463] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[16:02:35.463] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip8
[16:02:35.463] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[16:02:35.464] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip9
[16:02:35.464] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[16:02:35.464] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip10
[16:02:35.464] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[16:02:35.464] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip11
[16:02:35.464] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[16:02:35.465] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip12
[16:02:35.465] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[16:02:35.465] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip13
[16:02:35.465] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[16:02:35.466] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip14
[16:02:35.466] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[16:02:35.466] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip15
[16:02:35.466] INFO: safety margin for low PH: adding 0, margin is now 20
[16:02:35.472] INFO: safety margin for low PH: adding 0, margin is now 20
[16:02:35.479] INFO: safety margin for low PH: adding 0, margin is now 20
[16:02:35.485] INFO: safety margin for low PH: adding 0, margin is now 20
[16:02:35.491] INFO: safety margin for low PH: adding 0, margin is now 20
[16:02:35.497] INFO: safety margin for low PH: adding 0, margin is now 20
[16:02:35.504] INFO: safety margin for low PH: adding 1, margin is now 21
[16:02:35.513] INFO: safety margin for low PH: adding 2, margin is now 22
[16:02:35.521] INFO: safety margin for low PH: adding 3, margin is now 23
[16:02:35.528] INFO: safety margin for low PH: adding 4, margin is now 24
[16:02:35.534] INFO: safety margin for low PH: adding 5, margin is now 25
[16:02:35.541] INFO: safety margin for low PH: adding 0, margin is now 20
[16:02:35.548] INFO: safety margin for low PH: adding 0, margin is now 20
[16:02:35.555] INFO: safety margin for low PH: adding 0, margin is now 20
[16:02:35.561] INFO: safety margin for low PH: adding 1, margin is now 21
[16:02:35.567] INFO: safety margin for low PH: adding 2, margin is now 22
[16:02:35.574] INFO: safety margin for low PH: adding 3, margin is now 23
[16:02:35.581] INFO: safety margin for low PH: adding 4, margin is now 24
[16:02:35.587] INFO: safety margin for low PH: adding 5, margin is now 25
[16:02:35.593] INFO: safety margin for low PH: adding 6, margin is now 26
[16:02:35.600] INFO: safety margin for low PH: adding 7, margin is now 27
[16:02:35.607] INFO: safety margin for low PH: adding 0, margin is now 20
[16:02:35.613] INFO: safety margin for low PH: adding 0, margin is now 20
[16:02:35.620] INFO: safety margin for low PH: adding 1, margin is now 21
[16:02:35.626] INFO: safety margin for low PH: adding 2, margin is now 22
[16:02:35.633] INFO: safety margin for low PH: adding 3, margin is now 23
[16:02:35.639] INFO: safety margin for low PH: adding 4, margin is now 24
[16:02:35.646] INFO: safety margin for low PH: adding 5, margin is now 25
[16:02:35.652] INFO: safety margin for low PH: adding 6, margin is now 26
[16:02:35.658] INFO: safety margin for low PH: adding 0, margin is now 20
[16:02:35.667] INFO: safety margin for low PH: adding 0, margin is now 20
[16:02:35.673] INFO: safety margin for low PH: adding 0, margin is now 20
[16:02:35.681] INFO: safety margin for low PH: adding 0, margin is now 20
[16:02:35.687] INFO: safety margin for low PH: adding 0, margin is now 20
[16:02:35.694] DEBUG: <PixTestPhOptimization.cc/doTest:L172> optimisation done
[16:02:35.745] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//dacParameters35_C0.dat
[16:02:35.745] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//dacParameters35_C1.dat
[16:02:35.745] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//dacParameters35_C2.dat
[16:02:35.745] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//dacParameters35_C3.dat
[16:02:35.745] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//dacParameters35_C4.dat
[16:02:35.745] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//dacParameters35_C5.dat
[16:02:35.745] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//dacParameters35_C6.dat
[16:02:35.745] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//dacParameters35_C7.dat
[16:02:35.745] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//dacParameters35_C8.dat
[16:02:35.745] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//dacParameters35_C9.dat
[16:02:35.746] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//dacParameters35_C10.dat
[16:02:35.746] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//dacParameters35_C11.dat
[16:02:35.746] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//dacParameters35_C12.dat
[16:02:35.746] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//dacParameters35_C13.dat
[16:02:35.746] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//dacParameters35_C14.dat
[16:02:35.746] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//dacParameters35_C15.dat
[16:02:39.486] INFO: Test took 3735ms.
[16:02:43.462] INFO: Test took 3694ms.
[16:02:47.465] INFO: Test took 3726ms.
[16:02:47.750] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:02:48.654] INFO: Test took 904ms.
[16:02:48.657] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:02:49.749] INFO: Test took 1092ms.
[16:02:49.756] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:02:50.845] INFO: Test took 1090ms.
[16:02:50.849] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:02:51.940] INFO: Test took 1091ms.
[16:02:51.947] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:02:53.037] INFO: Test took 1090ms.
[16:02:53.044] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:02:54.132] INFO: Test took 1088ms.
[16:02:54.137] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:02:55.230] INFO: Test took 1093ms.
[16:02:55.237] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:02:56.326] INFO: Test took 1089ms.
[16:02:56.329] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:02:57.421] INFO: Test took 1092ms.
[16:02:57.425] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:02:58.516] INFO: Test took 1091ms.
[16:02:58.520] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:02:59.613] INFO: Test took 1094ms.
[16:02:59.617] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:03:00.706] INFO: Test took 1090ms.
[16:03:00.711] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:03:01.801] INFO: Test took 1090ms.
[16:03:01.804] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:03:02.897] INFO: Test took 1093ms.
[16:03:02.900] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:03:03.993] INFO: Test took 1093ms.
[16:03:03.000] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:03:05.091] INFO: Test took 1091ms.
[16:03:05.098] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:03:06.187] INFO: Test took 1089ms.
[16:03:06.194] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:03:07.289] INFO: Test took 1096ms.
[16:03:07.297] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:03:08.389] INFO: Test took 1092ms.
[16:03:08.393] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:03:09.484] INFO: Test took 1092ms.
[16:03:09.487] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:03:10.581] INFO: Test took 1094ms.
[16:03:10.585] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:03:11.677] INFO: Test took 1092ms.
[16:03:11.682] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:03:12.772] INFO: Test took 1090ms.
[16:03:12.778] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:03:13.866] INFO: Test took 1088ms.
[16:03:13.871] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:03:14.962] INFO: Test took 1091ms.
[16:03:14.966] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:03:16.059] INFO: Test took 1093ms.
[16:03:16.063] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:03:17.155] INFO: Test took 1092ms.
[16:03:17.159] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:03:18.250] INFO: Test took 1091ms.
[16:03:18.257] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:03:19.345] INFO: Test took 1088ms.
[16:03:19.349] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:03:20.441] INFO: Test took 1092ms.
[16:03:20.448] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:03:21.535] INFO: Test took 1087ms.
[16:03:21.541] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:03:22.636] INFO: Test took 1095ms.
[16:03:23.220] INFO: PixTestPhOptimization::doTest() done, duration: 431 seconds
[16:03:23.220] INFO: PH scale (per ROC): 75 80 76 82 66 76 68 81 73 73 80 73 66 79 79 78
[16:03:23.220] INFO: PH offset (per ROC): 158 169 180 145 176 176 160 154 176 172 161 174 175 155 170 176
[16:03:23.367] DEBUG: <PixTestGainPedestal.cc/setParameter:L83> PixTestGainPedestal::PixTest() fVcalStep = 10
[16:03:23.369] INFO: ######################################################################
[16:03:23.369] INFO: PixTestGainPedestal::fullTest() ntrig = 10
[16:03:23.369] INFO: ######################################################################
[16:03:23.369] DEBUG: <PixTestGainPedestal.cc/measure:L192> using FLAGS = 16
[16:03:23.386] INFO: scanning low vcal = 10
[16:03:26.737] INFO: Test took 3351ms.
[16:03:26.741] INFO: scanning low vcal = 20
[16:03:30.061] INFO: Test took 3320ms.
[16:03:30.066] INFO: scanning low vcal = 30
[16:03:33.416] INFO: Test took 3350ms.
[16:03:33.428] INFO: scanning low vcal = 40
[16:03:37.161] INFO: Test took 3733ms.
[16:03:37.223] INFO: scanning low vcal = 50
[16:03:41.016] INFO: Test took 3794ms.
[16:03:41.078] INFO: scanning low vcal = 60
[16:03:44.851] INFO: Test took 3773ms.
[16:03:44.914] INFO: scanning low vcal = 70
[16:03:48.704] INFO: Test took 3790ms.
[16:03:48.765] INFO: scanning low vcal = 80
[16:03:52.549] INFO: Test took 3784ms.
[16:03:52.613] INFO: scanning low vcal = 90
[16:03:56.395] INFO: Test took 3782ms.
[16:03:56.459] INFO: scanning low vcal = 100
[16:04:00.249] INFO: Test took 3790ms.
[16:04:00.312] INFO: scanning low vcal = 110
[16:04:04.107] INFO: Test took 3795ms.
[16:04:04.169] INFO: scanning low vcal = 120
[16:04:07.968] INFO: Test took 3799ms.
[16:04:08.031] INFO: scanning low vcal = 130
[16:04:11.929] INFO: Test took 3898ms.
[16:04:11.992] INFO: scanning low vcal = 140
[16:04:15.878] INFO: Test took 3887ms.
[16:04:15.937] INFO: scanning low vcal = 150
[16:04:19.745] INFO: Test took 3808ms.
[16:04:19.809] INFO: scanning low vcal = 160
[16:04:23.585] INFO: Test took 3775ms.
[16:04:23.643] INFO: scanning low vcal = 170
[16:04:27.433] INFO: Test took 3789ms.
[16:04:27.493] INFO: scanning low vcal = 180
[16:04:31.233] INFO: Test took 3740ms.
[16:04:31.290] INFO: scanning low vcal = 190
[16:04:35.018] INFO: Test took 3728ms.
[16:04:35.077] INFO: scanning low vcal = 200
[16:04:38.819] INFO: Test took 3742ms.
[16:04:38.876] INFO: scanning low vcal = 210
[16:04:42.604] INFO: Test took 3728ms.
[16:04:42.661] INFO: scanning low vcal = 220
[16:04:46.408] INFO: Test took 3747ms.
[16:04:46.467] INFO: scanning low vcal = 230
[16:04:50.211] INFO: Test took 3744ms.
[16:04:50.268] INFO: scanning low vcal = 240
[16:04:53.001] INFO: Test took 3733ms.
[16:04:54.059] INFO: scanning low vcal = 250
[16:04:57.805] INFO: Test took 3746ms.
[16:04:57.865] INFO: scanning high vcal = 30 (= 210 in low range)


[16:05:01.635] INFO: Test took 3769ms.
[16:05:01.697] INFO: scanning high vcal = 50 (= 350 in low range)
[16:05:05.459] INFO: Test took 3762ms.
[16:05:05.521] INFO: scanning high vcal = 70 (= 490 in low range)
[16:05:09.281] INFO: Test took 3760ms.
[16:05:09.344] INFO: scanning high vcal = 90 (= 630 in low range)
[16:05:13.093] INFO: Test took 3750ms.
[16:05:13.155] INFO: scanning high vcal = 200 (= 1400 in low range)
[16:05:16.900] INFO: Test took 3745ms.
[16:05:17.440] INFO: PixTestGainPedestal::measure() done
[16:05:17.441] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C0
[16:05:17.442] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C1
[16:05:17.442] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C2
[16:05:17.443] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C3
[16:05:17.443] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C4
[16:05:17.443] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C5
[16:05:17.443] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C6
[16:05:17.444] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C7
[16:05:17.444] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C8
[16:05:17.444] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C9
[16:05:17.444] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C10
[16:05:17.445] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C11
[16:05:17.445] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C12
[16:05:17.445] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C13
[16:05:17.445] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C14
[16:05:17.445] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C15
[16:05:47.006] INFO: PixTestGainPedestal::fit() done
[16:05:47.006] INFO: non-linearity mean: 0.959 0.955 0.952 0.956 0.954 0.964 0.950 0.950 0.967 0.948 0.966 0.955 0.961 0.955 0.957 0.949
[16:05:47.006] INFO: non-linearity RMS: 0.006 0.005 0.006 0.006 0.008 0.005 0.006 0.006 0.004 0.007 0.004 0.008 0.005 0.004 0.006 0.007
[16:05:47.006] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//phCalibrationFitErr35_C0.dat
[16:05:47.023] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//phCalibrationFitErr35_C1.dat
[16:05:47.040] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//phCalibrationFitErr35_C2.dat
[16:05:47.056] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//phCalibrationFitErr35_C3.dat
[16:05:47.073] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//phCalibrationFitErr35_C4.dat
[16:05:47.090] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//phCalibrationFitErr35_C5.dat
[16:05:47.106] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//phCalibrationFitErr35_C6.dat
[16:05:47.123] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//phCalibrationFitErr35_C7.dat
[16:05:47.140] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//phCalibrationFitErr35_C8.dat
[16:05:47.156] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//phCalibrationFitErr35_C9.dat
[16:05:47.173] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//phCalibrationFitErr35_C10.dat
[16:05:47.189] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//phCalibrationFitErr35_C11.dat
[16:05:47.206] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//phCalibrationFitErr35_C12.dat
[16:05:47.222] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//phCalibrationFitErr35_C13.dat
[16:05:47.239] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//phCalibrationFitErr35_C14.dat
[16:05:47.256] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//003_Fulltest_m20//phCalibrationFitErr35_C15.dat
[16:05:47.272] INFO: PixTestGainPedestal::doTest() done, duration: 143 seconds
[16:05:47.272] DEBUG: <PixTestGainPedestal.cc/~PixTestGainPedestal:L125> PixTestGainPedestal dtor
[16:05:47.279] DEBUG: <PixTestFullTest.cc/~PixTestFullTest:L78> PixTestFullTest dtor
[16:05:47.279] INFO: enter test to run
[16:05:47.279] INFO: test: q no parameter change
[16:05:47.279] DEBUG: <PixMonitor.cc/dumpSummaries:L34> PixMonitor::dumpSummaries
[16:05:47.411] QUIET: Connection to board 111 closed.
[16:05:47.411] INFO: pXar: this is the end, my friend
[16:05:47.411] DEBUG: <PixSetup.cc/~PixSetup:L68> PixSetup free fPxarMemory