[16:34:35.497] INFO: *** Welcome to pxar ***
[16:34:35.497] INFO: *** Today: 2015/07/27
[16:34:35.497] INFO: readRocDacs: /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//dacParameters_C0.dat .. /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//dacParameters_C15.dat
[16:34:35.498] INFO: readTbmDacs: /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//tbmParameters_C0a.dat .. /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//tbmParameters_C0b.dat
[16:34:35.498] INFO: readMaskFile: /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//defaultMaskFile.dat
[16:34:35.498] INFO: readTrimFile: /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//trimParameters_C0.dat .. /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//trimParameters_C15.dat
[16:34:35.559] INFO: clk: 4
[16:34:35.559] INFO: ctr: 4
[16:34:35.559] INFO: sda: 19
[16:34:35.559] INFO: tin: 9
[16:34:35.559] INFO: level: 15
[16:34:35.559] INFO: triggerdelay: 0
[16:34:35.559] QUIET: Instanciating API for pxar v2.2.5+67~g3b1c276
[16:34:35.559] INFO: Log level: DEBUG
[16:34:35.569] INFO: Found DTB DTB_WV86BD
[16:34:35.579] QUIET: Connection to board DTB_WV86BD opened.
[16:34:35.583] 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:
------------------------------------------------------
[16:34:35.586] INFO: RPC call hashes of host and DTB match: 447413373
[16:34:37.112] INFO: DUT info:
[16:34:37.112] INFO: The DUT currently contains the following objects:
[16:34:37.112] INFO: 2 TBM Cores tbm08c (2 ON)
[16:34:37.112] INFO: TBM Core alpha (0): 7 registers set
[16:34:37.112] INFO: TBM Core beta (1): 7 registers set
[16:34:37.112] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[16:34:37.112] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[16:34:37.112] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[16:34:37.112] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[16:34:37.112] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[16:34:37.112] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[16:34:37.112] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[16:34:37.112] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[16:34:37.112] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[16:34:37.112] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[16:34:37.112] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[16:34:37.112] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[16:34:37.112] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[16:34:37.112] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[16:34:37.112] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[16:34:37.112] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[16:34:37.112] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[16:34:37.112] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->BB<-
[16:34:37.112] DEBUG: <PixTestParameters.cc/dump:L107> dumpall: checkbox(0)
[16:34:37.112] DEBUG: <PixTestParameters.cc/dump:L107> dumpproblematic: checkbox(0)
[16:34:37.112] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 5
[16:34:37.112] DEBUG: <PixTestParameters.cc/dump:L107> vcals: 250
[16:34:37.112] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->BB2<-
[16:34:37.112] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> vcals: 222
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> plwidth: 35
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> pix: 11,20
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> targetia: 24
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->BB3<-
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> dumpall: checkbox(0)
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> dumpproblematic: checkbox(0)
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 5
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> vcals: 250
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Cmd<-
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->DacDacScan<-
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> phmap: checkbox
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> dac1: caldel
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> dac1lo: 0
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> dac1hi: 255
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> dac2: vthrcomp
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> dac2lo: 0
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> dac2hi: 255
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> pix: 11,20
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->DacScan<-
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> phmap: checkbox(1)
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> allpixels: checkbox(0)
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> unmasked: checkbox(0)
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> dac: vcal
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> daclo: 0
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> dachi: 255
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> pix: 11,20
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->GainPedestal<-
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> showfits: checkbox(0)
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> extended: checkbox(0)
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> dumphists: checkbox(0)
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> vcalstep: 10
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> measure: button
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> fit: button
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> save: button
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->HighRate<-
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> pix: 11,20
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> maskhotpixels: button
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> savemaskfile: checkbox(0)
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> maskfilename: default
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> caldelscan: button
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> xpixelalive: button
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 50
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> vcal: 200
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> xnoisemaps: button
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> daclo: 0
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> dachi: 100
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> dacs/step: 20
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> rundaq: button
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> trgfrequency(khz): 20
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> runseconds: 2
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> triggerdelay: 20
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> delaytbm: checkbox
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> filltree: checkbox
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->IV<-
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> port: /dev/FIXME
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> voltagestart: 0
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> voltagestop: 600
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> voltagestep: 5
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> delay: 1
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> compliance(ua): 100
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->PhOptimization<-
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> safetymarginlow: 20
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> saturationvcal: 100
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> quantilesaturation: 0.98
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->PixelAlive<-
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> vcal: 200
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> alivetest: button
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> masktest: button
[16:34:37.113] DEBUG: <PixTestParameters.cc/dump:L107> addressdecodingtest: button
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Pretest<-
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L107> programroc: button
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L107> targetia: 24
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L107> setvana: button
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L107> iterations: 100
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L107> settimings: button
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L107> findworkingpixel: button
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L107> setvthrcompcaldel: button
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L107> pix: 11,20
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L107> vcal: 250
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L107> deltavthrcomp: 50
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L107> fraccaldel: 0.5
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 5
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L107> savedacs: button
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Readback<-
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L107> calibratevd: button
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L107> calibrateva: button
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L107> calibrateia: button
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L107> readbackvbg: button
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L107> getcalibratedvbg: button
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L107> usecalvd: checkbox(1)
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L107> usecalva: checkbox(0)
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L107> setvana: button
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Scurves<-
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L107> adjustvcal: checkbox(1)
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L107> dumpall: checkbox(0)
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L107> dumpproblematic: checkbox(0)
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L107> dumpoutputfile: checkbox(0)
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 50
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L107> dac: VthrComp
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L107> daclo: 0
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L107> dachi: 200
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L107> dacs/step: 10
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L107> scurves: button
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Timing<-
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L107> fastscan: checkbox(0)
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L107> targetclk: 4
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L107> clocksdascan: button
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L107> phasescan: button
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L107> levelscan: button
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L107> tbmphasescan: button
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L107> rocdelayscan: button
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L107> timingtest: button
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L107> saveparameters: button
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Trim<-
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L107> trim: button
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L107> vcal: 35
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L107> trimbits: button
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Xray<-
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L107> maskhotpixels: button
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L107> savemaskfile: checkbox(0)
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L107> maskfilename: default
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L107> source: Ag
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L107> phrun: button
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L107> runseconds: 100
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L107> trgfrequency(khz): 100
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L107> ratescan: button
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L107> vthrcompmin: 10
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L107> vthrcompmax: 80
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L107> stepseconds: 5
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L107> delaytbm: checkbox
[16:34:37.114] DEBUG: <PixTestParameters.cc/dump:L107> filltree: checkbox
[16:34:37.115] DEBUG: <PixSetup.cc/init:L81> PixSetup init start; getCurrentRSS() = 32542720
[16:34:37.115] DEBUG: <PixSetup.cc/init:L87> fPixTestParameters = 0x1c2a810
[16:34:37.115] DEBUG: <PixSetup.cc/init:L88> fConfigParameters = 0x1b539c0
[16:34:37.115] DEBUG: <PixSetup.cc/init:L89> fPxarMemory = 0x7fa5edd94010
[16:34:37.115] DEBUG: <PixSetup.cc/init:L90> fPxarMemHi = 0x7fa5f3fff510
[16:34:37.115] DEBUG: <PixSetup.cc/init:L106> PixSetup init done; getCurrentRSS() = 32604160 fPxarMemory = 0x7fa5edd94010
[16:34:37.115] DEBUG: <PixTestFactory.cc/PixTestFactory:L52> PixTestFactory::PixTestFactory()
[16:34:37.517] INFO: enter 'restricted' command line mode
[16:34:37.517] INFO: enter test to run
[16:34:37.517] INFO: test: Pretest no parameter change
[16:34:37.517] INFO: running: pretest
[16:34:37.524] INFO: ######################################################################
[16:34:37.524] INFO: PixTestPretest::doTest()
[16:34:37.524] INFO: ######################################################################
[16:34:37.526] INFO: ----------------------------------------------------------------------
[16:34:37.526] INFO: PixTestPretest::programROC()
[16:34:37.526] INFO: ----------------------------------------------------------------------
[16:34:55.548] INFO: PixTestPretest::programROC() done: ROCs are all programmable
[16:34:55.548] INFO: IA differences per ROC: 18.5 17.7 19.3 18.5 17.7 18.5 17.7 16.9 16.1 19.3 19.3 17.7 17.7 20.9 18.5 19.3
[16:34:55.633] INFO: ----------------------------------------------------------------------
[16:34:55.633] INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[16:34:55.633] INFO: ----------------------------------------------------------------------
[16:34:55.737] DEBUG: <PixTestPretest.cc/setVana:L254> offset current from other 15 ROCs is 67.7812 mA
[16:34:55.838] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 0 iter 0 Vana 78 Ia 23.0188 mA
[16:34:55.939] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 1 Vana 84 Ia 24.6187 mA
[16:34:56.039] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 2 Vana 81 Ia 23.8187 mA
[16:34:56.141] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 3 Vana 82 Ia 23.8187 mA
[16:34:56.241] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 4 Vana 83 Ia 23.8187 mA
[16:34:56.342] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 5 Vana 84 Ia 24.6187 mA
[16:34:56.443] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 6 Vana 81 Ia 23.8187 mA
[16:34:56.544] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 7 Vana 82 Ia 23.8187 mA
[16:34:56.645] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 8 Vana 83 Ia 23.8187 mA
[16:34:56.745] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 9 Vana 84 Ia 24.6187 mA
[16:34:56.846] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 10 Vana 81 Ia 23.8187 mA
[16:34:56.947] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 0 iter 11 Vana 82 Ia 23.8187 mA
[16:34:57.049] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 1 iter 0 Vana 78 Ia 23.0188 mA
[16:34:57.149] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 1 Vana 84 Ia 24.6187 mA
[16:34:57.250] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 2 Vana 81 Ia 23.8187 mA
[16:34:57.351] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 3 Vana 82 Ia 23.8187 mA
[16:34:57.451] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 4 Vana 83 Ia 24.6187 mA
[16:34:57.552] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 5 Vana 80 Ia 23.8187 mA
[16:34:57.653] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 6 Vana 81 Ia 23.8187 mA
[16:34:57.754] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 7 Vana 82 Ia 23.8187 mA
[16:34:57.855] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 8 Vana 83 Ia 24.6187 mA
[16:34:57.956] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 9 Vana 80 Ia 23.8187 mA
[16:34:58.057] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 10 Vana 81 Ia 23.8187 mA
[16:34:58.158] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 1 iter 11 Vana 82 Ia 24.6187 mA
[16:34:58.260] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 2 iter 0 Vana 78 Ia 23.8187 mA
[16:34:58.361] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 2 iter 1 Vana 79 Ia 24.6187 mA
[16:34:58.462] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 2 iter 2 Vana 76 Ia 23.8187 mA
[16:34:58.563] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 2 iter 3 Vana 77 Ia 23.8187 mA
[16:34:58.664] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 2 iter 4 Vana 78 Ia 23.8187 mA
[16:34:58.765] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 2 iter 5 Vana 79 Ia 23.8187 mA
[16:34:58.868] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 2 iter 6 Vana 80 Ia 24.6187 mA
[16:34:58.969] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 2 iter 7 Vana 77 Ia 23.8187 mA
[16:34:59.070] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 2 iter 8 Vana 78 Ia 23.8187 mA
[16:34:59.171] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 2 iter 9 Vana 79 Ia 23.8187 mA
[16:34:59.272] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 2 iter 10 Vana 80 Ia 24.6187 mA
[16:34:59.376] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 2 iter 11 Vana 77 Ia 23.8187 mA
[16:34:59.477] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 3 iter 0 Vana 78 Ia 23.0188 mA
[16:34:59.578] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 1 Vana 84 Ia 24.6187 mA
[16:34:59.681] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 2 Vana 81 Ia 23.8187 mA
[16:34:59.782] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 3 Vana 82 Ia 23.8187 mA
[16:34:59.883] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 4 Vana 83 Ia 24.6187 mA
[16:34:59.983] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 5 Vana 80 Ia 23.8187 mA
[16:35:00.084] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 6 Vana 81 Ia 23.8187 mA
[16:35:00.185] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 7 Vana 82 Ia 23.8187 mA
[16:35:00.287] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 8 Vana 83 Ia 24.6187 mA
[16:35:00.387] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 9 Vana 80 Ia 23.8187 mA
[16:35:00.488] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 10 Vana 81 Ia 23.8187 mA
[16:35:00.589] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 3 iter 11 Vana 82 Ia 23.8187 mA
[16:35:00.691] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 4 iter 0 Vana 78 Ia 22.2188 mA
[16:35:00.792] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 4 iter 1 Vana 89 Ia 24.6187 mA
[16:35:00.893] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 4 iter 2 Vana 86 Ia 24.6187 mA
[16:35:00.994] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 4 iter 3 Vana 83 Ia 23.8187 mA
[16:35:01.095] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 4 iter 4 Vana 84 Ia 23.8187 mA
[16:35:01.197] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 4 iter 5 Vana 85 Ia 24.6187 mA
[16:35:01.297] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 4 iter 6 Vana 82 Ia 23.8187 mA
[16:35:01.398] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 4 iter 7 Vana 83 Ia 23.8187 mA
[16:35:01.499] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 4 iter 8 Vana 84 Ia 23.8187 mA
[16:35:01.600] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 4 iter 9 Vana 85 Ia 24.6187 mA
[16:35:01.701] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 4 iter 10 Vana 82 Ia 23.8187 mA
[16:35:01.802] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 4 iter 11 Vana 83 Ia 23.8187 mA
[16:35:01.907] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 5 iter 0 Vana 78 Ia 23.0188 mA
[16:35:02.007] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 1 Vana 84 Ia 24.6187 mA
[16:35:02.110] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 2 Vana 81 Ia 23.8187 mA
[16:35:02.211] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 3 Vana 82 Ia 24.6187 mA
[16:35:02.312] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 4 Vana 79 Ia 23.8187 mA
[16:35:02.413] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 5 Vana 80 Ia 23.8187 mA
[16:35:02.513] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 6 Vana 81 Ia 23.8187 mA
[16:35:02.616] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 7 Vana 82 Ia 24.6187 mA
[16:35:02.716] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 8 Vana 79 Ia 23.8187 mA
[16:35:02.817] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 9 Vana 80 Ia 23.8187 mA
[16:35:02.919] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 10 Vana 81 Ia 24.6187 mA
[16:35:03.020] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 5 iter 11 Vana 78 Ia 23.8187 mA
[16:35:03.122] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 6 iter 0 Vana 78 Ia 23.0188 mA
[16:35:03.223] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 1 Vana 84 Ia 24.6187 mA
[16:35:03.324] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 2 Vana 81 Ia 23.8187 mA
[16:35:03.424] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 3 Vana 82 Ia 23.8187 mA
[16:35:03.526] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 4 Vana 83 Ia 24.6187 mA
[16:35:03.627] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 5 Vana 80 Ia 23.8187 mA
[16:35:03.729] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 6 Vana 81 Ia 23.8187 mA
[16:35:03.830] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 7 Vana 82 Ia 23.8187 mA
[16:35:03.931] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 8 Vana 83 Ia 23.8187 mA
[16:35:04.033] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 9 Vana 84 Ia 24.6187 mA
[16:35:04.133] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 10 Vana 81 Ia 23.8187 mA
[16:35:04.235] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 6 iter 11 Vana 82 Ia 23.8187 mA
[16:35:04.336] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 7 iter 0 Vana 78 Ia 21.4188 mA
[16:35:04.437] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 7 iter 1 Vana 94 Ia 25.4188 mA
[16:35:04.538] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 7 iter 2 Vana 87 Ia 23.8187 mA
[16:35:04.638] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 7 iter 3 Vana 88 Ia 23.8187 mA
[16:35:04.740] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 7 iter 4 Vana 89 Ia 23.8187 mA
[16:35:04.840] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 7 iter 5 Vana 90 Ia 23.8187 mA
[16:35:04.941] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 7 iter 6 Vana 91 Ia 24.6187 mA
[16:35:05.042] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 7 iter 7 Vana 88 Ia 23.8187 mA
[16:35:05.142] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 7 iter 8 Vana 89 Ia 23.8187 mA
[16:35:05.243] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 7 iter 9 Vana 90 Ia 23.8187 mA
[16:35:05.344] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 7 iter 10 Vana 91 Ia 24.6187 mA
[16:35:05.445] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 7 iter 11 Vana 88 Ia 23.8187 mA
[16:35:05.547] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 8 iter 0 Vana 78 Ia 21.4188 mA
[16:35:05.648] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 8 iter 1 Vana 94 Ia 23.8187 mA
[16:35:05.749] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 8 iter 2 Vana 95 Ia 24.6187 mA
[16:35:05.850] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 8 iter 3 Vana 92 Ia 23.8187 mA
[16:35:05.951] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 8 iter 4 Vana 93 Ia 23.8187 mA
[16:35:06.053] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 8 iter 5 Vana 94 Ia 24.6187 mA
[16:35:06.153] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 8 iter 6 Vana 91 Ia 23.8187 mA
[16:35:06.255] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 8 iter 7 Vana 92 Ia 23.8187 mA
[16:35:06.356] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 8 iter 8 Vana 93 Ia 23.8187 mA
[16:35:06.457] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 8 iter 9 Vana 94 Ia 23.8187 mA
[16:35:06.558] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 8 iter 10 Vana 95 Ia 24.6187 mA
[16:35:06.659] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 8 iter 11 Vana 92 Ia 23.8187 mA
[16:35:06.761] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 9 iter 0 Vana 78 Ia 23.8187 mA
[16:35:06.862] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 9 iter 1 Vana 79 Ia 23.8187 mA
[16:35:06.963] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 9 iter 2 Vana 80 Ia 23.8187 mA
[16:35:07.064] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 9 iter 3 Vana 81 Ia 24.6187 mA
[16:35:07.165] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 9 iter 4 Vana 78 Ia 23.8187 mA
[16:35:07.266] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 9 iter 5 Vana 79 Ia 23.8187 mA
[16:35:07.367] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 9 iter 6 Vana 80 Ia 23.8187 mA
[16:35:07.468] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 9 iter 7 Vana 81 Ia 24.6187 mA
[16:35:07.569] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 9 iter 8 Vana 78 Ia 23.8187 mA
[16:35:07.671] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 9 iter 9 Vana 79 Ia 23.8187 mA
[16:35:07.772] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 9 iter 10 Vana 80 Ia 24.6187 mA
[16:35:07.873] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 9 iter 11 Vana 77 Ia 23.8187 mA
[16:35:07.975] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 10 iter 0 Vana 78 Ia 23.8187 mA
[16:35:08.076] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 1 Vana 79 Ia 23.8187 mA
[16:35:08.177] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 2 Vana 80 Ia 23.8187 mA
[16:35:08.278] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 3 Vana 81 Ia 24.6187 mA
[16:35:08.379] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 4 Vana 78 Ia 23.8187 mA
[16:35:08.480] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 5 Vana 79 Ia 23.8187 mA
[16:35:08.581] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 6 Vana 80 Ia 23.8187 mA
[16:35:08.683] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 7 Vana 81 Ia 24.6187 mA
[16:35:08.783] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 8 Vana 78 Ia 23.8187 mA
[16:35:08.884] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 9 Vana 79 Ia 23.8187 mA
[16:35:08.985] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 10 Vana 80 Ia 24.6187 mA
[16:35:09.087] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter 11 Vana 77 Ia 23.8187 mA
[16:35:09.189] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 11 iter 0 Vana 78 Ia 23.0188 mA
[16:35:09.290] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter 1 Vana 84 Ia 23.8187 mA
[16:35:09.391] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter 2 Vana 85 Ia 24.6187 mA
[16:35:09.491] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter 3 Vana 82 Ia 23.8187 mA
[16:35:09.592] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter 4 Vana 83 Ia 23.8187 mA
[16:35:09.694] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter 5 Vana 84 Ia 23.8187 mA
[16:35:09.795] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter 6 Vana 85 Ia 23.8187 mA
[16:35:09.897] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter 7 Vana 86 Ia 24.6187 mA
[16:35:09.998] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter 8 Vana 83 Ia 23.8187 mA
[16:35:10.098] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter 9 Vana 84 Ia 23.8187 mA
[16:35:10.199] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter 10 Vana 85 Ia 23.8187 mA
[16:35:10.300] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter 11 Vana 86 Ia 24.6187 mA
[16:35:10.402] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 12 iter 0 Vana 78 Ia 22.2188 mA
[16:35:10.503] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter 1 Vana 89 Ia 24.6187 mA
[16:35:10.605] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter 2 Vana 86 Ia 24.6187 mA
[16:35:10.705] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter 3 Vana 83 Ia 23.8187 mA
[16:35:10.807] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter 4 Vana 84 Ia 23.8187 mA
[16:35:10.908] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter 5 Vana 85 Ia 23.8187 mA
[16:35:11.009] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter 6 Vana 86 Ia 24.6187 mA
[16:35:11.110] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter 7 Vana 83 Ia 23.8187 mA
[16:35:11.211] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter 8 Vana 84 Ia 23.8187 mA
[16:35:11.312] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter 9 Vana 85 Ia 24.6187 mA
[16:35:11.413] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter 10 Vana 82 Ia 23.8187 mA
[16:35:11.513] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter 11 Vana 83 Ia 23.8187 mA
[16:35:11.615] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 13 iter 0 Vana 78 Ia 25.4188 mA
[16:35:11.715] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 1 Vana 71 Ia 23.8187 mA
[16:35:11.816] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 2 Vana 72 Ia 23.8187 mA
[16:35:11.917] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 3 Vana 73 Ia 23.8187 mA
[16:35:12.017] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 4 Vana 74 Ia 24.6187 mA
[16:35:12.118] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 5 Vana 71 Ia 23.8187 mA
[16:35:12.219] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 6 Vana 72 Ia 23.8187 mA
[16:35:12.320] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 7 Vana 73 Ia 23.8187 mA
[16:35:12.420] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 8 Vana 74 Ia 23.8187 mA
[16:35:12.521] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 9 Vana 75 Ia 23.8187 mA
[16:35:12.622] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 10 Vana 76 Ia 24.6187 mA
[16:35:12.723] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter 11 Vana 73 Ia 23.8187 mA
[16:35:12.825] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 14 iter 0 Vana 78 Ia 23.8187 mA
[16:35:12.925] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 1 Vana 79 Ia 23.8187 mA
[16:35:13.027] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 2 Vana 80 Ia 23.8187 mA
[16:35:13.128] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 3 Vana 81 Ia 24.6187 mA
[16:35:13.229] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 4 Vana 78 Ia 23.8187 mA
[16:35:13.330] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 5 Vana 79 Ia 23.8187 mA
[16:35:13.430] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 6 Vana 80 Ia 23.8187 mA
[16:35:13.531] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 7 Vana 81 Ia 24.6187 mA
[16:35:13.632] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 8 Vana 78 Ia 23.8187 mA
[16:35:13.733] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 9 Vana 79 Ia 23.8187 mA
[16:35:13.834] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 10 Vana 80 Ia 23.8187 mA
[16:35:13.934] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter 11 Vana 81 Ia 23.8187 mA
[16:35:14.036] DEBUG: <PixTestPretest.cc/setVana:L280> ROC 15 iter 0 Vana 78 Ia 23.8187 mA
[16:35:14.137] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 1 Vana 79 Ia 23.8187 mA
[16:35:14.238] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 2 Vana 80 Ia 24.6187 mA
[16:35:14.339] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 3 Vana 77 Ia 23.8187 mA
[16:35:14.440] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 4 Vana 78 Ia 23.8187 mA
[16:35:14.541] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 5 Vana 79 Ia 23.8187 mA
[16:35:14.642] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 6 Vana 80 Ia 25.4188 mA
[16:35:14.742] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 7 Vana 73 Ia 23.0188 mA
[16:35:14.843] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 8 Vana 79 Ia 24.6187 mA
[16:35:14.944] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 9 Vana 76 Ia 23.8187 mA
[16:35:15.044] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 10 Vana 77 Ia 23.8187 mA
[16:35:15.148] DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter 11 Vana 78 Ia 23.8187 mA
[16:35:15.197] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 0 Vana 82
[16:35:15.197] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 1 Vana 82
[16:35:15.198] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 2 Vana 77
[16:35:15.198] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 3 Vana 82
[16:35:15.198] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 4 Vana 83
[16:35:15.198] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 5 Vana 78
[16:35:15.202] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 6 Vana 82
[16:35:15.202] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 7 Vana 88
[16:35:15.203] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 8 Vana 92
[16:35:15.203] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 9 Vana 77
[16:35:15.203] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 10 Vana 77
[16:35:15.203] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 11 Vana 86
[16:35:15.204] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 12 Vana 83
[16:35:15.204] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 13 Vana 73
[16:35:15.204] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 14 Vana 81
[16:35:15.204] DEBUG: <PixTestPretest.cc/setVana:L343> ROC 15 Vana 78
[16:35:15.307] INFO: PixTestPretest::setVana() done, Module Ia 379.4 mA = 23.7125 mA/ROC
[16:35:15.309] INFO: ----------------------------------------------------------------------
[16:35:15.309] INFO: PixTestPreTest::setTimings()
[16:35:15.309] INFO: ----------------------------------------------------------------------
[16:35:15.309] DEBUG: <PixTestPretest.cc/setTimings:L392> Testing Timing: Attempt #1
[16:35:16.277] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:35:16.277] INFO: Decoding statistics:
[16:35:16.277] INFO: General information:
[16:35:16.277] INFO: 16bit words read: 120
[16:35:16.277] INFO: valid events total: 10
[16:35:16.277] INFO: empty events: 10
[16:35:16.277] INFO: valid events with pixels: 0
[16:35:16.277] INFO: valid pixel hits: 0
[16:35:16.277] INFO: Event errors: 0
[16:35:16.278] INFO: start marker: 0
[16:35:16.278] INFO: stop marker: 0
[16:35:16.278] INFO: overflow: 0
[16:35:16.278] INFO: invalid 5bit words: 0
[16:35:16.278] INFO: invalid XOR eye diagram: 0
[16:35:16.278] INFO: TBM errors: 0
[16:35:16.278] INFO: flawed TBM headers: 0
[16:35:16.278] INFO: flawed TBM trailers: 0
[16:35:16.278] INFO: event ID mismatches: 0
[16:35:16.278] INFO: ROC errors: 0
[16:35:16.278] INFO: missing ROC header(s): 0
[16:35:16.278] INFO: misplaced readback start: 0
[16:35:16.278] INFO: Pixel decoding errors: 0
[16:35:16.278] INFO: pixel data incomplete: 0
[16:35:16.278] INFO: pixel address: 0
[16:35:16.278] INFO: pulse height fill bit: 0
[16:35:16.278] INFO: buffer corruption: 0
[16:35:16.278] INFO: ----------------------------------------------------------------------
[16:35:16.278] INFO: Default timings are good. No timing scan needed.
[16:35:16.278] INFO: ----------------------------------------------------------------------
[16:35:16.278] INFO: Test took 969 ms.
[16:35:16.278] INFO: PixTestPretest::setTimings() done.
[16:35:16.470] INFO: ----------------------------------------------------------------------
[16:35:16.470] INFO: PixTestPretest::findWorkingPixel()
[16:35:16.470] INFO: ----------------------------------------------------------------------
[16:35:23.775] INFO: Test took 7303ms.
[16:35:24.010] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C0 OK, with vthrComp = 104 and Delta(CalDel) = 62
[16:35:24.015] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C1 OK, with vthrComp = 94 and Delta(CalDel) = 62
[16:35:24.018] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C2 OK, with vthrComp = 87 and Delta(CalDel) = 59
[16:35:24.020] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C3 OK, with vthrComp = 94 and Delta(CalDel) = 60
[16:35:24.023] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C4 OK, with vthrComp = 63 and Delta(CalDel) = 61
[16:35:24.026] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C5 OK, with vthrComp = 99 and Delta(CalDel) = 63
[16:35:24.028] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C6 OK, with vthrComp = 103 and Delta(CalDel) = 60
[16:35:24.031] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C7 OK, with vthrComp = 72 and Delta(CalDel) = 58
[16:35:24.034] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C8 OK, with vthrComp = 100 and Delta(CalDel) = 63
[16:35:24.036] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C9 OK, with vthrComp = 85 and Delta(CalDel) = 57
[16:35:24.039] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C10 OK, with vthrComp = 96 and Delta(CalDel) = 60
[16:35:24.042] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C11 OK, with vthrComp = 99 and Delta(CalDel) = 60
[16:35:24.044] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C12 OK, with vthrComp = 99 and Delta(CalDel) = 61
[16:35:24.047] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C13 OK, with vthrComp = 100 and Delta(CalDel) = 57
[16:35:24.051] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C14 OK, with vthrComp = 84 and Delta(CalDel) = 63
[16:35:24.053] DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C15 OK, with vthrComp = 99 and Delta(CalDel) = 60
[16:35:24.079] INFO: Found working pixel in all ROCs: col/row = 12/22
[16:35:24.127] INFO: ----------------------------------------------------------------------
[16:35:24.127] INFO: PixTestPretest::setVthrCompCalDel()
[16:35:24.127] INFO: ----------------------------------------------------------------------
[16:35:31.512] INFO: Test took 7378ms.
[16:35:31.566] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 126 +/- 31.5
[16:35:31.741] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 134 +/- 31
[16:35:31.746] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 119 +/- 29
[16:35:31.749] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 126 +/- 30
[16:35:31.752] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 139 +/- 30.5
[16:35:31.754] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 125 +/- 31
[16:35:31.757] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 114 +/- 29.5
[16:35:31.759] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 124 +/- 29.5
[16:35:31.762] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 124 +/- 31.5
[16:35:31.766] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 114 +/- 30
[16:35:31.768] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 115 +/- 29.5
[16:35:31.771] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 119 +/- 29.5
[16:35:31.773] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 129 +/- 30.5
[16:35:31.776] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 125 +/- 28.5
[16:35:31.779] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 138 +/- 31.5
[16:35:31.782] DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 123 +/- 30
[16:35:31.833] INFO: PixTestPretest::setVthrCompCalDel() done
[16:35:31.833] INFO: CalDel: 126 134 119 126 139 125 114 124 124 114 115 119 129 125 138 123
[16:35:31.833] INFO: VthrComp: 52 51 51 51 51 54 53 51 53 51 51 52 51 51 51 51
[16:35:31.836] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//dacParameters_C0.dat
[16:35:31.837] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//dacParameters_C1.dat
[16:35:31.837] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//dacParameters_C2.dat
[16:35:31.837] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//dacParameters_C3.dat
[16:35:31.837] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//dacParameters_C4.dat
[16:35:31.837] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//dacParameters_C5.dat
[16:35:31.837] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//dacParameters_C6.dat
[16:35:31.837] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//dacParameters_C7.dat
[16:35:31.838] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//dacParameters_C8.dat
[16:35:31.838] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//dacParameters_C9.dat
[16:35:31.838] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//dacParameters_C10.dat
[16:35:31.838] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//dacParameters_C11.dat
[16:35:31.838] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//dacParameters_C12.dat
[16:35:31.838] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//dacParameters_C13.dat
[16:35:31.838] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//dacParameters_C14.dat
[16:35:31.838] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//dacParameters_C15.dat
[16:35:31.838] INFO: PixTestPretest::doTest() done, duration: 54 seconds
[16:35:31.839] DEBUG: <PixTestPretest.cc/~PixTestPretest:L134> PixTestPretest dtor
[16:35:31.915] INFO: enter test to run
[16:35:31.915] INFO: test: Fulltest no parameter change
[16:35:31.915] INFO: running: fulltest
[16:35:31.915] DEBUG: <PixTestFullTest.cc/init:L49> PixTestFullTest::init()
[16:35:31.915] DEBUG: <PixTestFullTest.cc/PixTestFullTest:L20> PixTestFullTest ctor(PixSetup &a, string, TGTab *)
[16:35:31.915] INFO: ######################################################################
[16:35:31.915] INFO: PixTestFullTest::doTest()
[16:35:31.915] INFO: ######################################################################
[16:35:31.915] DEBUG: <PixTestAlive.cc/init:L77> PixTestAlive::init()
[16:35:31.915] DEBUG: <PixTestAlive.cc/PixTestAlive:L21> PixTestAlive ctor(PixSetup &a, string, TGTab *)
[16:35:31.927] INFO: ######################################################################
[16:35:31.928] INFO: PixTestAlive::doTest()
[16:35:31.928] INFO: ######################################################################
[16:35:31.929] INFO: ----------------------------------------------------------------------
[16:35:31.929] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[16:35:31.929] INFO: ----------------------------------------------------------------------
[16:35:31.932] DEBUG: <PixTest.cc/efficiencyMaps:L328> attempt #0
[16:35:35.667] INFO: Test took 3735ms.
[16:35:35.691] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:35:35.691] DEBUG: <PixTest.cc/efficiencyMaps:L339> eff result size = 66556
[16:35:35.691] DEBUG: <PixTest.cc/efficiencyMaps:L344> Create hists PixelAlive_C0 .. PixelAlive_C15
[16:35:35.931] INFO: PixTestAlive::aliveTest() done
[16:35:35.931] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 1 0 0 0 0 1 0 0 0 2
[16:35:35.931] 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
[16:35:35.934] INFO: ----------------------------------------------------------------------
[16:35:35.934] INFO: PixTestAlive::maskTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[16:35:35.934] INFO: ----------------------------------------------------------------------
[16:35:35.937] DEBUG: <PixTest.cc/efficiencyMaps:L328> attempt #0
[16:35:38.620] INFO: Test took 2683ms.
[16:35:38.621] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:35:38.621] DEBUG: <PixTest.cc/efficiencyMaps:L339> eff result size = 0
[16:35:38.621] DEBUG: <PixTest.cc/efficiencyMaps:L344> Create hists MaskTest_C0 .. MaskTest_C15
[16:35:38.622] INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[16:35:38.863] INFO: PixTestAlive::maskTest() done
[16:35:38.863] INFO: number of mask-defect pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[16:35:38.868] INFO: ----------------------------------------------------------------------
[16:35:38.868] INFO: PixTestAlive::addressDecodingTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[16:35:38.868] INFO: ----------------------------------------------------------------------
[16:35:38.870] DEBUG: <PixTest.cc/efficiencyMaps:L328> attempt #0
[16:35:42.611] INFO: Test took 3741ms.
[16:35:42.633] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:35:42.633] DEBUG: <PixTest.cc/efficiencyMaps:L339> eff result size = 66556
[16:35:42.633] DEBUG: <PixTest.cc/efficiencyMaps:L344> Create hists AddressDecodingTest_C0 .. AddressDecodingTest_C15
[16:35:42.876] INFO: PixTestAlive::addressDecodingTest() done
[16:35:42.876] INFO: number of address-decoding pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[16:35:42.876] INFO: PixTestAlive::doTest() done, duration: 10 seconds
[16:35:42.876] DEBUG: <PixTestAlive.cc/~PixTestAlive:L109> PixTestAlive dtor
[16:35:42.881] DEBUG: <PixTestBBMap.cc/init:L79> PixTestBBMap::init()
[16:35:42.881] DEBUG: <PixTestBBMap.cc/PixTestBBMap:L27> PixTestBBMap ctor(PixSetup &a, string, TGTab *)
[16:35:42.882] INFO: ######################################################################
[16:35:42.882] INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[16:35:42.882] INFO: ######################################################################
[16:35:42.887] INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (30) hits flags = 2 (plus default)
[16:35:42.901] INFO: dacScan step from 0 .. 29
[16:35:42.901] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[16:36:00.859] INFO: Test took 17958ms.
[16:36:00.895] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:36:00.895] INFO: dacScan step from 30 .. 59
[16:36:00.895] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[16:36:19.607] INFO: Test took 18712ms.
[16:36:19.702] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:36:19.717] INFO: dacScan step from 60 .. 89
[16:36:19.717] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[16:36:43.819] INFO: Test took 24102ms.
[16:36:44.086] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:36:44.181] INFO: dacScan step from 90 .. 119
[16:36:44.181] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[16:37:08.000] INFO: Test took 24819ms.
[16:37:09.269] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:37:09.362] INFO: dacScan step from 120 .. 149
[16:37:09.363] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[16:37:32.032] INFO: Test took 22669ms.
[16:37:32.238] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:37:32.283] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[16:37:33.572] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[16:37:34.864] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[16:37:36.125] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[16:37:37.456] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[16:37:38.631] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[16:37:39.899] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[16:37:41.122] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[16:37:42.311] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[16:37:43.575] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[16:37:44.801] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[16:37:46.033] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[16:37:47.301] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[16:37:48.576] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[16:37:49.849] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[16:37:51.119] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[16:37:52.926] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 258605056
[16:37:52.996] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C0_V0
[16:37:52.998] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 96 (obtained for minval = 0) start: 96 .. 115 last peak: 61.0456 last sigma: 5.46729 lcuts[0] = 77.4474 lcuts[1] = 115.718
[16:37:52.001] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C1_V0
[16:37:52.002] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 101 (obtained for minval = 0) start: 101 .. 122 last peak: 62.6215 last sigma: 5.95025 lcuts[0] = 80.4722 lcuts[1] = 122.124
[16:37:53.002] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C2_V0
[16:37:53.003] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 93 (obtained for minval = 0) start: 93 .. 112 last peak: 59.2742 last sigma: 5.33074 lcuts[0] = 75.2665 lcuts[1] = 112.582
[16:37:53.004] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C3_V0
[16:37:53.004] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 92 (obtained for minval = 0) start: 92 .. 111 last peak: 56.8864 last sigma: 5.47777 lcuts[0] = 73.3197 lcuts[1] = 111.664
[16:37:53.005] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C4_V0
[16:37:53.006] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 74 (obtained for minval = 0) start: 74 .. 88 last peak: 47.4003 last sigma: 4.12343 lcuts[0] = 59.7706 lcuts[1] = 88.6346
[16:37:53.007] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C5_V0
[16:37:53.007] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 103 (obtained for minval = 0) start: 103 .. 124 last peak: 64.8824 last sigma: 5.93475 lcuts[0] = 82.6866 lcuts[1] = 124.23
[16:37:53.008] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C6_V0
[16:37:53.009] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 93 (obtained for minval = 0) start: 93 .. 112 last peak: 56.8716 last sigma: 5.60599 lcuts[0] = 73.6896 lcuts[1] = 112.931
[16:37:53.009] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C7_V0
[16:37:53.010] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 84 (obtained for minval = 0) start: 84 .. 100 last peak: 53.5655 last sigma: 4.73517 lcuts[0] = 67.771 lcuts[1] = 100.917
[16:37:53.011] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C8_V0
[16:37:53.012] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 99 (obtained for minval = 0) start: 99 .. 120 last peak: 58.8074 last sigma: 6.18701 lcuts[0] = 77.3684 lcuts[1] = 120.677
[16:37:53.012] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C9_V0
[16:37:53.013] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 95 (obtained for minval = 0) start: 95 .. 115 last peak: 58.5817 last sigma: 5.73937 lcuts[0] = 75.7998 lcuts[1] = 115.975
[16:37:53.014] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C10_V0
[16:37:53.014] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 93 (obtained for minval = 0) start: 93 .. 113 last peak: 55.9434 last sigma: 5.78399 lcuts[0] = 73.2954 lcuts[1] = 113.783
[16:37:53.015] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C11_V0
[16:37:53.016] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 100 (obtained for minval = 0) start: 100 .. 121 last peak: 62.2994 last sigma: 5.89689 lcuts[0] = 79.99 lcuts[1] = 121.268
[16:37:53.016] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C12_V0
[16:37:53.017] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 105 (obtained for minval = 0) start: 105 .. 127 last peak: 65.1841 last sigma: 6.18826 lcuts[0] = 83.7489 lcuts[1] = 127.067
[16:37:53.017] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C13_V0
[16:37:53.018] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 103 (obtained for minval = 0) start: 103 .. 124 last peak: 65.7342 last sigma: 5.84402 lcuts[0] = 83.2663 lcuts[1] = 124.174
[16:37:53.019] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C14_V0
[16:37:53.019] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 103 (obtained for minval = 0) start: 103 .. 125 last peak: 63.0649 last sigma: 6.19833 lcuts[0] = 81.6599 lcuts[1] = 125.048
[16:37:53.020] DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C15_V0
[16:37:53.021] DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 99 (obtained for minval = 0) start: 94 .. 114 last peak: 57.5093 last sigma: 5.70526 lcuts[0] = 74.6251 lcuts[1] = 114.562
[16:37:53.023] INFO: PixTestBBMap::doTest() done, duration: 130 seconds
[16:37:53.023] INFO: number of dead bumps (per ROC): 2 3 1 0 1 0 2 1 2 0 1 1 0 1 3 1
[16:37:53.023] INFO: separation cut (per ROC): 97 102 94 93 75 104 94 85 100 96 94 101 106 104 104 100
[16:37:53.023] DEBUG: <PixTestBBMap.cc/~PixTestBBMap:L97> PixTestBBMap dtor
[16:37:53.159] DEBUG: <PixTestScurves.cc/setParameter:L92> set fOutputFilename =
[16:37:53.163] INFO: ######################################################################
[16:37:53.164] INFO: PixTestScurves::fullTest() ntrig = 50
[16:37:53.164] INFO: ######################################################################
[16:37:53.164] INFO: ----------------------------------------------------------------------
[16:37:53.165] INFO: PixTestScurves::scurves(Vcal), ntrig = 50
[16:37:53.165] INFO: ----------------------------------------------------------------------
[16:37:53.166] INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 0 .. 149 (10) hits flags = 16 (plus default)
[16:37:53.192] INFO: dacScan step from 0 .. 9
[16:37:53.193] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[16:38:27.811] INFO: Test took 34617ms.
[16:38:27.886] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:38:27.886] INFO: dacScan step from 10 .. 19
[16:38:27.886] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[16:39:02.580] INFO: Test took 34694ms.
[16:39:02.653] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:39:02.653] INFO: dacScan step from 20 .. 29
[16:39:02.653] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[16:39:37.318] INFO: Test took 34664ms.
[16:39:37.386] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:39:37.386] INFO: dacScan step from 30 .. 39
[16:39:37.386] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[16:40:12.074] INFO: Test took 34688ms.
[16:40:12.145] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:40:12.145] INFO: dacScan step from 40 .. 49
[16:40:12.145] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[16:40:46.777] INFO: Test took 34631ms.
[16:40:46.849] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:40:46.850] INFO: dacScan step from 50 .. 59
[16:40:46.850] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[16:41:21.503] INFO: Test took 34653ms.
[16:41:21.577] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:41:21.577] INFO: dacScan step from 60 .. 69
[16:41:21.577] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[16:41:56.371] INFO: Test took 34794ms.
[16:41:56.441] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:41:56.441] INFO: dacScan step from 70 .. 79
[16:41:56.441] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[16:42:31.195] INFO: Test took 34754ms.
[16:42:31.267] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:42:31.268] INFO: dacScan step from 80 .. 89
[16:42:31.268] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[16:43:06.512] ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 1 Number of ROCs (4) != Token Chain Length (8)
[16:43:06.512] WARNING: Channel 1 ROC 5: Readback start marker after 15 readouts!
[16:43:06.512] WARNING: Channel 1 ROC 6: Readback start marker after 15 readouts!
[16:43:06.512] WARNING: Channel 1 ROC 7: Readback start marker after 15 readouts!
[16:43:06.540] INFO: Test took 35272ms.
[16:43:06.664] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:43:06.667] INFO: dacScan step from 90 .. 99
[16:43:06.667] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[16:43:43.139] ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 1 Number of ROCs (7) != Token Chain Length (8)
[16:43:45.067] INFO: Test took 38400ms.
[16:43:45.325] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:43:45.339] INFO: dacScan step from 100 .. 109
[16:43:45.340] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[16:44:21.084] ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 1 Number of ROCs (6) != Token Chain Length (8)
[16:44:21.084] WARNING: Channel 1 ROC 7: Readback start marker after 15 readouts!
[16:44:31.962] INFO: Test took 46622ms.
[16:44:32.408] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:44:32.432] INFO: dacScan step from 110 .. 119
[16:44:32.432] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[16:45:03.847] ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 1 Number of ROCs (4) != Token Chain Length (8)
[16:45:03.847] WARNING: Channel 1 ROC 5: Readback start marker after 15 readouts!
[16:45:03.847] WARNING: Channel 1 ROC 6: Readback start marker after 15 readouts!
[16:45:03.847] WARNING: Channel 1 ROC 7: Readback start marker after 15 readouts!
[16:45:24.592] ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 1 Number of ROCs (6) != Token Chain Length (8)
[16:45:24.592] WARNING: Channel 1 ROC 7: Readback start marker after 15 readouts!
[16:45:27.248] INFO: Test took 54816ms.
[16:45:27.855] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:45:27.894] INFO: dacScan step from 120 .. 129
[16:45:27.895] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[16:45:58.670] ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 1 Number of ROCs (6) != Token Chain Length (8)
[16:45:58.671] WARNING: Channel 1 ROC 7: Readback start marker after 15 readouts!
[16:46:26.689] INFO: Test took 58794ms.
[16:46:27.297] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:46:27.334] INFO: dacScan step from 130 .. 139
[16:46:27.335] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[16:46:58.325] ERROR: <datapipe.cc/CheckEventID:L420> Channel 1 Event ID mismatch: local ID (201) != TBM ID (0)
[16:46:58.325] ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 1 Number of ROCs (7) != Token Chain Length (8)
[16:46:58.325] ERROR: <datapipe.cc/CheckEventID:L420> Channel 1 Event ID mismatch: local ID (1) != TBM ID (202)
[16:47:20.304] ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 1 Number of ROCs (6) != Token Chain Length (8)
[16:47:20.304] WARNING: Channel 1 ROC 7: Readback start marker after 15 readouts!
[16:47:25.941] INFO: Test took 58606ms.
[16:47:26.517] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:47:26.553] INFO: dacScan step from 140 .. 149
[16:47:26.553] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[16:47:56.911] ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 1 Number of ROCs (6) != Token Chain Length (8)
[16:47:56.911] WARNING: Channel 1 ROC 7: Readback start marker after 15 readouts!
[16:48:19.540] ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 1 Number of ROCs (6) != Token Chain Length (8)
[16:48:19.540] WARNING: Channel 1 ROC 7: Readback start marker after 15 readouts!
[16:48:25.484] INFO: Test took 58931ms.
[16:48:26.063] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:48:26.102] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[16:48:26.102] INFO: dumping ASCII scurve output file: SCurveData
[16:48:27.362] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[16:48:27.362] INFO: dumping ASCII scurve output file: SCurveData
[16:48:28.625] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[16:48:28.625] INFO: dumping ASCII scurve output file: SCurveData
[16:48:29.905] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[16:48:29.906] INFO: dumping ASCII scurve output file: SCurveData
[16:48:31.213] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[16:48:31.213] INFO: dumping ASCII scurve output file: SCurveData
[16:48:32.504] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[16:48:32.504] INFO: dumping ASCII scurve output file: SCurveData
[16:48:33.722] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[16:48:33.723] INFO: dumping ASCII scurve output file: SCurveData
[16:48:34.995] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[16:48:34.995] INFO: dumping ASCII scurve output file: SCurveData
[16:48:36.285] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[16:48:36.285] INFO: dumping ASCII scurve output file: SCurveData
[16:48:37.543] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[16:48:37.543] INFO: dumping ASCII scurve output file: SCurveData
[16:48:38.816] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[16:48:38.816] INFO: dumping ASCII scurve output file: SCurveData
[16:48:40.091] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[16:48:40.091] INFO: dumping ASCII scurve output file: SCurveData
[16:48:41.351] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[16:48:41.351] INFO: dumping ASCII scurve output file: SCurveData
[16:48:42.609] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[16:48:42.609] INFO: dumping ASCII scurve output file: SCurveData
[16:48:43.879] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[16:48:43.879] INFO: dumping ASCII scurve output file: SCurveData
[16:48:45.280] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[16:48:45.280] INFO: dumping ASCII scurve output file: SCurveData
[16:48:46.768] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 569327616
[16:48:46.817] INFO: PixTestScurves::scurves() done
[16:48:46.817] INFO: Vcal mean: 110.29 104.29 98.51 95.86 99.27 116.80 103.22 89.85 110.40 105.75 104.12 109.39 109.96 100.89 105.73 99.94
[16:48:46.817] INFO: Vcal RMS: 5.28 5.57 5.86 5.30 6.70 5.65 5.95 5.05 5.69 5.86 5.41 6.41 5.32 5.89 5.48 6.17
[16:48:46.817] INFO: PixTestScurves::fullTest() done, duration: 653 seconds
[16:48:46.817] DEBUG: <PixTestScurves.cc/~PixTestScurves:L141> PixTestScurves dtor
[16:48:46.881] INFO: ######################################################################
[16:48:46.881] INFO: PixTestTrim::doTest()
[16:48:46.881] INFO: ######################################################################
[16:48:46.883] INFO: ----------------------------------------------------------------------
[16:48:46.883] INFO: PixTestTrim::trimTest() ntrig = 10, vcal = 35
[16:48:46.883] INFO: ----------------------------------------------------------------------
[16:48:46.953] INFO: ---> VthrComp thr map (minimal VthrComp)
[16:48:46.953] INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 5 dacrange: 0 .. 159 (20) hits flags = 16 (plus default)
[16:48:46.968] INFO: dacScan step from 0 .. 19
[16:48:46.968] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[16:48:59.380] INFO: Test took 12412ms.
[16:48:59.405] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:48:59.405] INFO: dacScan step from 20 .. 39
[16:48:59.405] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[16:49:11.828] INFO: Test took 12423ms.
[16:49:11.853] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:49:11.853] INFO: dacScan step from 40 .. 59
[16:49:11.854] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[16:49:24.532] INFO: Test took 12678ms.
[16:49:24.560] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:49:24.560] INFO: dacScan step from 60 .. 79
[16:49:24.560] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[16:49:37.212] INFO: Test took 12652ms.
[16:49:37.240] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:49:37.240] INFO: dacScan step from 80 .. 99
[16:49:37.240] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[16:49:50.010] INFO: Test took 12770ms.
[16:49:50.049] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:49:50.053] INFO: dacScan step from 100 .. 119
[16:49:50.053] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[16:50:04.810] INFO: Test took 14757ms.
[16:50:04.957] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:50:04.990] INFO: dacScan step from 120 .. 139
[16:50:04.990] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[16:50:22.073] INFO: Test took 17083ms.
[16:50:22.231] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:50:22.270] INFO: dacScan step from 140 .. 159
[16:50:22.270] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[16:50:35.741] INFO: Test took 13471ms.
[16:50:35.805] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:50:35.820] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[16:50:37.030] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[16:50:38.189] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[16:50:39.348] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[16:50:40.522] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[16:50:41.601] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[16:50:42.794] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[16:50:43.945] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[16:50:45.056] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[16:50:46.240] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[16:50:47.395] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[16:50:48.561] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[16:50:49.748] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[16:50:50.945] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[16:50:52.141] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[16:50:53.320] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[16:50:54.504] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 569348096
[16:50:54.506] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 103.113 minThrLimit = 103.102 minThrNLimit = 124.314 -> result = 103.113 -> 103
[16:50:54.507] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 99.3288 minThrLimit = 99.2907 minThrNLimit = 116.783 -> result = 99.3288 -> 99
[16:50:54.507] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 94.72 minThrLimit = 94.7129 minThrNLimit = 113.025 -> result = 94.72 -> 94
[16:50:54.507] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 95.6584 minThrLimit = 95.6317 minThrNLimit = 115.248 -> result = 95.6584 -> 95
[16:50:54.508] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 80.6736 minThrLimit = 72.9353 minThrNLimit = 100.035 -> result = 80.6736 -> 80
[16:50:54.508] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 105.311 minThrLimit = 104.936 minThrNLimit = 124.369 -> result = 105.311 -> 105
[16:50:54.508] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 98.4803 minThrLimit = 98.4741 minThrNLimit = 115.522 -> result = 98.4803 -> 98
[16:50:54.509] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 88.1719 minThrLimit = 88.0149 minThrNLimit = 106.156 -> result = 88.1719 -> 88
[16:50:54.509] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 102.551 minThrLimit = 102.5 minThrNLimit = 121.658 -> result = 102.551 -> 102
[16:50:54.509] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 97.2921 minThrLimit = 97.245 minThrNLimit = 114.725 -> result = 97.2921 -> 97
[16:50:54.510] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 98.1218 minThrLimit = 98.1022 minThrNLimit = 115.735 -> result = 98.1218 -> 98
[16:50:54.510] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 101.201 minThrLimit = 101.182 minThrNLimit = 121.845 -> result = 101.201 -> 101
[16:50:54.510] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 102.974 minThrLimit = 102.878 minThrNLimit = 123.629 -> result = 102.974 -> 102
[16:50:54.511] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 99.4625 minThrLimit = 99.4248 minThrNLimit = 121.6 -> result = 99.4625 -> 99
[16:50:54.511] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 101.329 minThrLimit = 101.315 minThrNLimit = 121.671 -> result = 101.329 -> 101
[16:50:54.511] DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 98.2895 minThrLimit = 98.2456 minThrNLimit = 119.17 -> result = 98.2895 -> 98
[16:50:54.511] INFO: ROC 0 VthrComp = 103
[16:50:54.512] INFO: ROC 1 VthrComp = 99
[16:50:54.512] INFO: ROC 2 VthrComp = 94
[16:50:54.512] INFO: ROC 3 VthrComp = 95
[16:50:54.513] INFO: ROC 4 VthrComp = 80
[16:50:54.513] INFO: ROC 5 VthrComp = 105
[16:50:54.513] INFO: ROC 6 VthrComp = 98
[16:50:54.513] INFO: ROC 7 VthrComp = 88
[16:50:54.514] INFO: ROC 8 VthrComp = 102
[16:50:54.514] INFO: ROC 9 VthrComp = 97
[16:50:54.514] INFO: ROC 10 VthrComp = 98
[16:50:54.515] INFO: ROC 11 VthrComp = 101
[16:50:54.515] INFO: ROC 12 VthrComp = 102
[16:50:54.515] INFO: ROC 13 VthrComp = 99
[16:50:54.515] INFO: ROC 14 VthrComp = 101
[16:50:54.515] INFO: ROC 15 VthrComp = 98
[16:50:54.515] INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[16:50:54.515] INFO: ---> dac: vcal name: TrimThr1 ntrig: 5 dacrange: 0 .. 159 (20) hits flags = 16 (plus default)
[16:50:54.529] INFO: dacScan step from 0 .. 19
[16:50:54.529] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[16:51:07.119] INFO: Test took 12590ms.
[16:51:07.148] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:51:07.148] INFO: dacScan step from 20 .. 39
[16:51:07.149] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[16:51:19.627] INFO: Test took 12478ms.
[16:51:19.661] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:51:19.663] INFO: dacScan step from 40 .. 59
[16:51:19.663] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[16:51:34.696] INFO: Test took 15033ms.
[16:51:34.852] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:51:34.900] INFO: dacScan step from 60 .. 79
[16:51:34.900] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[16:51:52.086] INFO: Test took 17186ms.
[16:51:52.264] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:51:52.327] INFO: dacScan step from 80 .. 99
[16:51:52.327] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[16:52:09.487] INFO: Test took 17160ms.
[16:52:09.658] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:52:09.721] INFO: dacScan step from 100 .. 119
[16:52:09.721] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[16:52:26.985] INFO: Test took 17264ms.
[16:52:27.160] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:52:27.226] INFO: dacScan step from 120 .. 139
[16:52:27.226] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[16:52:45.916] INFO: Test took 18690ms.
[16:52:46.084] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:52:46.146] INFO: dacScan step from 140 .. 159
[16:52:46.146] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[16:53:03.511] INFO: Test took 17365ms.
[16:53:03.685] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:53:03.748] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[16:53:05.168] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[16:53:06.572] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[16:53:07.972] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[16:53:09.369] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[16:53:10.834] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[16:53:12.272] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[16:53:13.678] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[16:53:15.068] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[16:53:16.502] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[16:53:17.919] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[16:53:19.326] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[16:53:20.746] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[16:53:22.155] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[16:53:23.535] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[16:53:24.917] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[16:53:26.316] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 569348096
[16:53:26.319] INFO: roc 0 with ID = 0 has maximal Vcal 61.8688 for pixel 6/0 mean/min/max = 47.408/32.8176/61.9983
[16:53:26.319] INFO: roc 1 with ID = 1 has maximal Vcal 60.3469 for pixel 11/62 mean/min/max = 45.9342/31.486/60.3824
[16:53:26.319] INFO: roc 2 with ID = 2 has maximal Vcal 62.0261 for pixel 22/0 mean/min/max = 47.1693/32.1305/62.208
[16:53:26.320] INFO: roc 3 with ID = 3 has maximal Vcal 58.597 for pixel 40/79 mean/min/max = 45.7605/32.8626/58.6585
[16:53:26.320] INFO: roc 4 with ID = 4 has maximal Vcal 74.1655 for pixel 6/71 mean/min/max = 56.3117/38.1907/74.4326
[16:53:26.320] INFO: roc 5 with ID = 5 has maximal Vcal 65.9008 for pixel 9/0 mean/min/max = 50.4482/34.7134/66.1829
[16:53:26.320] INFO: roc 6 with ID = 6 has maximal Vcal 61.4994 for pixel 1/16 mean/min/max = 46.6664/31.7794/61.5535
[16:53:26.321] INFO: roc 7 with ID = 7 has maximal Vcal 58.3506 for pixel 49/79 mean/min/max = 45.8157/33.2736/58.3578
[16:53:26.321] INFO: roc 8 with ID = 8 has maximal Vcal 64.6849 for pixel 15/76 mean/min/max = 48.8706/32.949/64.7922
[16:53:26.321] INFO: roc 9 with ID = 9 has maximal Vcal 62.9743 for pixel 18/24 mean/min/max = 47.4655/31.7368/63.1942
[16:53:26.322] INFO: roc 10 with ID = 10 has maximal Vcal 61.7552 for pixel 15/19 mean/min/max = 46.6775/31.5294/61.8257
[16:53:26.322] INFO: roc 11 with ID = 11 has maximal Vcal 64.8067 for pixel 25/68 mean/min/max = 48.7215/32.243/65.1999
[16:53:26.322] INFO: roc 12 with ID = 12 has maximal Vcal 62.4738 for pixel 30/78 mean/min/max = 47.8518/33.1076/62.596
[16:53:26.323] INFO: roc 13 with ID = 13 has maximal Vcal 60.4455 for pixel 17/1 mean/min/max = 46.125/31.6471/60.6029
[16:53:26.323] INFO: roc 14 with ID = 14 has maximal Vcal 60.3437 for pixel 19/0 mean/min/max = 46.1777/31.8421/60.5133
[16:53:26.323] INFO: roc 15 with ID = 15 has maximal Vcal 59.9327 for pixel 0/52 mean/min/max = 45.9863/31.4081/60.5644
[16:53:26.323] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:54:42.306] INFO: Test took 75983ms.
[16:54:43.094] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.1897 < 35 for itrim = 116; old thr = 34.4488 ... break
[16:54:43.122] DEBUG: <PixTestTrim.cc/trimTest:L309> vtrim: vcal = 36.3019 < 35 for itrim+1 = 119; old thr = 34.1605 ... break
[16:54:43.145] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.0129 < 35 for itrim = 105; old thr = 33.5562 ... break
[16:54:43.170] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.4712 < 35 for itrim = 104; old thr = 33.4817 ... break
[16:54:43.183] DEBUG: <PixTestTrim.cc/trimTest:L309> vtrim: vcal = 35.6191 < 35 for itrim+1 = 124; old thr = 34.9311 ... break
[16:54:43.200] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.1703 < 35 for itrim = 112; old thr = 33.9514 ... break
[16:54:43.221] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.1624 < 35 for itrim = 106; old thr = 33.7841 ... break
[16:54:43.248] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 36.0757 < 35 for itrim = 101; old thr = 33.9028 ... break
[16:54:43.266] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.167 < 35 for itrim = 119; old thr = 34.193 ... break
[16:54:43.290] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.3847 < 35 for itrim = 118; old thr = 33.8094 ... break
[16:54:43.313] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.119 < 35 for itrim = 114; old thr = 32.9124 ... break
[16:54:43.343] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.1842 < 35 for itrim = 131; old thr = 34.3017 ... break
[16:54:43.370] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 35.0421 < 35 for itrim = 122; old thr = 33.0151 ... break
[16:54:43.400] DEBUG: <PixTestTrim.cc/trimTest:L304> vtrim: vcal = 36.2372 < 35 for itrim = 115; old thr = 33.5463 ... break
[16:54:43.427] DEBUG: <PixTestTrim.cc/trimTest:L309> vtrim: vcal = 35.596 < 35 for itrim+1 = 111; old thr = 34.795 ... break
[16:54:43.449] DEBUG: <PixTestTrim.cc/trimTest:L309> vtrim: vcal = 35.7359 < 35 for itrim+1 = 109; old thr = 34.7623 ... break
[16:54:43.514] INFO: ---> dac: vcal name: TrimThr2 ntrig: 10 dacrange: 0 .. 199 (20) hits flags = 16 (plus default)
[16:54:43.528] INFO: dacScan step from 0 .. 19
[16:54:43.529] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[16:55:02.244] INFO: Test took 18715ms.
[16:55:02.300] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:55:02.304] INFO: dacScan step from 20 .. 39
[16:55:02.304] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[16:55:25.227] INFO: Test took 22923ms.
[16:55:25.471] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:55:25.514] INFO: dacScan step from 40 .. 59
[16:55:25.514] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[16:55:53.265] INFO: Test took 27751ms.
[16:55:53.562] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:55:53.622] INFO: dacScan step from 60 .. 79
[16:55:53.622] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[16:56:20.524] INFO: Test took 26902ms.
[16:56:20.813] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:56:20.874] INFO: dacScan step from 80 .. 99
[16:56:20.874] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[16:56:48.522] INFO: Test took 27648ms.
[16:56:48.808] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:56:48.870] INFO: dacScan step from 100 .. 119
[16:56:48.870] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[16:57:16.701] INFO: Test took 27831ms.
[16:57:16.995] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:57:17.055] INFO: dacScan step from 120 .. 139
[16:57:17.055] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[16:57:46.309] INFO: Test took 29254ms.
[16:57:46.602] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:57:46.664] INFO: dacScan step from 140 .. 159
[16:57:46.664] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[16:58:14.694] INFO: Test took 28030ms.
[16:58:14.989] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:58:15.049] INFO: dacScan step from 160 .. 179
[16:58:15.050] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[16:58:42.093] INFO: Test took 27043ms.
[16:58:42.393] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:58:42.454] INFO: dacScan step from 180 .. 199
[16:58:42.454] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[16:59:11.057] INFO: Test took 28603ms.
[16:59:11.358] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:59:11.418] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[16:59:12.842] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[16:59:14.244] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[16:59:15.655] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[16:59:17.078] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[16:59:18.600] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[16:59:20.057] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[16:59:21.481] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[16:59:22.895] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[16:59:24.341] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[16:59:25.768] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[16:59:27.190] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[16:59:28.631] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[16:59:30.037] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[16:59:31.408] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[16:59:32.819] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[16:59:34.231] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 573702144
[16:59:34.232] INFO: ---> TrimStepCorr4 extremal thresholds: 0.001956 .. 255.000000
[16:59:34.294] INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 4 dacrange: 0 .. 255 (20) hits flags = 16 (plus default)
[16:59:34.306] INFO: dacScan step from 0 .. 19
[16:59:34.307] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[16:59:45.666] INFO: Test took 11359ms.
[16:59:45.692] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:59:45.693] INFO: dacScan step from 20 .. 39
[16:59:45.693] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[16:59:57.995] INFO: Test took 12302ms.
[16:59:58.081] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:59:58.104] INFO: dacScan step from 40 .. 59
[16:59:58.104] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:00:12.911] INFO: Test took 14807ms.
[17:00:13.068] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:00:13.130] INFO: dacScan step from 60 .. 79
[17:00:13.130] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:00:27.888] INFO: Test took 14758ms.
[17:00:28.041] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:00:28.102] INFO: dacScan step from 80 .. 99
[17:00:28.102] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:00:42.899] INFO: Test took 14797ms.
[17:00:43.048] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:00:43.109] INFO: dacScan step from 100 .. 119
[17:00:43.110] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:00:58.347] INFO: Test took 15237ms.
[17:00:58.504] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:00:58.574] INFO: dacScan step from 120 .. 139
[17:00:58.574] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:01:14.751] INFO: Test took 16177ms.
[17:01:14.899] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:01:14.960] INFO: dacScan step from 140 .. 159
[17:01:14.960] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:01:29.879] INFO: Test took 14919ms.
[17:01:30.027] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:01:30.086] INFO: dacScan step from 160 .. 179
[17:01:30.086] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:01:45.316] INFO: Test took 15230ms.
[17:01:45.469] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:01:45.528] INFO: dacScan step from 180 .. 199
[17:01:45.528] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:02:01.514] INFO: Test took 15986ms.
[17:02:01.664] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:02:01.735] INFO: dacScan step from 200 .. 219
[17:02:01.735] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:02:16.834] INFO: Test took 15099ms.
[17:02:16.990] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:02:17.053] INFO: dacScan step from 220 .. 239
[17:02:17.053] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:02:32.117] INFO: Test took 15063ms.
[17:02:32.271] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:02:32.333] INFO: dacScan step from 240 .. 255
[17:02:32.333] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:02:44.971] INFO: Test took 12638ms.
[17:02:45.091] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:02:45.143] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[17:02:46.881] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[17:02:48.635] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[17:02:50.371] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[17:02:52.118] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[17:02:53.948] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[17:02:55.715] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[17:02:57.457] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[17:02:59.195] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[17:03:00.963] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[17:03:02.697] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[17:03:04.434] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[17:03:06.200] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[17:03:07.934] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[17:03:09.648] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[17:03:11.367] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[17:03:13.086] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 573853696
[17:03:13.153] INFO: ---> TrimStepCorr2 extremal thresholds: 1.031349 .. 59.232163
[17:03:13.216] INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 4 dacrange: 1 .. 69 (20) hits flags = 16 (plus default)
[17:03:13.231] INFO: dacScan step from 1 .. 20
[17:03:13.231] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:03:24.673] INFO: Test took 11442ms.
[17:03:24.699] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:03:24.699] INFO: dacScan step from 21 .. 40
[17:03:24.699] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:03:37.167] INFO: Test took 12468ms.
[17:03:37.262] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:03:37.289] INFO: dacScan step from 41 .. 60
[17:03:37.289] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:03:52.303] INFO: Test took 15014ms.
[17:03:52.462] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:03:52.530] INFO: dacScan step from 61 .. 69
[17:03:52.530] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:04:00.677] INFO: Test took 8147ms.
[17:04:00.748] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:04:00.780] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[17:04:01.755] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[17:04:02.733] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[17:04:03.713] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[17:04:04.694] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[17:04:05.676] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[17:04:06.662] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[17:04:07.654] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[17:04:08.643] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[17:04:09.638] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[17:04:10.632] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[17:04:12.130] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[17:04:13.607] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[17:04:14.619] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[17:04:15.639] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[17:04:16.689] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[17:04:17.718] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 573976576
[17:04:17.789] INFO: ---> TrimStepCorr1a extremal thresholds: 1.173916 .. 59.232163
[17:04:17.860] INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 4 dacrange: 1 .. 69 (20) hits flags = 16 (plus default)
[17:04:17.879] INFO: dacScan step from 1 .. 20
[17:04:17.880] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:04:29.481] INFO: Test took 11601ms.
[17:04:29.505] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:04:29.505] INFO: dacScan step from 21 .. 40
[17:04:29.505] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:04:41.814] INFO: Test took 12309ms.
[17:04:41.898] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:04:41.924] INFO: dacScan step from 41 .. 60
[17:04:41.925] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:04:57.019] INFO: Test took 15094ms.
[17:04:57.174] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:04:57.243] INFO: dacScan step from 61 .. 69
[17:04:57.243] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:05:05.422] INFO: Test took 8179ms.
[17:05:05.492] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:05:05.525] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[17:05:06.487] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[17:05:07.443] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[17:05:08.412] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[17:05:09.369] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[17:05:10.331] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[17:05:11.289] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[17:05:12.249] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[17:05:13.205] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[17:05:14.164] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[17:05:15.119] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[17:05:16.078] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[17:05:17.038] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[17:05:18.002] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[17:05:18.964] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[17:05:19.927] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[17:05:20.888] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 573976576
[17:05:20.955] INFO: ---> TrimStepCorr1b extremal thresholds: 0.267905 .. 59.232163
[17:05:21.019] INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 4 dacrange: 0 .. 69 (20) hits flags = 16 (plus default)
[17:05:21.032] INFO: dacScan step from 0 .. 19
[17:05:21.032] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:05:32.317] INFO: Test took 11285ms.
[17:05:32.341] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:05:32.341] INFO: dacScan step from 20 .. 39
[17:05:32.341] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:05:44.326] INFO: Test took 11985ms.
[17:05:44.405] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:05:44.432] INFO: dacScan step from 40 .. 59
[17:05:44.432] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:05:59.535] INFO: Test took 15103ms.
[17:05:59.696] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:05:59.766] INFO: dacScan step from 60 .. 69
[17:05:59.766] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:06:08.560] INFO: Test took 8794ms.
[17:06:08.638] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:06:08.673] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[17:06:09.634] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[17:06:10.595] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[17:06:11.552] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[17:06:12.507] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[17:06:13.469] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[17:06:14.429] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[17:06:15.384] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[17:06:16.344] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[17:06:17.303] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[17:06:18.264] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[17:06:19.225] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[17:06:20.182] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[17:06:21.147] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[17:06:22.107] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[17:06:23.063] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[17:06:24.025] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 573980672
[17:06:24.095] INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[17:06:24.095] INFO: ---> dac: vcal name: TrimThrFinal ntrig: 10 dacrange: 15 .. 55 (20) hits flags = 16 (plus default)
[17:06:24.108] INFO: dacScan step from 15 .. 34
[17:06:24.108] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:06:42.682] INFO: Test took 18574ms.
[17:06:42.760] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:06:42.776] INFO: dacScan step from 35 .. 54
[17:06:42.776] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:07:09.610] INFO: Test took 26834ms.
[17:07:09.920] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:07:09.984] INFO: dacScan step from 55 .. 55
[17:07:09.984] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:07:13.757] INFO: Test took 3773ms.
[17:07:13.776] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:07:13.781] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[17:07:14.544] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[17:07:15.291] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[17:07:16.040] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[17:07:16.790] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[17:07:17.531] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[17:07:18.286] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[17:07:19.045] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[17:07:19.803] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[17:07:20.557] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[17:07:21.318] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[17:07:22.074] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[17:07:22.832] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[17:07:23.595] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[17:07:24.366] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[17:07:25.129] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[17:07:25.889] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 573980672
[17:07:25.948] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//dacParameters35_C0.dat
[17:07:25.948] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//dacParameters35_C1.dat
[17:07:25.948] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//dacParameters35_C2.dat
[17:07:25.948] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//dacParameters35_C3.dat
[17:07:25.948] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//dacParameters35_C4.dat
[17:07:25.948] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//dacParameters35_C5.dat
[17:07:25.948] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//dacParameters35_C6.dat
[17:07:25.948] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//dacParameters35_C7.dat
[17:07:25.948] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//dacParameters35_C8.dat
[17:07:25.948] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//dacParameters35_C9.dat
[17:07:25.948] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//dacParameters35_C10.dat
[17:07:25.948] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//dacParameters35_C11.dat
[17:07:25.948] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//dacParameters35_C12.dat
[17:07:25.949] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//dacParameters35_C13.dat
[17:07:25.949] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//dacParameters35_C14.dat
[17:07:25.949] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//dacParameters35_C15.dat
[17:07:25.949] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//trimParameters35_C0.dat
[17:07:25.955] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//trimParameters35_C1.dat
[17:07:25.960] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//trimParameters35_C2.dat
[17:07:25.966] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//trimParameters35_C3.dat
[17:07:25.972] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//trimParameters35_C4.dat
[17:07:25.978] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//trimParameters35_C5.dat
[17:07:25.984] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//trimParameters35_C6.dat
[17:07:25.991] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//trimParameters35_C7.dat
[17:07:25.997] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//trimParameters35_C8.dat
[17:07:26.003] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//trimParameters35_C9.dat
[17:07:26.009] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//trimParameters35_C10.dat
[17:07:26.015] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//trimParameters35_C11.dat
[17:07:26.020] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//trimParameters35_C12.dat
[17:07:26.026] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//trimParameters35_C13.dat
[17:07:26.032] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//trimParameters35_C14.dat
[17:07:26.038] INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//trimParameters35_C15.dat
[17:07:26.043] INFO: PixTestTrim::trimTest() done
[17:07:26.043] INFO: vtrim: 116 119 105 104 124 112 106 101 119 118 114 131 122 115 111 109
[17:07:26.043] INFO: vthrcomp: 103 99 94 95 80 105 98 88 102 97 98 101 102 99 101 98
[17:07:26.043] INFO: vcal mean: 35.07 35.02 35.08 35.06 35.16 35.12 35.10 35.05 35.14 35.14 35.04 35.13 34.90 34.79 35.08 35.13
[17:07:26.043] INFO: vcal RMS: 1.33 1.26 1.27 1.10 1.54 1.17 1.50 1.08 1.21 1.28 1.43 1.46 3.64 1.04 1.09 1.38
[17:07:26.043] INFO: bits mean: 9.94 10.29 9.59 9.83 7.92 8.81 9.70 9.37 9.52 9.93 10.00 9.49 9.66 9.92 9.36 9.80
[17:07:26.043] INFO: bits RMS: 2.29 2.38 2.51 2.45 2.00 2.29 2.55 2.55 2.33 2.43 2.47 2.45 2.34 2.50 2.78 2.62
[17:07:26.058] INFO: ----------------------------------------------------------------------
[17:07:26.058] INFO: PixTestTrim::trimBitTest() ntrig = 10, vtrims = 254 126 63 32
[17:07:26.059] INFO: ----------------------------------------------------------------------
[17:07:26.063] DEBUG: <PixTestTrim.cc/trimBitTest:L518> trimBitTest determine threshold map without trims
[17:07:26.063] INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 10 dacrange: 0 .. 199 (20) hits flags = 16 (plus default)
[17:07:26.080] INFO: dacScan step from 0 .. 19
[17:07:26.081] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:07:44.331] INFO: Test took 18250ms.
[17:07:44.371] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:07:44.372] INFO: dacScan step from 20 .. 39
[17:07:44.372] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:08:02.476] INFO: Test took 18104ms.
[17:08:02.516] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:08:02.516] INFO: dacScan step from 40 .. 59
[17:08:02.516] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:08:21.120] INFO: Test took 18604ms.
[17:08:21.162] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:08:21.162] INFO: dacScan step from 60 .. 79
[17:08:21.162] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:08:39.804] INFO: Test took 18642ms.
[17:08:39.845] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:08:39.845] INFO: dacScan step from 80 .. 99
[17:08:39.845] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:08:58.458] INFO: Test took 18613ms.
[17:08:58.496] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:08:58.496] INFO: dacScan step from 100 .. 119
[17:08:58.496] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:09:17.007] INFO: Test took 18511ms.
[17:09:17.065] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:09:17.068] INFO: dacScan step from 120 .. 139
[17:09:17.068] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:09:40.188] INFO: Test took 23120ms.
[17:09:40.368] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:09:40.391] INFO: dacScan step from 140 .. 159
[17:09:40.391] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:10:07.307] INFO: Test took 26916ms.
[17:10:07.598] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:10:07.654] INFO: dacScan step from 160 .. 179
[17:10:07.654] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:10:35.615] INFO: Test took 27961ms.
[17:10:35.895] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:10:35.962] INFO: dacScan step from 180 .. 199
[17:10:35.963] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:11:04.820] INFO: Test took 28857ms.
[17:11:05.105] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:11:05.185] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[17:11:06.552] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[17:11:07.927] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[17:11:09.309] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[17:11:10.705] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[17:11:12.100] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[17:11:13.428] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[17:11:14.807] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[17:11:16.220] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[17:11:17.582] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[17:11:18.958] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[17:11:20.336] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[17:11:21.699] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[17:11:23.060] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[17:11:24.441] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[17:11:25.815] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[17:11:27.208] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 573997056
[17:11:27.209] DEBUG: <PixTestTrim.cc/trimBitTest:L533> trimBitTest initDUT with trim bits = 14
[17:11:27.272] DEBUG: <PixTestTrim.cc/trimBitTest:L539> trimBitTest threshold map with trim = 14
[17:11:27.272] INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 10 dacrange: 0 .. 194 (20) hits flags = 16 (plus default)
[17:11:27.288] INFO: dacScan step from 0 .. 19
[17:11:27.288] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:11:45.502] INFO: Test took 18214ms.
[17:11:45.546] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:11:45.546] INFO: dacScan step from 20 .. 39
[17:11:45.546] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:12:04.186] INFO: Test took 18640ms.
[17:12:04.226] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:12:04.226] INFO: dacScan step from 40 .. 59
[17:12:04.227] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:12:22.841] INFO: Test took 18614ms.
[17:12:22.882] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:12:22.882] INFO: dacScan step from 60 .. 79
[17:12:22.882] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:12:41.448] INFO: Test took 18566ms.
[17:12:41.489] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:12:41.489] INFO: dacScan step from 80 .. 99
[17:12:41.489] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:13:00.088] INFO: Test took 18599ms.
[17:13:00.130] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:13:00.130] INFO: dacScan step from 100 .. 119
[17:13:00.130] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:13:19.419] INFO: Test took 19289ms.
[17:13:19.529] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:13:19.543] INFO: dacScan step from 120 .. 139
[17:13:19.543] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:13:45.779] INFO: Test took 26236ms.
[17:13:46.044] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:13:46.087] INFO: dacScan step from 140 .. 159
[17:13:46.087] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:14:14.010] INFO: Test took 27923ms.
[17:14:14.294] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:14:14.356] INFO: dacScan step from 160 .. 179
[17:14:14.356] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:14:42.491] INFO: Test took 28135ms.
[17:14:42.769] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:14:42.831] INFO: dacScan step from 180 .. 194
[17:14:42.831] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:15:05.095] INFO: Test took 22264ms.
[17:15:05.306] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:15:05.354] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[17:15:06.709] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[17:15:08.075] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[17:15:09.469] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[17:15:10.873] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[17:15:12.270] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[17:15:13.609] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[17:15:14.972] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[17:15:16.377] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[17:15:17.725] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[17:15:19.093] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[17:15:20.467] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[17:15:21.820] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[17:15:23.176] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[17:15:24.561] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[17:15:25.921] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[17:15:27.310] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 573997056
[17:15:27.311] DEBUG: <PixTestTrim.cc/trimBitTest:L533> trimBitTest initDUT with trim bits = 13
[17:15:27.375] DEBUG: <PixTestTrim.cc/trimBitTest:L539> trimBitTest threshold map with trim = 13
[17:15:27.375] INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 10 dacrange: 0 .. 178 (20) hits flags = 16 (plus default)
[17:15:27.389] INFO: dacScan step from 0 .. 19
[17:15:27.390] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:15:45.993] INFO: Test took 18603ms.
[17:15:46.036] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:15:46.037] INFO: dacScan step from 20 .. 39
[17:15:46.040] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:16:04.599] INFO: Test took 18558ms.
[17:16:04.641] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:16:04.641] INFO: dacScan step from 40 .. 59
[17:16:04.641] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:16:23.177] INFO: Test took 18536ms.
[17:16:23.218] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:16:23.218] INFO: dacScan step from 60 .. 79
[17:16:23.218] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:16:41.799] INFO: Test took 18581ms.
[17:16:41.839] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:16:41.839] INFO: dacScan step from 80 .. 99
[17:16:41.839] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:17:00.060] INFO: Test took 18221ms.
[17:17:00.101] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:17:00.101] INFO: dacScan step from 100 .. 119
[17:17:00.101] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:17:19.918] INFO: Test took 19817ms.
[17:17:20.030] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:17:20.042] INFO: dacScan step from 120 .. 139
[17:17:20.043] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:17:45.618] INFO: Test took 25575ms.
[17:17:45.882] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:17:45.925] INFO: dacScan step from 140 .. 159
[17:17:45.925] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:18:13.051] INFO: Test took 27126ms.
[17:18:13.338] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:18:13.399] INFO: dacScan step from 160 .. 178
[17:18:13.399] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:18:40.256] INFO: Test took 26857ms.
[17:18:40.523] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:18:40.582] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[17:18:41.835] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[17:18:43.124] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[17:18:44.431] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[17:18:45.743] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[17:18:47.050] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[17:18:48.286] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[17:18:49.556] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[17:18:50.875] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[17:18:52.131] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[17:18:53.404] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[17:18:54.684] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[17:18:55.941] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[17:18:57.200] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[17:18:58.592] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[17:18:59.896] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[17:19:01.326] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 573997056
[17:19:01.327] DEBUG: <PixTestTrim.cc/trimBitTest:L533> trimBitTest initDUT with trim bits = 11
[17:19:01.393] DEBUG: <PixTestTrim.cc/trimBitTest:L539> trimBitTest threshold map with trim = 11
[17:19:01.393] INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 10 dacrange: 0 .. 176 (20) hits flags = 16 (plus default)
[17:19:01.411] INFO: dacScan step from 0 .. 19
[17:19:01.411] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:19:19.585] INFO: Test took 18174ms.
[17:19:19.627] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:19:19.627] INFO: dacScan step from 20 .. 39
[17:19:19.628] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:19:38.278] INFO: Test took 18650ms.
[17:19:38.317] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:19:38.317] INFO: dacScan step from 40 .. 59
[17:19:38.317] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:19:56.932] INFO: Test took 18615ms.
[17:19:56.972] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:19:56.972] INFO: dacScan step from 60 .. 79
[17:19:56.972] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:20:15.560] INFO: Test took 18588ms.
[17:20:15.599] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:20:15.600] INFO: dacScan step from 80 .. 99
[17:20:15.600] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:20:34.206] INFO: Test took 18606ms.
[17:20:34.248] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:20:34.248] INFO: dacScan step from 100 .. 119
[17:20:34.248] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:20:54.041] INFO: Test took 19793ms.
[17:20:54.153] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:20:54.166] INFO: dacScan step from 120 .. 139
[17:20:54.166] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:21:20.297] INFO: Test took 26131ms.
[17:21:20.564] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:21:20.606] INFO: dacScan step from 140 .. 159
[17:21:20.606] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:21:48.313] INFO: Test took 27707ms.
[17:21:48.608] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:21:48.670] INFO: dacScan step from 160 .. 176
[17:21:48.670] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:22:12.459] INFO: Test took 23789ms.
[17:22:12.697] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:22:12.750] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[17:22:14.029] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[17:22:15.327] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[17:22:16.652] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[17:22:17.992] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[17:22:19.325] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[17:22:20.584] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[17:22:21.882] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[17:22:23.245] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[17:22:24.541] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[17:22:25.853] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[17:22:27.162] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[17:22:28.441] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[17:22:29.729] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[17:22:31.043] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[17:22:32.344] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[17:22:33.687] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 573997056
[17:22:33.687] DEBUG: <PixTestTrim.cc/trimBitTest:L533> trimBitTest initDUT with trim bits = 7
[17:22:33.751] DEBUG: <PixTestTrim.cc/trimBitTest:L539> trimBitTest threshold map with trim = 7
[17:22:33.751] INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 10 dacrange: 0 .. 177 (20) hits flags = 16 (plus default)
[17:22:33.765] INFO: dacScan step from 0 .. 19
[17:22:33.765] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:22:52.379] INFO: Test took 18614ms.
[17:22:52.420] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:22:52.420] INFO: dacScan step from 20 .. 39
[17:22:52.420] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:23:11.061] INFO: Test took 18641ms.
[17:23:11.100] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:23:11.101] INFO: dacScan step from 40 .. 59
[17:23:11.101] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:23:29.690] INFO: Test took 18589ms.
[17:23:29.730] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:23:29.730] INFO: dacScan step from 60 .. 79
[17:23:29.731] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:23:48.298] INFO: Test took 18567ms.
[17:23:48.339] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:23:48.339] INFO: dacScan step from 80 .. 99
[17:23:48.339] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:24:06.000] INFO: Test took 18661ms.
[17:24:07.044] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:24:07.044] INFO: dacScan step from 100 .. 119
[17:24:07.044] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:24:26.819] INFO: Test took 19775ms.
[17:24:26.934] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:24:26.948] INFO: dacScan step from 120 .. 139
[17:24:26.948] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:24:53.222] INFO: Test took 26274ms.
[17:24:53.486] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:24:53.530] INFO: dacScan step from 140 .. 159
[17:24:53.530] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:25:21.431] INFO: Test took 27901ms.
[17:25:21.717] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:25:21.777] INFO: dacScan step from 160 .. 177
[17:25:21.777] DEBUG: <PixTest.cc/dacScan:L1518> attempt #0
[17:25:47.136] INFO: Test took 25359ms.
[17:25:47.390] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:25:47.446] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0
[17:25:48.731] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1
[17:25:50.034] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2
[17:25:51.369] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3
[17:25:52.721] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4
[17:25:54.043] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5
[17:25:55.478] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6
[17:25:56.918] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7
[17:25:58.388] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8
[17:25:59.665] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9
[17:26:00.977] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10
[17:26:02.251] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11
[17:26:03.503] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12
[17:26:04.758] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13
[17:26:06.057] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14
[17:26:07.323] DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15
[17:26:08.629] DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 573997056
[17:26:08.630] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 0 step 0: thr difference mean: 11.5674, thr difference RMS: 1.38352
[17:26:08.630] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 1 step 0: thr difference mean: 11.3305, thr difference RMS: 1.03602
[17:26:08.630] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 2 step 0: thr difference mean: 11.7493, thr difference RMS: 1.31425
[17:26:08.630] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 3 step 0: thr difference mean: 10.3969, thr difference RMS: 1.48014
[17:26:08.630] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 4 step 0: thr difference mean: 11.6212, thr difference RMS: 1.21172
[17:26:08.631] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 5 step 0: thr difference mean: 12.7701, thr difference RMS: 1.39788
[17:26:08.631] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 6 step 0: thr difference mean: 11.6766, thr difference RMS: 1.11806
[17:26:08.631] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 7 step 0: thr difference mean: 9.59315, thr difference RMS: 1.38598
[17:26:08.631] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 8 step 0: thr difference mean: 11.2921, thr difference RMS: 1.2442
[17:26:08.632] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 9 step 0: thr difference mean: 12.1623, thr difference RMS: 1.13777
[17:26:08.632] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 10 step 0: thr difference mean: 11.2094, thr difference RMS: 0.964569
[17:26:08.632] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 11 step 0: thr difference mean: 11.3807, thr difference RMS: 1.31472
[17:26:08.632] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 12 step 0: thr difference mean: 11.7842, thr difference RMS: 1.45167
[17:26:08.632] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 13 step 0: thr difference mean: 11.0011, thr difference RMS: 1.17578
[17:26:08.632] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 14 step 0: thr difference mean: 10.2461, thr difference RMS: 1.02003
[17:26:08.633] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 15 step 0: thr difference mean: 11.1071, thr difference RMS: 1.13259
[17:26:08.633] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 0 step 1: thr difference mean: 11.8495, thr difference RMS: 1.35601
[17:26:08.633] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 1 step 1: thr difference mean: 11.3841, thr difference RMS: 1.02591
[17:26:08.633] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 2 step 1: thr difference mean: 11.9622, thr difference RMS: 1.33752
[17:26:08.633] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 3 step 1: thr difference mean: 10.4411, thr difference RMS: 1.44541
[17:26:08.633] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 4 step 1: thr difference mean: 11.5269, thr difference RMS: 1.20614
[17:26:08.634] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 5 step 1: thr difference mean: 12.7886, thr difference RMS: 1.99095
[17:26:08.634] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 6 step 1: thr difference mean: 11.5983, thr difference RMS: 1.0909
[17:26:08.634] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 7 step 1: thr difference mean: 9.65572, thr difference RMS: 1.39556
[17:26:08.634] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 8 step 1: thr difference mean: 11.404, thr difference RMS: 1.26333
[17:26:08.634] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 9 step 1: thr difference mean: 12.2347, thr difference RMS: 1.13702
[17:26:08.634] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 10 step 1: thr difference mean: 11.2714, thr difference RMS: 0.948458
[17:26:08.635] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 11 step 1: thr difference mean: 11.4086, thr difference RMS: 1.28981
[17:26:08.635] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 12 step 1: thr difference mean: 11.5419, thr difference RMS: 1.45508
[17:26:08.635] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 13 step 1: thr difference mean: 11.0375, thr difference RMS: 1.20081
[17:26:08.635] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 14 step 1: thr difference mean: 10.3076, thr difference RMS: 0.985959
[17:26:08.635] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 15 step 1: thr difference mean: 11.0675, thr difference RMS: 1.11858
[17:26:08.635] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 0 step 2: thr difference mean: 12.0068, thr difference RMS: 1.34062
[17:26:08.636] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 1 step 2: thr difference mean: 11.4983, thr difference RMS: 1.0075
[17:26:08.636] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 2 step 2: thr difference mean: 12.1834, thr difference RMS: 1.32921
[17:26:08.636] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 3 step 2: thr difference mean: 10.5708, thr difference RMS: 1.44068
[17:26:08.636] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 4 step 2: thr difference mean: 11.507, thr difference RMS: 1.19605
[17:26:08.636] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 5 step 2: thr difference mean: 12.8724, thr difference RMS: 2.34382
[17:26:08.636] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 6 step 2: thr difference mean: 11.5653, thr difference RMS: 1.09715
[17:26:08.637] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 7 step 2: thr difference mean: 9.53342, thr difference RMS: 1.37764
[17:26:08.637] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 8 step 2: thr difference mean: 11.4937, thr difference RMS: 1.25176
[17:26:08.637] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 9 step 2: thr difference mean: 12.2806, thr difference RMS: 1.12991
[17:26:08.637] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 10 step 2: thr difference mean: 11.3378, thr difference RMS: 0.946111
[17:26:08.637] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 11 step 2: thr difference mean: 11.3793, thr difference RMS: 1.27634
[17:26:08.637] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 12 step 2: thr difference mean: 11.7825, thr difference RMS: 1.45104
[17:26:08.638] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 13 step 2: thr difference mean: 11.0892, thr difference RMS: 1.19358
[17:26:08.638] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 14 step 2: thr difference mean: 10.3139, thr difference RMS: 0.967427
[17:26:08.638] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 15 step 2: thr difference mean: 11.0178, thr difference RMS: 1.12597
[17:26:08.638] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 0 step 3: thr difference mean: 12.2309, thr difference RMS: 1.3368
[17:26:08.638] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 1 step 3: thr difference mean: 11.5534, thr difference RMS: 1.00412
[17:26:08.638] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 2 step 3: thr difference mean: 12.4016, thr difference RMS: 1.35278
[17:26:08.639] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 3 step 3: thr difference mean: 10.7648, thr difference RMS: 1.44964
[17:26:08.639] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 4 step 3: thr difference mean: 11.4826, thr difference RMS: 1.18816
[17:26:08.639] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 5 step 3: thr difference mean: 12.8565, thr difference RMS: 1.36875
[17:26:08.639] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 6 step 3: thr difference mean: 11.7125, thr difference RMS: 1.07304
[17:26:08.639] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 7 step 3: thr difference mean: 9.73996, thr difference RMS: 1.3726
[17:26:08.639] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 8 step 3: thr difference mean: 11.6712, thr difference RMS: 1.22976
[17:26:08.640] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 9 step 3: thr difference mean: 12.252, thr difference RMS: 1.09693
[17:26:08.640] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 10 step 3: thr difference mean: 11.5582, thr difference RMS: 0.938583
[17:26:08.640] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 11 step 3: thr difference mean: 11.4306, thr difference RMS: 1.26503
[17:26:08.640] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 12 step 3: thr difference mean: 11.9441, thr difference RMS: 1.42285
[17:26:08.640] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 13 step 3: thr difference mean: 11.4156, thr difference RMS: 1.20842
[17:26:08.640] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 14 step 3: thr difference mean: 10.4171, thr difference RMS: 0.972256
[17:26:08.641] DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 15 step 3: thr difference mean: 11.0644, thr difference RMS: 1.11931
[17:26:08.752] INFO: PixTestTrim::trimBitTest() done
[17:26:08.754] INFO: PixTestTrim::doTest() done, duration: 2241 seconds
[17:26:08.754] DEBUG: <PixTestTrim.cc/~PixTestTrim:L104> PixTestTrim dtor
[17:26:09.329] DEBUG: <PixTest.cc/setTestParameter:L569> setting ntrig to new value 10
[17:26:09.329] DEBUG: <PixTestPhOptimization.cc/setParameter:L37> setting fParNtrig ->10<- from sval = 10
[17:26:09.329] DEBUG: <PixTestPhOptimization.cc/setParameter:L42> setting fSafetyMarginLow ->20<- from sval = 20
[17:26:09.329] DEBUG: <PixTestPhOptimization.cc/setParameter:L48> setting fVcalMax ->100<- from sval = 100
[17:26:09.330] DEBUG: <PixTestPhOptimization.cc/setParameter:L53> setting fQuantMax ->0.98<- from sval = 0.98
[17:26:09.330] INFO: ######################################################################
[17:26:09.330] INFO: PixTestPhOptimization::doTest() Ntrig = 10
[17:26:09.330] INFO: ######################################################################
[17:26:09.333] DEBUG: <PixTest.cc/efficiencyMaps:L328> attempt #0
[17:26:13.034] INFO: Test took 3701ms.
[17:26:13.054] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:26:13.054] DEBUG: <PixTest.cc/efficiencyMaps:L339> eff result size = 66543
[17:26:13.054] DEBUG: <PixTest.cc/efficiencyMaps:L344> Create hists PixelAlive_C0 .. PixelAlive_C15
[17:26:13.057] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [0, 41, 40] has eff 4/10
[17:26:13.058] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [0, 41, 40]
[17:26:13.058] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [0, 5, 55] has eff 0/10
[17:26:13.058] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [0, 5, 55]
[17:26:13.058] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [1, 17, 18] has eff 0/10
[17:26:13.058] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [1, 17, 18]
[17:26:13.058] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [2, 51, 43] has eff 0/10
[17:26:13.058] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [2, 51, 43]
[17:26:13.058] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [4, 0, 24] has eff 8/10
[17:26:13.058] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [4, 0, 24]
[17:26:13.058] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [4, 0, 26] has eff 9/10
[17:26:13.058] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [4, 0, 26]
[17:26:13.058] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [4, 2, 26] has eff 9/10
[17:26:13.058] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [4, 2, 26]
[17:26:13.058] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [4, 0, 33] has eff 9/10
[17:26:13.058] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [4, 0, 33]
[17:26:13.058] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [4, 34, 33] has eff 0/10
[17:26:13.058] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [4, 34, 33]
[17:26:13.058] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [4, 1, 39] has eff 0/10
[17:26:13.058] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [4, 1, 39]
[17:26:13.058] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [4, 43, 46] has eff 0/10
[17:26:13.058] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [4, 43, 46]
[17:26:13.058] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [4, 2, 53] has eff 9/10
[17:26:13.058] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [4, 2, 53]
[17:26:13.058] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [4, 0, 68] has eff 9/10
[17:26:13.058] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [4, 0, 68]
[17:26:13.058] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [4, 0, 73] has eff 9/10
[17:26:13.058] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [4, 0, 73]
[17:26:13.059] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [6, 6, 11] has eff 0/10
[17:26:13.059] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [6, 6, 11]
[17:26:13.059] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [6, 42, 24] has eff 0/10
[17:26:13.059] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [6, 42, 24]
[17:26:13.059] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [6, 37, 27] has eff 1/10
[17:26:13.059] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [6, 37, 27]
[17:26:13.059] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [6, 45, 43] has eff 0/10
[17:26:13.059] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [6, 45, 43]
[17:26:13.059] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [9, 41, 50] has eff 3/10
[17:26:13.059] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [9, 41, 50]
[17:26:13.059] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [10, 13, 31] has eff 2/10
[17:26:13.059] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [10, 13, 31]
[17:26:13.059] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [10, 35, 35] has eff 0/10
[17:26:13.059] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [10, 35, 35]
[17:26:13.059] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [10, 45, 56] has eff 0/10
[17:26:13.059] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [10, 45, 56]
[17:26:13.059] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [11, 40, 32] has eff 0/10
[17:26:13.059] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [11, 40, 32]
[17:26:13.059] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [11, 36, 43] has eff 0/10
[17:26:13.059] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [11, 36, 43]
[17:26:13.059] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [12, 49, 27] has eff 0/10
[17:26:13.059] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [12, 49, 27]
[17:26:13.060] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [12, 5, 39] has eff 0/10
[17:26:13.060] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [12, 5, 39]
[17:26:13.060] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [15, 43, 9] has eff 0/10
[17:26:13.060] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [15, 43, 9]
[17:26:13.060] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [15, 43, 10] has eff 0/10
[17:26:13.060] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [15, 43, 10]
[17:26:13.071] DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L239> Number of bad pixels found: 28
[17:26:13.071] DEBUG: <PixTestPhOptimization.cc/doTest:L124> **********Ph range will be optimised on the whole ROC***********
[17:26:13.071] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L276> ROC type is newer than digv2
[17:26:13.071] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L277> ROC type is psi46digv21respin
[17:26:13.254] DEBUG: <PixTest.cc/phMaps:L264> attempt #0
[17:26:16.957] INFO: Test took 3703ms.
[17:26:17.019] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:26:17.019] DEBUG: <PixTest.cc/phMaps:L275> eff result size = 66545
[17:26:17.019] DEBUG: <PixTest.cc/phMaps:L282> Create hists maxphmap_C0 .. maxphmap_C15
[17:26:17.023] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 177.974
[17:26:17.023] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,9] phvalue 178
[17:26:17.023] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 175.789
[17:26:17.023] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,5] phvalue 175
[17:26:17.023] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 157.571
[17:26:17.023] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,15] phvalue 157
[17:26:17.024] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 187.617
[17:26:17.024] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [4 ,5] phvalue 188
[17:26:17.024] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 165.07
[17:26:17.024] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [16 ,5] phvalue 165
[17:26:17.024] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 172.246
[17:26:17.024] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,10] phvalue 173
[17:26:17.024] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 178.011
[17:26:17.024] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,16] phvalue 178
[17:26:17.024] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 182.336
[17:26:17.024] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [12 ,5] phvalue 182
[17:26:17.024] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 169.505
[17:26:17.024] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [4 ,6] phvalue 170
[17:26:17.024] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 167.692
[17:26:17.024] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,5] phvalue 167
[17:26:17.024] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 180.35
[17:26:17.025] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,6] phvalue 180
[17:26:17.025] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 164.265
[17:26:17.025] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,15] phvalue 164
[17:26:17.025] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 166.254
[17:26:17.025] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,5] phvalue 166
[17:26:17.025] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 178.742
[17:26:17.025] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [4 ,5] phvalue 179
[17:26:17.025] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 172.128
[17:26:17.025] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [8 ,17] phvalue 172
[17:26:17.025] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 164.005
[17:26:17.025] DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,5] phvalue 164
[17:26:17.025] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L427> ROC type is newer than digv2
[17:26:17.025] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L428> ROC type is psi46digv21respin
[17:26:17.025] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L450> init_phScale=150, flag_minPh = 0, minph = 0
[17:26:17.034] DEBUG: <PixTest.cc/phMaps:L264> attempt #0
[17:26:20.734] INFO: Test took 3700ms.
[17:26:20.796] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:26:20.796] DEBUG: <PixTest.cc/phMaps:L275> eff result size = 66546
[17:26:20.796] DEBUG: <PixTest.cc/phMaps:L282> Create hists minphmap_C0 .. minphmap_C15
[17:26:20.799] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L457> result size 0
[17:26:20.800] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L484> done. init_phScale=155, flag_minPh = 1, minph = 49minph_roc = 5
[17:26:20.800] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 76.1491
[17:26:20.800] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,12] phvalue 77
[17:26:20.800] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 60.63
[17:26:20.800] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,42] phvalue 61
[17:26:20.800] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 51.2942
[17:26:20.800] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,12] phvalue 52
[17:26:20.800] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 84.7437
[17:26:20.800] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,42] phvalue 85
[17:26:20.801] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 57.1669
[17:26:20.801] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,50] phvalue 58
[17:26:20.801] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 54.448
[17:26:20.801] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [4 ,11] phvalue 55
[17:26:20.801] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 77.5719
[17:26:20.801] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [4 ,31] phvalue 78
[17:26:20.801] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 77.2808
[17:26:20.801] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,12] phvalue 78
[17:26:20.801] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 61.9277
[17:26:20.801] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,8] phvalue 62
[17:26:20.801] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 61.8553
[17:26:20.801] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,14] phvalue 62
[17:26:20.802] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 72.6602
[17:26:20.802] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [4 ,42] phvalue 73
[17:26:20.802] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 60.5525
[17:26:20.802] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,48] phvalue 61
[17:26:20.802] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 64.6561
[17:26:20.802] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [10 ,6] phvalue 65
[17:26:20.802] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 77.3724
[17:26:20.802] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,24] phvalue 77
[17:26:20.802] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 60.8031
[17:26:20.802] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,68] phvalue 61
[17:26:20.802] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 52.4129
[17:26:20.802] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,32] phvalue 53
[17:26:20.805] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 12, 0 0
[17:26:20.805] INFO: The DUT currently contains the following objects:
[17:26:20.805] INFO: 2 TBM Cores tbm08c (2 ON)
[17:26:20.805] INFO: TBM Core alpha (0): 7 registers set
[17:26:20.805] INFO: TBM Core beta (1): 7 registers set
[17:26:20.805] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[17:26:20.805] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:20.805] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:20.805] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:20.805] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:20.805] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:20.805] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:20.805] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:20.805] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:20.805] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:20.805] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:20.805] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:20.805] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:20.805] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:20.805] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:20.805] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:20.805] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:21.896] INFO: Test took 1091ms.
[17:26:21.896] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[17:26:21.896] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 42, 1 1
[17:26:21.896] INFO: The DUT currently contains the following objects:
[17:26:21.896] INFO: 2 TBM Cores tbm08c (2 ON)
[17:26:21.896] INFO: TBM Core alpha (0): 7 registers set
[17:26:21.896] INFO: TBM Core beta (1): 7 registers set
[17:26:21.896] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[17:26:21.896] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:21.896] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:21.896] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:21.896] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:21.897] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:21.897] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:21.897] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:21.897] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:21.897] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:21.897] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:21.897] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:21.897] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:21.897] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:21.897] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:21.897] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:21.897] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:22.988] INFO: Test took 1091ms.
[17:26:22.989] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[17:26:22.989] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 12, 2 2
[17:26:22.989] INFO: The DUT currently contains the following objects:
[17:26:22.989] INFO: 2 TBM Cores tbm08c (2 ON)
[17:26:22.989] INFO: TBM Core alpha (0): 7 registers set
[17:26:22.989] INFO: TBM Core beta (1): 7 registers set
[17:26:22.989] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[17:26:22.989] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:22.989] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:22.989] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:22.989] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:22.989] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:22.989] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:22.989] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:22.989] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:22.989] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:22.989] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:22.989] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:22.989] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:22.989] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:22.989] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:22.989] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:22.989] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:24.081] INFO: Test took 1092ms.
[17:26:24.082] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[17:26:24.085] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 42, 3 3
[17:26:24.085] INFO: The DUT currently contains the following objects:
[17:26:24.085] INFO: 2 TBM Cores tbm08c (2 ON)
[17:26:24.086] INFO: TBM Core alpha (0): 7 registers set
[17:26:24.086] INFO: TBM Core beta (1): 7 registers set
[17:26:24.087] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[17:26:24.087] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:24.088] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:24.089] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:24.089] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:24.090] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:24.091] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:24.091] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:24.092] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:24.092] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:24.093] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:24.094] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:24.094] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:24.094] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:24.094] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:24.094] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:24.094] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:25.173] INFO: Test took 1078ms.
[17:26:25.174] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[17:26:25.174] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 50, 4 4
[17:26:25.174] INFO: The DUT currently contains the following objects:
[17:26:25.174] INFO: 2 TBM Cores tbm08c (2 ON)
[17:26:25.174] INFO: TBM Core alpha (0): 7 registers set
[17:26:25.174] INFO: TBM Core beta (1): 7 registers set
[17:26:25.174] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[17:26:25.174] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:25.174] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:25.174] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:25.174] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:25.174] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:25.174] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:25.174] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:25.174] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:25.174] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:25.174] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:25.174] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:25.174] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:25.174] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:25.174] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:25.174] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:25.174] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:26.264] INFO: Test took 1090ms.
[17:26:26.265] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[17:26:26.268] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 4, 11, 5 5
[17:26:26.268] INFO: The DUT currently contains the following objects:
[17:26:26.268] INFO: 2 TBM Cores tbm08c (2 ON)
[17:26:26.268] INFO: TBM Core alpha (0): 7 registers set
[17:26:26.268] INFO: TBM Core beta (1): 7 registers set
[17:26:26.268] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[17:26:26.268] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:26.268] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:26.268] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:26.268] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:26.268] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:26.268] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:26.268] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:26.268] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:26.268] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:26.268] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:26.269] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:26.269] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:26.269] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:26.269] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:26.269] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:26.269] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:27.356] INFO: Test took 1087ms.
[17:26:27.356] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[17:26:27.356] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 4, 31, 6 6
[17:26:27.357] INFO: The DUT currently contains the following objects:
[17:26:27.357] INFO: 2 TBM Cores tbm08c (2 ON)
[17:26:27.357] INFO: TBM Core alpha (0): 7 registers set
[17:26:27.357] INFO: TBM Core beta (1): 7 registers set
[17:26:27.357] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[17:26:27.357] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:27.357] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:27.357] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:27.357] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:27.357] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:27.357] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:27.357] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:27.357] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:27.357] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:27.357] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:27.357] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:27.357] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:27.357] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:27.357] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:27.357] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:27.357] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:28.447] INFO: Test took 1090ms.
[17:26:28.448] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[17:26:28.449] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 12, 7 7
[17:26:28.449] INFO: The DUT currently contains the following objects:
[17:26:28.449] INFO: 2 TBM Cores tbm08c (2 ON)
[17:26:28.449] INFO: TBM Core alpha (0): 7 registers set
[17:26:28.449] INFO: TBM Core beta (1): 7 registers set
[17:26:28.449] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[17:26:28.449] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:28.449] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:28.449] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:28.449] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:28.449] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:28.449] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:28.449] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:28.449] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:28.449] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:28.449] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:28.449] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:28.449] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:28.449] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:28.449] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:28.449] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:28.449] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:29.543] INFO: Test took 1094ms.
[17:26:29.544] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[17:26:29.547] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 8, 8 8
[17:26:29.548] INFO: The DUT currently contains the following objects:
[17:26:29.548] INFO: 2 TBM Cores tbm08c (2 ON)
[17:26:29.548] INFO: TBM Core alpha (0): 7 registers set
[17:26:29.549] INFO: TBM Core beta (1): 7 registers set
[17:26:29.549] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[17:26:29.550] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:29.550] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:29.551] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:29.552] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:29.552] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:29.553] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:29.553] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:29.554] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:29.554] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:29.555] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:29.556] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:29.556] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:29.557] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:29.557] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:29.558] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:29.559] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:30.635] INFO: Test took 1076ms.
[17:26:30.636] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[17:26:30.636] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 14, 9 9
[17:26:30.636] INFO: The DUT currently contains the following objects:
[17:26:30.636] INFO: 2 TBM Cores tbm08c (2 ON)
[17:26:30.636] INFO: TBM Core alpha (0): 7 registers set
[17:26:30.636] INFO: TBM Core beta (1): 7 registers set
[17:26:30.636] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[17:26:30.636] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:30.636] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:30.636] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:30.636] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:30.636] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:30.636] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:30.636] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:30.636] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:30.636] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:30.637] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:30.637] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:30.637] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:30.637] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:30.637] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:30.637] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:30.637] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:31.727] INFO: Test took 1090ms.
[17:26:31.727] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[17:26:31.730] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 4, 42, 10 10
[17:26:31.730] INFO: The DUT currently contains the following objects:
[17:26:31.731] INFO: 2 TBM Cores tbm08c (2 ON)
[17:26:31.731] INFO: TBM Core alpha (0): 7 registers set
[17:26:31.732] INFO: TBM Core beta (1): 7 registers set
[17:26:31.732] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[17:26:31.733] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:31.733] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:31.734] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:31.734] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:31.735] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:31.736] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:31.736] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:31.737] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:31.737] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:31.738] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:31.739] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:31.739] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:31.740] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:31.740] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:31.741] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:31.742] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:32.823] INFO: Test took 1081ms.
[17:26:32.823] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[17:26:32.824] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 48, 11 11
[17:26:32.824] INFO: The DUT currently contains the following objects:
[17:26:32.824] INFO: 2 TBM Cores tbm08c (2 ON)
[17:26:32.824] INFO: TBM Core alpha (0): 7 registers set
[17:26:32.824] INFO: TBM Core beta (1): 7 registers set
[17:26:32.824] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[17:26:32.824] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:32.824] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:32.824] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:32.824] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:32.824] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:32.824] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:32.824] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:32.824] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:32.824] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:32.824] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:32.824] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:32.824] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:32.824] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:32.824] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:32.824] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:32.824] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:33.914] INFO: Test took 1090ms.
[17:26:33.914] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[17:26:33.914] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 10, 6, 12 12
[17:26:33.914] INFO: The DUT currently contains the following objects:
[17:26:33.915] INFO: 2 TBM Cores tbm08c (2 ON)
[17:26:33.915] INFO: TBM Core alpha (0): 7 registers set
[17:26:33.915] INFO: TBM Core beta (1): 7 registers set
[17:26:33.915] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[17:26:33.915] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:33.915] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:33.915] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:33.915] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:33.915] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:33.915] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:33.915] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:33.915] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:33.915] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:33.915] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:33.915] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:33.915] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:33.915] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:33.915] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:33.915] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:33.915] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:35.005] INFO: Test took 1090ms.
[17:26:35.006] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[17:26:35.006] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 24, 13 13
[17:26:35.006] INFO: The DUT currently contains the following objects:
[17:26:35.006] INFO: 2 TBM Cores tbm08c (2 ON)
[17:26:35.006] INFO: TBM Core alpha (0): 7 registers set
[17:26:35.006] INFO: TBM Core beta (1): 7 registers set
[17:26:35.006] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[17:26:35.006] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:35.006] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:35.006] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:35.006] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:35.006] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:35.006] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:35.006] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:35.006] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:35.006] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:35.006] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:35.006] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:35.006] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:35.006] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:35.006] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:35.006] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:35.006] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:36.096] INFO: Test took 1090ms.
[17:26:36.097] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[17:26:36.097] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 68, 14 14
[17:26:36.097] INFO: The DUT currently contains the following objects:
[17:26:36.097] INFO: 2 TBM Cores tbm08c (2 ON)
[17:26:36.097] INFO: TBM Core alpha (0): 7 registers set
[17:26:36.097] INFO: TBM Core beta (1): 7 registers set
[17:26:36.097] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[17:26:36.097] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:36.097] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:36.097] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:36.097] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:36.097] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:36.097] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:36.097] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:36.097] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:36.097] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:36.097] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:36.097] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:36.097] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:36.097] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:36.097] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:36.097] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:36.097] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:37.187] INFO: Test took 1090ms.
[17:26:37.188] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[17:26:37.188] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 32, 15 15
[17:26:37.188] INFO: The DUT currently contains the following objects:
[17:26:37.188] INFO: 2 TBM Cores tbm08c (2 ON)
[17:26:37.188] INFO: TBM Core alpha (0): 7 registers set
[17:26:37.188] INFO: TBM Core beta (1): 7 registers set
[17:26:37.188] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[17:26:37.188] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:37.188] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:37.188] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:37.188] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:37.188] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:37.188] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:37.188] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:37.188] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:37.188] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:37.188] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:37.188] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:37.188] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:37.188] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:37.188] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:37.188] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:37.188] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[17:26:38.278] INFO: Test took 1090ms.
[17:26:38.279] DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256
[17:26:38.279] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 32 on ROC0
[17:26:38.279] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 33 on ROC1
[17:26:38.279] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 31 on ROC2
[17:26:38.279] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 30 on ROC3
[17:26:38.279] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 23 on ROC4
[17:26:38.279] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 29 on ROC5
[17:26:38.279] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 30 on ROC6
[17:26:38.279] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 32 on ROC7
[17:26:38.279] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 35 on ROC8
[17:26:38.279] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 33 on ROC9
[17:26:38.279] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 31 on ROC10
[17:26:38.279] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 29 on ROC11
[17:26:38.279] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 33 on ROC12
[17:26:38.279] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 33 on ROC13
[17:26:38.279] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 30 on ROC14
[17:26:38.279] DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 28 on ROC15
[17:26:38.285] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:29:34.569] INFO: Test took 176284ms.
[17:29:36.067] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:32:31.165] INFO: Test took 175098ms.
[17:32:32.790] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[17:32:32.791] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip0
[17:32:32.791] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[17:32:32.791] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip1
[17:32:32.791] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[17:32:32.792] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip2
[17:32:32.792] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[17:32:32.792] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip3
[17:32:32.792] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[17:32:32.792] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip4
[17:32:32.792] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[17:32:32.793] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip5
[17:32:32.793] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[17:32:32.793] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip6
[17:32:32.793] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[17:32:32.793] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip7
[17:32:32.793] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[17:32:32.794] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip8
[17:32:32.794] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[17:32:32.794] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip9
[17:32:32.794] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[17:32:32.795] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip10
[17:32:32.795] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[17:32:32.795] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip11
[17:32:32.795] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[17:32:32.795] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip12
[17:32:32.795] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[17:32:32.796] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip13
[17:32:32.796] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[17:32:32.796] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip14
[17:32:32.796] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component
[17:32:32.796] DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip15
[17:32:32.796] INFO: safety margin for low PH: adding 0, margin is now 20
[17:32:32.802] INFO: safety margin for low PH: adding 0, margin is now 20
[17:32:32.809] INFO: safety margin for low PH: adding 0, margin is now 20
[17:32:32.815] INFO: safety margin for low PH: adding 0, margin is now 20
[17:32:32.822] INFO: safety margin for low PH: adding 0, margin is now 20
[17:32:32.830] INFO: safety margin for low PH: adding 0, margin is now 20
[17:32:32.838] INFO: safety margin for low PH: adding 0, margin is now 20
[17:32:32.844] INFO: safety margin for low PH: adding 0, margin is now 20
[17:32:32.852] INFO: safety margin for low PH: adding 0, margin is now 20
[17:32:32.858] INFO: safety margin for low PH: adding 0, margin is now 20
[17:32:32.864] INFO: safety margin for low PH: adding 0, margin is now 20
[17:32:32.871] INFO: safety margin for low PH: adding 0, margin is now 20
[17:32:32.877] INFO: safety margin for low PH: adding 0, margin is now 20
[17:32:32.884] INFO: safety margin for low PH: adding 0, margin is now 20
[17:32:32.890] INFO: safety margin for low PH: adding 1, margin is now 21
[17:32:32.896] INFO: safety margin for low PH: adding 2, margin is now 22
[17:32:32.903] INFO: safety margin for low PH: adding 3, margin is now 23
[17:32:32.909] INFO: safety margin for low PH: adding 4, margin is now 24
[17:32:32.915] INFO: safety margin for low PH: adding 0, margin is now 20
[17:32:32.922] INFO: safety margin for low PH: adding 0, margin is now 20
[17:32:32.928] DEBUG: <PixTestPhOptimization.cc/doTest:L172> optimisation done
[17:32:32.979] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//dacParameters35_C0.dat
[17:32:32.979] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//dacParameters35_C1.dat
[17:32:32.980] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//dacParameters35_C2.dat
[17:32:32.980] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//dacParameters35_C3.dat
[17:32:32.980] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//dacParameters35_C4.dat
[17:32:32.980] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//dacParameters35_C5.dat
[17:32:32.980] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//dacParameters35_C6.dat
[17:32:32.980] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//dacParameters35_C7.dat
[17:32:32.980] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//dacParameters35_C8.dat
[17:32:32.980] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//dacParameters35_C9.dat
[17:32:32.980] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//dacParameters35_C10.dat
[17:32:32.980] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//dacParameters35_C11.dat
[17:32:32.981] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//dacParameters35_C12.dat
[17:32:32.981] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//dacParameters35_C13.dat
[17:32:32.981] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//dacParameters35_C14.dat
[17:32:32.981] INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//dacParameters35_C15.dat
[17:32:36.676] INFO: Test took 3690ms.
[17:32:40.655] INFO: Test took 3696ms.
[17:32:44.669] INFO: Test took 3735ms.
[17:32:44.956] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:32:45.860] INFO: Test took 904ms.
[17:32:45.863] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:32:46.957] INFO: Test took 1095ms.
[17:32:46.961] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:32:48.055] INFO: Test took 1094ms.
[17:32:48.058] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:32:49.152] INFO: Test took 1094ms.
[17:32:49.156] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:32:50.250] INFO: Test took 1094ms.
[17:32:50.253] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:32:51.347] INFO: Test took 1094ms.
[17:32:51.350] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:32:52.442] INFO: Test took 1092ms.
[17:32:52.445] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:32:53.540] INFO: Test took 1095ms.
[17:32:53.544] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:32:54.636] INFO: Test took 1092ms.
[17:32:54.640] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:32:55.732] INFO: Test took 1092ms.
[17:32:55.735] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:32:56.829] INFO: Test took 1094ms.
[17:32:56.832] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:32:57.926] INFO: Test took 1094ms.
[17:32:57.929] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:32:59.023] INFO: Test took 1094ms.
[17:32:59.026] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:33:00.119] INFO: Test took 1093ms.
[17:33:00.123] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:33:01.216] INFO: Test took 1093ms.
[17:33:01.220] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:33:02.313] INFO: Test took 1094ms.
[17:33:02.316] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:33:03.409] INFO: Test took 1093ms.
[17:33:03.413] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:33:04.505] INFO: Test took 1092ms.
[17:33:04.509] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:33:05.602] INFO: Test took 1093ms.
[17:33:05.606] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:33:06.700] INFO: Test took 1095ms.
[17:33:06.704] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:33:07.794] INFO: Test took 1090ms.
[17:33:07.798] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:33:08.894] INFO: Test took 1097ms.
[17:33:08.897] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:33:09.990] INFO: Test took 1093ms.
[17:33:09.993] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:33:11.086] INFO: Test took 1093ms.
[17:33:11.089] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:33:12.181] INFO: Test took 1092ms.
[17:33:12.185] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:33:13.276] INFO: Test took 1091ms.
[17:33:13.280] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:33:14.370] INFO: Test took 1091ms.
[17:33:14.374] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:33:15.464] INFO: Test took 1090ms.
[17:33:15.468] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:33:16.558] INFO: Test took 1090ms.
[17:33:16.562] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:33:17.654] INFO: Test took 1092ms.
[17:33:17.658] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:33:18.750] INFO: Test took 1093ms.
[17:33:18.754] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:33:19.845] INFO: Test took 1091ms.
[17:33:20.443] INFO: PixTestPhOptimization::doTest() done, duration: 431 seconds
[17:33:20.443] INFO: PH scale (per ROC): 64 68 64 74 59 66 63 73 61 63 69 64 59 69 69 67
[17:33:20.443] INFO: PH offset (per ROC): 178 189 205 170 197 195 178 174 192 191 178 193 194 176 189 197
[17:33:20.588] DEBUG: <PixTestGainPedestal.cc/setParameter:L83> PixTestGainPedestal::PixTest() fVcalStep = 10
[17:33:20.590] INFO: ######################################################################
[17:33:20.590] INFO: PixTestGainPedestal::fullTest() ntrig = 10
[17:33:20.590] INFO: ######################################################################
[17:33:20.590] DEBUG: <PixTestGainPedestal.cc/measure:L192> using FLAGS = 16
[17:33:20.605] INFO: scanning low vcal = 10
[17:33:23.908] INFO: Test took 3303ms.
[17:33:23.913] INFO: scanning low vcal = 20
[17:33:27.220] INFO: Test took 3307ms.
[17:33:27.224] INFO: scanning low vcal = 30
[17:33:30.570] INFO: Test took 3346ms.
[17:33:30.580] INFO: scanning low vcal = 40
[17:33:34.317] INFO: Test took 3737ms.
[17:33:34.378] INFO: scanning low vcal = 50
[17:33:38.148] INFO: Test took 3770ms.
[17:33:38.207] INFO: scanning low vcal = 60
[17:33:41.984] INFO: Test took 3777ms.
[17:33:42.045] INFO: scanning low vcal = 70
[17:33:45.815] INFO: Test took 3770ms.
[17:33:45.875] INFO: scanning low vcal = 80
[17:33:49.656] INFO: Test took 3781ms.
[17:33:49.716] INFO: scanning low vcal = 90
[17:33:53.488] INFO: Test took 3772ms.
[17:33:53.547] INFO: scanning low vcal = 100
[17:33:57.337] INFO: Test took 3790ms.
[17:33:57.402] INFO: scanning low vcal = 110
[17:34:01.167] INFO: Test took 3765ms.
[17:34:01.226] INFO: scanning low vcal = 120
[17:34:05.016] INFO: Test took 3790ms.
[17:34:05.077] INFO: scanning low vcal = 130
[17:34:08.917] INFO: Test took 3840ms.
[17:34:08.976] INFO: scanning low vcal = 140
[17:34:12.849] INFO: Test took 3873ms.
[17:34:12.910] INFO: scanning low vcal = 150
[17:34:16.639] INFO: Test took 3729ms.
[17:34:16.697] INFO: scanning low vcal = 160
[17:34:20.503] INFO: Test took 3806ms.
[17:34:20.565] INFO: scanning low vcal = 170
[17:34:24.372] INFO: Test took 3807ms.
[17:34:24.434] INFO: scanning low vcal = 180
[17:34:28.234] INFO: Test took 3800ms.
[17:34:28.297] INFO: scanning low vcal = 190
[17:34:32.064] INFO: Test took 3767ms.
[17:34:32.124] INFO: scanning low vcal = 200
[17:34:35.904] INFO: Test took 3780ms.
[17:34:35.966] INFO: scanning low vcal = 210
[17:34:39.754] INFO: Test took 3788ms.
[17:34:39.816] INFO: scanning low vcal = 220
[17:34:43.608] INFO: Test took 3792ms.
[17:34:43.667] INFO: scanning low vcal = 230
[17:34:47.424] INFO: Test took 3757ms.
[17:34:47.485] INFO: scanning low vcal = 240
[17:34:51.255] INFO: Test took 3770ms.
[17:34:51.318] INFO: scanning low vcal = 250
[17:34:55.107] INFO: Test took 3789ms.
[17:34:55.172] INFO: scanning high vcal = 30 (= 210 in low range)
[17:34:58.943] INFO: Test took 3771ms.
[17:34:59.004] INFO: scanning high vcal = 50 (= 350 in low range)
[17:35:02.773] INFO: Test took 3768ms.
[17:35:02.834] INFO: scanning high vcal = 70 (= 490 in low range)
[17:35:06.605] INFO: Test took 3771ms.
[17:35:06.667] INFO: scanning high vcal = 90 (= 630 in low range)
[17:35:10.466] INFO: Test took 3799ms.
[17:35:10.526] INFO: scanning high vcal = 200 (= 1400 in low range)
[17:35:14.313] INFO: Test took 3787ms.
[17:35:14.860] INFO: PixTestGainPedestal::measure() done
[17:35:14.862] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C0
[17:35:14.862] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C1
[17:35:14.862] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C2
[17:35:14.862] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C3
[17:35:14.863] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C4
[17:35:14.863] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C5
[17:35:14.863] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C6
[17:35:14.863] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C7
[17:35:14.864] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C8
[17:35:14.864] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C9
[17:35:14.865] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C10
[17:35:14.865] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C11
[17:35:14.865] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C12
[17:35:14.865] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C13
[17:35:14.865] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C14
[17:35:14.866] DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C15
[17:35:44.859] INFO: PixTestGainPedestal::fit() done
[17:35:44.859] INFO: non-linearity mean: 0.961 0.949 0.953 0.959 0.955 0.962 0.957 0.950 0.958 0.947 0.960 0.955 0.962 0.961 0.958 0.949
[17:35:44.859] INFO: non-linearity RMS: 0.007 0.009 0.007 0.007 0.008 0.008 0.008 0.008 0.008 0.008 0.007 0.008 0.007 0.004 0.007 0.009
[17:35:44.859] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//phCalibrationFitErr35_C0.dat
[17:35:44.876] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//phCalibrationFitErr35_C1.dat
[17:35:44.893] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//phCalibrationFitErr35_C2.dat
[17:35:44.910] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//phCalibrationFitErr35_C3.dat
[17:35:44.927] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//phCalibrationFitErr35_C4.dat
[17:35:44.943] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//phCalibrationFitErr35_C5.dat
[17:35:44.960] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//phCalibrationFitErr35_C6.dat
[17:35:44.976] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//phCalibrationFitErr35_C7.dat
[17:35:44.993] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//phCalibrationFitErr35_C8.dat
[17:35:45.009] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//phCalibrationFitErr35_C9.dat
[17:35:45.026] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//phCalibrationFitErr35_C10.dat
[17:35:45.042] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//phCalibrationFitErr35_C11.dat
[17:35:45.059] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//phCalibrationFitErr35_C12.dat
[17:35:45.075] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//phCalibrationFitErr35_C13.dat
[17:35:45.092] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//phCalibrationFitErr35_C14.dat
[17:35:45.108] INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3015_FullQualification_2015-07-27_09h56m_1437983808//005_Fulltest_p17//phCalibrationFitErr35_C15.dat
[17:35:45.125] INFO: PixTestGainPedestal::doTest() done, duration: 144 seconds
[17:35:45.125] DEBUG: <PixTestGainPedestal.cc/~PixTestGainPedestal:L125> PixTestGainPedestal dtor
[17:35:45.131] DEBUG: <PixTestFullTest.cc/~PixTestFullTest:L78> PixTestFullTest dtor
[17:35:45.131] INFO: enter test to run
[17:35:45.131] INFO: test: q no parameter change
[17:35:45.131] DEBUG: <PixMonitor.cc/dumpSummaries:L34> PixMonitor::dumpSummaries
[17:35:45.240] QUIET: Connection to board 111 closed.
[17:35:45.241] INFO: pXar: this is the end, my friend
[17:35:45.241] DEBUG: <PixSetup.cc/~PixSetup:L68> PixSetup free fPxarMemory