MORE-Web

Test Date: 2015-07-30 09:25
Analysis date: 2015-10-28 15:12
Logfile
LogfileView
[09:20:14.265]     INFO: *** Welcome to pxar ***

[09:20:14.265]     INFO: *** Today: 2015/07/31

[09:20:14.265]     INFO: readRocDacs: /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters_C0.dat .. /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters_C15.dat

[09:20:14.265]     INFO: readTbmDacs: /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//tbmParameters_C0a.dat .. /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//tbmParameters_C0b.dat

[09:20:14.265]     INFO: readMaskFile: /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//defaultMaskFile.dat

[09:20:14.266]     INFO: readTrimFile: /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//trimParameters_C0.dat .. /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//trimParameters_C15.dat

[09:20:14.325]     INFO:         clk: 4

[09:20:14.325]     INFO:         ctr: 4

[09:20:14.325]     INFO:         sda: 19

[09:20:14.325]     INFO:         tin: 9

[09:20:14.325]     INFO:         level: 15

[09:20:14.325]     INFO:         triggerdelay: 0

[09:20:14.325]    QUIET: Instanciating API for pxar v2.2.5+67~g3b1c276

[09:20:14.325]     INFO: Log level: DEBUG

[09:20:14.333]     INFO: Found DTB DTB_WV5QFZ

[09:20:14.344]    QUIET: Connection to board DTB_WV5QFZ opened.

[09:20:14.347]     INFO: DTB startup information

--- DTB info------------------------------------------

Board id:    98

HW version:  DTB1.2

FW version:  4.2

SW version:  4.2

USB id:      DTB_WV5QFZ

MAC address: 40D855118062

Hostname:    pixelDTB098

Comment:     with CMOS buffer

------------------------------------------------------

[09:20:14.350]     INFO: RPC call hashes of host and DTB match: 447413373

[09:20:15.938]     INFO: DUT info: 

[09:20:15.938]     INFO: The DUT currently contains the following objects:

[09:20:15.938]     INFO:  2 TBM Cores tbm08c (2 ON)

[09:20:15.938]     INFO: 	TBM Core alpha (0): 7 registers set

[09:20:15.938]     INFO: 	TBM Core beta  (1): 7 registers set

[09:20:15.938]     INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs

[09:20:15.938]     INFO: 	ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.

[09:20:15.938]     INFO: 	ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.

[09:20:15.938]     INFO: 	ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.

[09:20:15.938]     INFO: 	ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.

[09:20:15.938]     INFO: 	ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.

[09:20:15.938]     INFO: 	ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.

[09:20:15.938]     INFO: 	ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.

[09:20:15.938]     INFO: 	ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.

[09:20:15.938]     INFO: 	ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.

[09:20:15.938]     INFO: 	ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.

[09:20:15.938]     INFO: 	ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.

[09:20:15.938]     INFO: 	ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.

[09:20:15.938]     INFO: 	ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.

[09:20:15.938]     INFO: 	ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.

[09:20:15.938]     INFO: 	ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.

[09:20:15.938]     INFO: 	ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->BB<-

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   dumpall: checkbox(0)

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   dumpproblematic: checkbox(0)

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   ntrig: 5

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   vcals: 250

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->BB2<-

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   ntrig: 10

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   vcals: 222

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   plwidth: 35

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   pix: 11,20

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   targetia: 24

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->BB3<-

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   dumpall: checkbox(0)

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   dumpproblematic: checkbox(0)

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   ntrig: 5

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   vcals: 250

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Cmd<-

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->DacDacScan<-

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   phmap: checkbox

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   ntrig: 10

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   dac1: caldel

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   dac1lo: 0

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   dac1hi: 255

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   dac2: vthrcomp

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   dac2lo: 0

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   dac2hi: 255

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   pix: 11,20

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->DacScan<-

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   phmap: checkbox(1)

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   allpixels: checkbox(0)

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   unmasked: checkbox(0)

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   ntrig: 10

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   dac: vcal

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   daclo: 0

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   dachi: 255

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   pix: 11,20

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->GainPedestal<-

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   showfits: checkbox(0)

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   extended: checkbox(0)

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   dumphists: checkbox(0)

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   ntrig: 10

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   vcalstep: 10

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   measure: button

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   fit: button

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   save: button

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->HighRate<-

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   pix: 11,20

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   maskhotpixels: button

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   savemaskfile: checkbox(0)

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   maskfilename: default

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   caldelscan: button

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   xpixelalive: button

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   ntrig: 50

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   vcal: 200

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   xnoisemaps: button

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   daclo: 0

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   dachi: 100

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   dacs/step: 20

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   rundaq: button

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   trgfrequency(khz): 20

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   runseconds: 2

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   triggerdelay: 20

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   delaytbm: checkbox

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   filltree: checkbox

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->IV<-

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   port: /dev/FIXME

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   voltagestart: 0

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   voltagestop: 600

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   voltagestep: 5

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   delay: 1

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   compliance(ua): 100

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->PhOptimization<-

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   ntrig: 10

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   safetymarginlow: 20

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   saturationvcal: 100

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   quantilesaturation: 0.98

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->PixelAlive<-

[09:20:15.939]    DEBUG: <PixTestParameters.cc/dump:L107>   ntrig: 10

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   vcal: 200

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   alivetest: button

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   masktest: button

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   addressdecodingtest: button

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Pretest<-

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   programroc: button

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   targetia: 24

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   setvana: button

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   iterations: 100

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   settimings: button

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   findworkingpixel: button

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   setvthrcompcaldel: button

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   pix: 11,20

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   vcal: 250

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   deltavthrcomp: 50

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   fraccaldel: 0.5

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   ntrig: 5

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   savedacs: button

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Readback<-

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   calibratevd: button

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   calibrateva: button

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   calibrateia: button

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   readbackvbg: button

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   getcalibratedvbg: button

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   usecalvd: checkbox(1)

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   usecalva: checkbox(0)

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   setvana: button

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Scurves<-

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   adjustvcal: checkbox(1)

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   dumpall: checkbox(0)

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   dumpproblematic: checkbox(0)

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   dumpoutputfile: checkbox(0)

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   ntrig: 50

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   dac: VthrComp

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   daclo: 0

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   dachi: 200

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   dacs/step: 10

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   scurves: button

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Timing<-

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   fastscan: checkbox(0)

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   targetclk: 4

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   ntrig: 10

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   clocksdascan: button

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   phasescan: button

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   levelscan: button

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   tbmphasescan: button

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   rocdelayscan: button

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   timingtest: button

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   saveparameters: button

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Trim<-

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   trim: button

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   ntrig: 10

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   vcal: 35

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   trimbits: button

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Xray<-

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   maskhotpixels: button

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   savemaskfile: checkbox(0)

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   maskfilename: default

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   source: Ag

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   phrun: button

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   runseconds: 100

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   trgfrequency(khz): 100

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   ratescan: button

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   vthrcompmin: 10

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   vthrcompmax: 80

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   stepseconds: 5

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   delaytbm: checkbox

[09:20:15.940]    DEBUG: <PixTestParameters.cc/dump:L107>   filltree: checkbox

[09:20:15.940]    DEBUG: <PixSetup.cc/init:L81> PixSetup init start; getCurrentRSS() = 32817152

[09:20:15.940]    DEBUG: <PixSetup.cc/init:L87> fPixTestParameters = 0x137bbe0

[09:20:15.940]    DEBUG: <PixSetup.cc/init:L88>  fConfigParameters = 0x12a09c0

[09:20:15.940]    DEBUG: <PixSetup.cc/init:L89>        fPxarMemory = 0x7ff051d94010

[09:20:15.940]    DEBUG: <PixSetup.cc/init:L90>         fPxarMemHi = 0x7ff057fff510

[09:20:15.940]    DEBUG: <PixSetup.cc/init:L106> PixSetup init done;  getCurrentRSS() = 32878592 fPxarMemory = 0x7ff051d94010

[09:20:15.940]    DEBUG: <PixTestFactory.cc/PixTestFactory:L52> PixTestFactory::PixTestFactory()

[09:20:16.341]     INFO: enter 'restricted' command line mode

[09:20:16.341]     INFO: enter test to run

[09:20:16.341]     INFO:   test: Pretest no parameter change

[09:20:16.341]     INFO:   running: pretest

[09:20:16.347]     INFO: ######################################################################

[09:20:16.347]     INFO: PixTestPretest::doTest()

[09:20:16.347]     INFO: ######################################################################

[09:20:16.349]     INFO:    ----------------------------------------------------------------------

[09:20:16.349]     INFO:    PixTestPretest::programROC() 

[09:20:16.349]     INFO:    ----------------------------------------------------------------------

[09:20:34.372]     INFO: PixTestPretest::programROC() done: ROCs are all programmable

[09:20:34.372]     INFO: IA differences per ROC:  18.5 16.9 18.5 17.7 15.3 20.9 19.3 18.5 18.5 20.1 17.7 20.1 17.7 18.5 20.1 19.3

[09:20:34.442]     INFO:    ----------------------------------------------------------------------

[09:20:34.442]     INFO:    PixTestPretest::setVana() target Ia = 24 mA/ROC

[09:20:34.442]     INFO:    ----------------------------------------------------------------------

[09:20:34.545]    DEBUG: <PixTestPretest.cc/setVana:L254> offset current from other 15 ROCs is 69.2812 mA

[09:20:34.646]    DEBUG: <PixTestPretest.cc/setVana:L280> ROC 0 iter 0 Vana 78 Ia 22.3188 mA

[09:20:34.747]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC  0 iter  1 Vana  88 Ia 24.7188 mA

[09:20:34.848]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC  0 iter  2 Vana  85 Ia 23.9188 mA

[09:20:34.949]    DEBUG: <PixTestPretest.cc/setVana:L280> ROC 1 iter 0 Vana 78 Ia 20.7188 mA

[09:20:35.050]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC  1 iter  1 Vana  98 Ia 24.7188 mA

[09:20:35.151]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC  1 iter  2 Vana  95 Ia 23.9188 mA

[09:20:35.252]    DEBUG: <PixTestPretest.cc/setVana:L280> ROC 2 iter 0 Vana 78 Ia 23.1188 mA

[09:20:35.353]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC  2 iter  1 Vana  83 Ia 24.7188 mA

[09:20:35.453]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC  2 iter  2 Vana  80 Ia 23.9188 mA

[09:20:35.555]    DEBUG: <PixTestPretest.cc/setVana:L280> ROC 3 iter 0 Vana 78 Ia 20.7188 mA

[09:20:35.656]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC  3 iter  1 Vana  98 Ia 24.7188 mA

[09:20:35.756]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC  3 iter  2 Vana  95 Ia 24.7188 mA

[09:20:35.857]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC  3 iter  3 Vana  92 Ia 23.9188 mA

[09:20:35.958]    DEBUG: <PixTestPretest.cc/setVana:L280> ROC 4 iter 0 Vana 78 Ia 19.9188 mA

[09:20:36.059]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC  4 iter  1 Vana 103 Ia 23.9188 mA

[09:20:36.160]    DEBUG: <PixTestPretest.cc/setVana:L280> ROC 5 iter 0 Vana 78 Ia 24.7188 mA

[09:20:36.261]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC  5 iter  1 Vana  75 Ia 23.9188 mA

[09:20:36.362]    DEBUG: <PixTestPretest.cc/setVana:L280> ROC 6 iter 0 Vana 78 Ia 23.9188 mA

[09:20:36.464]    DEBUG: <PixTestPretest.cc/setVana:L280> ROC 7 iter 0 Vana 78 Ia 22.3188 mA

[09:20:36.565]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC  7 iter  1 Vana  88 Ia 24.7188 mA

[09:20:36.666]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC  7 iter  2 Vana  85 Ia 24.7188 mA

[09:20:36.767]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC  7 iter  3 Vana  82 Ia 23.9188 mA

[09:20:36.868]    DEBUG: <PixTestPretest.cc/setVana:L280> ROC 8 iter 0 Vana 78 Ia 22.3188 mA

[09:20:36.969]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC  8 iter  1 Vana  88 Ia 23.9188 mA

[09:20:37.071]    DEBUG: <PixTestPretest.cc/setVana:L280> ROC 9 iter 0 Vana 78 Ia 23.9188 mA

[09:20:37.173]    DEBUG: <PixTestPretest.cc/setVana:L280> ROC 10 iter 0 Vana 78 Ia 22.3188 mA

[09:20:37.273]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC 10 iter  1 Vana  88 Ia 23.9188 mA

[09:20:37.375]    DEBUG: <PixTestPretest.cc/setVana:L280> ROC 11 iter 0 Vana 78 Ia 23.9188 mA

[09:20:37.476]    DEBUG: <PixTestPretest.cc/setVana:L280> ROC 12 iter 0 Vana 78 Ia 20.7188 mA

[09:20:37.576]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter  1 Vana  98 Ia 25.5188 mA

[09:20:37.677]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter  2 Vana  90 Ia 23.1188 mA

[09:20:37.778]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter  3 Vana  95 Ia 24.7188 mA

[09:20:37.879]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter  4 Vana  92 Ia 23.9188 mA

[09:20:37.980]    DEBUG: <PixTestPretest.cc/setVana:L280> ROC 13 iter 0 Vana 78 Ia 22.3188 mA

[09:20:38.081]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter  1 Vana  88 Ia 24.7188 mA

[09:20:38.182]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter  2 Vana  85 Ia 24.7188 mA

[09:20:38.282]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter  3 Vana  82 Ia 23.9188 mA

[09:20:38.383]    DEBUG: <PixTestPretest.cc/setVana:L280> ROC 14 iter 0 Vana 78 Ia 23.1188 mA

[09:20:38.484]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter  1 Vana  83 Ia 24.7188 mA

[09:20:38.585]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter  2 Vana  80 Ia 24.7188 mA

[09:20:38.686]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter  3 Vana  77 Ia 23.1188 mA

[09:20:38.787]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter  4 Vana  82 Ia 24.7188 mA

[09:20:38.888]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter  5 Vana  79 Ia 23.9188 mA

[09:20:38.990]    DEBUG: <PixTestPretest.cc/setVana:L280> ROC 15 iter 0 Vana 78 Ia 23.1188 mA

[09:20:39.090]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter  1 Vana  83 Ia 24.7188 mA

[09:20:39.191]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC 15 iter  2 Vana  80 Ia 23.9188 mA

[09:20:39.238]    DEBUG: <PixTestPretest.cc/setVana:L343> ROC  0 Vana  85

[09:20:39.238]    DEBUG: <PixTestPretest.cc/setVana:L343> ROC  1 Vana  95

[09:20:39.238]    DEBUG: <PixTestPretest.cc/setVana:L343> ROC  2 Vana  80

[09:20:39.238]    DEBUG: <PixTestPretest.cc/setVana:L343> ROC  3 Vana  92

[09:20:39.238]    DEBUG: <PixTestPretest.cc/setVana:L343> ROC  4 Vana 103

[09:20:39.239]    DEBUG: <PixTestPretest.cc/setVana:L343> ROC  5 Vana  75

[09:20:39.239]    DEBUG: <PixTestPretest.cc/setVana:L343> ROC  6 Vana  78

[09:20:39.239]    DEBUG: <PixTestPretest.cc/setVana:L343> ROC  7 Vana  82

[09:20:39.239]    DEBUG: <PixTestPretest.cc/setVana:L343> ROC  8 Vana  88

[09:20:39.240]    DEBUG: <PixTestPretest.cc/setVana:L343> ROC  9 Vana  78

[09:20:39.240]    DEBUG: <PixTestPretest.cc/setVana:L343> ROC 10 Vana  88

[09:20:39.240]    DEBUG: <PixTestPretest.cc/setVana:L343> ROC 11 Vana  78

[09:20:39.240]    DEBUG: <PixTestPretest.cc/setVana:L343> ROC 12 Vana  92

[09:20:39.240]    DEBUG: <PixTestPretest.cc/setVana:L343> ROC 13 Vana  82

[09:20:39.240]    DEBUG: <PixTestPretest.cc/setVana:L343> ROC 14 Vana  79

[09:20:39.241]    DEBUG: <PixTestPretest.cc/setVana:L343> ROC 15 Vana  80

[09:20:39.343]     INFO: PixTestPretest::setVana() done, Module Ia 389.9 mA = 24.3688 mA/ROC

[09:20:39.345]     INFO:    ----------------------------------------------------------------------

[09:20:39.345]     INFO:    PixTestPreTest::setTimings()

[09:20:39.345]     INFO:    ----------------------------------------------------------------------

[09:20:39.345]    DEBUG: <PixTestPretest.cc/setTimings:L392> Testing Timing: Attempt #1

[09:20:40.343]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:20:40.344]     INFO: Decoding statistics:

[09:20:40.344]     INFO:   General information:

[09:20:40.344]     INFO: 	 16bit words read:         120

[09:20:40.344]     INFO: 	 valid events total:       10

[09:20:40.344]     INFO: 	 empty events:             10

[09:20:40.344]     INFO: 	 valid events with pixels: 0

[09:20:40.344]     INFO: 	 valid pixel hits:         0

[09:20:40.344]     INFO:   Event errors: 	           0

[09:20:40.344]     INFO: 	 start marker:             0

[09:20:40.344]     INFO: 	 stop marker:              0

[09:20:40.344]     INFO: 	 overflow:                 0

[09:20:40.344]     INFO: 	 invalid 5bit words:       0

[09:20:40.344]     INFO: 	 invalid XOR eye diagram:  0

[09:20:40.344]     INFO:   TBM errors: 		           0

[09:20:40.344]     INFO: 	 flawed TBM headers:       0

[09:20:40.344]     INFO: 	 flawed TBM trailers:      0

[09:20:40.344]     INFO: 	 event ID mismatches:      0

[09:20:40.344]     INFO:   ROC errors: 		           0

[09:20:40.344]     INFO: 	 missing ROC header(s):    0

[09:20:40.344]     INFO: 	 misplaced readback start: 0

[09:20:40.344]     INFO:   Pixel decoding errors:	   0

[09:20:40.344]     INFO: 	 pixel data incomplete:    0

[09:20:40.344]     INFO: 	 pixel address:            0

[09:20:40.344]     INFO: 	 pulse height fill bit:    0

[09:20:40.344]     INFO: 	 buffer corruption:        0

[09:20:40.344]     INFO:    ----------------------------------------------------------------------

[09:20:40.344]     INFO:    Default timings are good. No timing scan needed.

[09:20:40.344]     INFO:    ----------------------------------------------------------------------

[09:20:40.344]     INFO: Test took 999 ms.

[09:20:40.344]     INFO: PixTestPretest::setTimings() done.

[09:20:40.604]     INFO:    ----------------------------------------------------------------------

[09:20:40.604]     INFO:    PixTestPretest::findWorkingPixel()

[09:20:40.604]     INFO:    ----------------------------------------------------------------------

[09:20:48.553]     INFO: Test took 7947ms.

[09:20:48.848]    DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C0 OK, with vthrComp = 100 and Delta(CalDel) = 58

[09:20:48.851]    DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C1 OK, with vthrComp = 86 and Delta(CalDel) = 61

[09:20:48.853]    DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C2 OK, with vthrComp = 107 and Delta(CalDel) = 63

[09:20:48.855]    DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C3 OK, with vthrComp = 109 and Delta(CalDel) = 59

[09:20:48.858]    DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C4 OK, with vthrComp = 103 and Delta(CalDel) = 52

[09:20:48.860]    DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C5 OK, with vthrComp = 92 and Delta(CalDel) = 60

[09:20:48.862]    DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C6 OK, with vthrComp = 113 and Delta(CalDel) = 63

[09:20:48.865]    DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C7 OK, with vthrComp = 79 and Delta(CalDel) = 60

[09:20:48.867]    DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C8 OK, with vthrComp = 74 and Delta(CalDel) = 62

[09:20:48.870]    DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C9 OK, with vthrComp = 94 and Delta(CalDel) = 57

[09:20:48.872]    DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C10 OK, with vthrComp = 102 and Delta(CalDel) = 58

[09:20:48.875]    DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C11 OK, with vthrComp = 110 and Delta(CalDel) = 57

[09:20:48.877]    DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C12 OK, with vthrComp = 109 and Delta(CalDel) = 59

[09:20:48.879]    DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C13 OK, with vthrComp = 97 and Delta(CalDel) = 60

[09:20:48.882]    DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C14 OK, with vthrComp = 94 and Delta(CalDel) = 59

[09:20:48.884]    DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C15 OK, with vthrComp = 83 and Delta(CalDel) = 57

[09:20:48.909]     INFO: Found working pixel in all ROCs: col/row = 12/22

[09:20:48.964]     INFO:    ----------------------------------------------------------------------

[09:20:48.964]     INFO:    PixTestPretest::setVthrCompCalDel()

[09:20:48.964]     INFO:    ----------------------------------------------------------------------

[09:20:57.062]     INFO: Test took 8092ms.

[09:20:57.119]    DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 125 +/- 29.5

[09:20:57.360]    DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 127 +/- 30

[09:20:57.362]    DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 130 +/- 31.5

[09:20:57.365]    DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 126 +/- 30

[09:20:57.367]    DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 93 +/- 27.5

[09:20:57.369]    DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 129 +/- 30.5

[09:20:57.372]    DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 131 +/- 31

[09:20:57.374]    DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 120 +/- 29

[09:20:57.376]    DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 138 +/- 31.5

[09:20:57.378]    DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 109 +/- 29

[09:20:57.380]    DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 110 +/- 30.5

[09:20:57.383]    DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 113 +/- 30

[09:20:57.385]    DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 104 +/- 28

[09:20:57.387]    DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 103 +/- 28

[09:20:57.390]    DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 117 +/- 28

[09:20:57.392]    DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 122 +/- 28.5

[09:20:57.444]     INFO: PixTestPretest::setVthrCompCalDel() done

[09:20:57.444]     INFO: CalDel:      125   127   130   126    93   129   131   120   138   109   110   113   104   103   117   122

[09:20:57.444]     INFO: VthrComp:     51    51    51    51    51    51    51    51    51    51    54    51    51    51    51    51

[09:20:57.447]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters_C0.dat

[09:20:57.447]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters_C1.dat

[09:20:57.447]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters_C2.dat

[09:20:57.447]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters_C3.dat

[09:20:57.448]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters_C4.dat

[09:20:57.448]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters_C5.dat

[09:20:57.448]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters_C6.dat

[09:20:57.448]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters_C7.dat

[09:20:57.448]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters_C8.dat

[09:20:57.448]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters_C9.dat

[09:20:57.448]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters_C10.dat

[09:20:57.448]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters_C11.dat

[09:20:57.448]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters_C12.dat

[09:20:57.449]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters_C13.dat

[09:20:57.449]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters_C14.dat

[09:20:57.449]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters_C15.dat

[09:20:57.449]     INFO: PixTestPretest::doTest() done, duration: 41 seconds

[09:20:57.449]    DEBUG: <PixTestPretest.cc/~PixTestPretest:L134> PixTestPretest dtor

[09:20:57.523]     INFO: enter test to run

[09:20:57.523]     INFO:   test: Fulltest no parameter change

[09:20:57.523]     INFO:   running: fulltest

[09:20:57.523]    DEBUG: <PixTestFullTest.cc/init:L49> PixTestFullTest::init()

[09:20:57.523]    DEBUG: <PixTestFullTest.cc/PixTestFullTest:L20> PixTestFullTest ctor(PixSetup &a, string, TGTab *)

[09:20:57.523]     INFO: ######################################################################

[09:20:57.523]     INFO: PixTestFullTest::doTest()

[09:20:57.523]     INFO: ######################################################################

[09:20:57.523]    DEBUG: <PixTestAlive.cc/init:L77> PixTestAlive::init()

[09:20:57.523]    DEBUG: <PixTestAlive.cc/PixTestAlive:L21> PixTestAlive ctor(PixSetup &a, string, TGTab *)

[09:20:57.525]     INFO: ######################################################################

[09:20:57.525]     INFO: PixTestAlive::doTest()

[09:20:57.525]     INFO: ######################################################################

[09:20:57.527]     INFO:    ----------------------------------------------------------------------

[09:20:57.527]     INFO:    PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)

[09:20:57.527]     INFO:    ----------------------------------------------------------------------

[09:20:57.529]    DEBUG: <PixTest.cc/efficiencyMaps:L328>       attempt #0

[09:21:01.499]     INFO: Test took 3970ms.

[09:21:01.520]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:21:01.520]    DEBUG: <PixTest.cc/efficiencyMaps:L339>  eff result size = 66546

[09:21:01.520]    DEBUG: <PixTest.cc/efficiencyMaps:L344> Create hists PixelAlive_C0 .. PixelAlive_C15

[09:21:01.827]     INFO: PixTestAlive::aliveTest() done

[09:21:01.827]     INFO: number of dead pixels (per ROC):     0    0    1    0    0    0    4    5    3    1    0    0    0    0    0    0

[09:21:01.828]    DEBUG: <PixTestAlive.cc/aliveTest:L188> number of red-efficiency pixels:     0    0    1    0    0    0    4    5    3    1    0    0    0    0    0    0

[09:21:01.829]     INFO:    ----------------------------------------------------------------------

[09:21:01.829]     INFO:    PixTestAlive::maskTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)

[09:21:01.829]     INFO:    ----------------------------------------------------------------------

[09:21:01.831]    DEBUG: <PixTest.cc/efficiencyMaps:L328>       attempt #0

[09:21:04.728]     INFO: Test took 2897ms.

[09:21:04.731]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:21:04.731]    DEBUG: <PixTest.cc/efficiencyMaps:L339>  eff result size = 0

[09:21:04.731]    DEBUG: <PixTest.cc/efficiencyMaps:L344> Create hists MaskTest_C0 .. MaskTest_C15

[09:21:04.731]     INFO: mask vs. old pixelAlive PixelAlive_C0_V0 ..  PixelAlive_C15_V0

[09:21:05.038]     INFO: PixTestAlive::maskTest() done

[09:21:05.038]     INFO: number of mask-defect pixels (per ROC):     0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0

[09:21:05.040]     INFO:    ----------------------------------------------------------------------

[09:21:05.040]     INFO:    PixTestAlive::addressDecodingTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)

[09:21:05.040]     INFO:    ----------------------------------------------------------------------

[09:21:05.042]    DEBUG: <PixTest.cc/efficiencyMaps:L328>       attempt #0

[09:21:08.988]     INFO: Test took 3946ms.

[09:21:09.010]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:21:09.010]    DEBUG: <PixTest.cc/efficiencyMaps:L339>  eff result size = 66546

[09:21:09.010]    DEBUG: <PixTest.cc/efficiencyMaps:L344> Create hists AddressDecodingTest_C0 .. AddressDecodingTest_C15

[09:21:09.319]     INFO: PixTestAlive::addressDecodingTest() done

[09:21:09.319]     INFO: number of address-decoding pixels (per ROC):     0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0

[09:21:09.319]     INFO: PixTestAlive::doTest() done, duration: 11 seconds

[09:21:09.319]    DEBUG: <PixTestAlive.cc/~PixTestAlive:L109> PixTestAlive dtor

[09:21:09.326]    DEBUG: <PixTestBBMap.cc/init:L79> PixTestBBMap::init()

[09:21:09.326]    DEBUG: <PixTestBBMap.cc/PixTestBBMap:L27> PixTestBBMap ctor(PixSetup &a, string, TGTab *)

[09:21:09.328]     INFO: ######################################################################

[09:21:09.328]     INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)

[09:21:09.328]     INFO: ######################################################################

[09:21:09.332]     INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (30) hits flags = 2 (plus default)

[09:21:09.347]     INFO:   dacScan step  from 0 .. 29

[09:21:09.347]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:21:29.250]     INFO: Test took 19903ms.

[09:21:29.287]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:21:29.287]     INFO:   dacScan step  from 30 .. 59

[09:21:29.287]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:21:51.351]     INFO: Test took 22064ms.

[09:21:51.492]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:21:51.520]     INFO:   dacScan step  from 60 .. 89

[09:21:51.520]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:22:18.143]     INFO: Test took 26623ms.

[09:22:18.397]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:22:18.479]     INFO:   dacScan step  from 90 .. 119

[09:22:18.479]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:22:45.326]     INFO: Test took 26847ms.

[09:22:45.579]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:22:45.663]     INFO:   dacScan step  from 120 .. 149

[09:22:45.663]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:23:10.125]     INFO: Test took 24462ms.

[09:23:10.349]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:23:10.409]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0

[09:23:11.682]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1

[09:23:12.969]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2

[09:23:14.269]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3

[09:23:15.550]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4

[09:23:16.886]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5

[09:23:18.218]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6

[09:23:19.651]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7

[09:23:20.897]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8

[09:23:22.135]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9

[09:23:23.425]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10

[09:23:24.746]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11

[09:23:26.070]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12

[09:23:27.376]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13

[09:23:28.644]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14

[09:23:29.948]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15

[09:23:31.209]    DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 261038080

[09:23:31.256]    DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C0_V0

[09:23:31.257]    DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 80 (obtained for minval = 0) start: 77 .. 92 last peak: 49.0313 last sigma: 4.3233 lcuts[0] = 62.0012 lcuts[1] = 92.2643

[09:23:31.257]    DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C1_V0

[09:23:31.258]    DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 87 (obtained for minval = 0) start: 87 .. 105 last peak: 54.8095 last sigma: 5.0915 lcuts[0] = 70.084 lcuts[1] = 105.725

[09:23:31.258]    DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C2_V0

[09:23:31.258]    DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 90 (obtained for minval = 0) start: 90 .. 109 last peak: 54.0289 last sigma: 5.55537 lcuts[0] = 70.695 lcuts[1] = 109.583

[09:23:31.259]    DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C3_V0

[09:23:31.259]    DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 83 (obtained for minval = 0) start: 83 .. 100 last peak: 51.4381 last sigma: 4.93374 lcuts[0] = 66.2393 lcuts[1] = 100.775

[09:23:31.259]    DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C4_V0

[09:23:31.260]    DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 78 (obtained for minval = 0) start: 78 .. 94 last peak: 48.7478 last sigma: 4.55081 lcuts[0] = 62.4002 lcuts[1] = 94.2559

[09:23:31.260]    DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C5_V0

[09:23:31.260]    DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 72 (obtained for minval = 0) start: 71 .. 85 last peak: 46.0079 last sigma: 3.98992 lcuts[0] = 57.9776 lcuts[1] = 85.9071

[09:23:31.261]    DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C6_V0

[09:23:31.261]    DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 78 (obtained for minval = 0) start: 78 .. 94 last peak: 48.1445 last sigma: 4.62118 lcuts[0] = 62.008 lcuts[1] = 94.3562

[09:23:31.261]    DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C7_V0

[09:23:31.261]    DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 75 (obtained for minval = 0) start: 72 .. 85 last peak: 46.9495 last sigma: 3.87465 lcuts[0] = 58.5734 lcuts[1] = 85.696

[09:23:31.262]    DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C8_V0

[09:23:31.262]    DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 77 (obtained for minval = 0) start: 74 .. 88 last peak: 46.3295 last sigma: 4.25938 lcuts[0] = 59.1077 lcuts[1] = 88.9234

[09:23:31.262]    DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C9_V0

[09:23:31.263]    DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 92 (obtained for minval = 0) start: 92 .. 112 last peak: 54.3005 last sigma: 5.86866 lcuts[0] = 71.9065 lcuts[1] = 112.987

[09:23:31.263]    DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C10_V0

[09:23:31.263]    DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 105 (obtained for minval = 0) start: 105 .. 128 last peak: 61.3577 last sigma: 6.75929 lcuts[0] = 81.6355 lcuts[1] = 128.951

[09:23:31.264]    DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C11_V0

[09:23:31.264]    DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 97 (obtained for minval = 0) start: 97 .. 117 last peak: 58.893 last sigma: 5.87048 lcuts[0] = 76.5045 lcuts[1] = 117.598

[09:23:31.264]    DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C12_V0

[09:23:31.265]    DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 87 (obtained for minval = 0) start: 87 .. 105 last peak: 52.8434 last sigma: 5.26558 lcuts[0] = 68.6402 lcuts[1] = 105.499

[09:23:31.265]    DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C13_V0

[09:23:31.265]    DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 77 (obtained for minval = 0) start: 77 .. 93 last peak: 47.0536 last sigma: 4.67861 lcuts[0] = 61.0894 lcuts[1] = 93.8396

[09:23:31.265]    DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C14_V0

[09:23:31.266]    DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 89 (obtained for minval = 0) start: 89 .. 108 last peak: 53.3792 last sigma: 5.54178 lcuts[0] = 70.0046 lcuts[1] = 108.797

[09:23:31.266]    DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C15_V0

[09:23:31.267]    DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 84 (obtained for minval = 0) start: 82 .. 99 last peak: 49.6841 last sigma: 5.02042 lcuts[0] = 64.7453 lcuts[1] = 99.8883

[09:23:31.268]     INFO: PixTestBBMap::doTest() done, duration: 141 seconds

[09:23:31.268]     INFO: number of dead bumps (per ROC):     1    0    0    1    0    3    1    1    2    1    0    0    0    2    0    2

[09:23:31.268]     INFO: separation cut       (per ROC):    81   88   91   84   79   73   79   76   78   93  106   98   88   78   90   85

[09:23:31.268]    DEBUG: <PixTestBBMap.cc/~PixTestBBMap:L97> PixTestBBMap dtor

[09:23:31.340]    DEBUG: <PixTestScurves.cc/setParameter:L92> set fOutputFilename = 

[09:23:31.341]     INFO: ######################################################################

[09:23:31.341]     INFO: PixTestScurves::fullTest() ntrig = 50

[09:23:31.341]     INFO: ######################################################################

[09:23:31.341]     INFO:    ----------------------------------------------------------------------

[09:23:31.341]     INFO:    PixTestScurves::scurves(Vcal), ntrig = 50

[09:23:31.341]     INFO:    ----------------------------------------------------------------------

[09:23:31.342]     INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 0 .. 149 (10) hits flags = 16 (plus default)

[09:23:31.350]     INFO:   dacScan step  from 0 .. 9

[09:23:31.351]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:24:06.569]     INFO: Test took 35218ms.

[09:24:06.637]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:24:06.637]     INFO:   dacScan step  from 10 .. 19

[09:24:06.637]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:24:41.801]     INFO: Test took 35164ms.

[09:24:41.869]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:24:41.869]     INFO:   dacScan step  from 20 .. 29

[09:24:41.869]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:25:17.253]     INFO: Test took 35384ms.

[09:25:17.318]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:25:17.318]     INFO:   dacScan step  from 30 .. 39

[09:25:17.319]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:25:52.556]     INFO: Test took 35237ms.

[09:25:52.625]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:25:52.625]     INFO:   dacScan step  from 40 .. 49

[09:25:52.625]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:26:27.714]     INFO: Test took 35089ms.

[09:26:27.779]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:26:27.779]     INFO:   dacScan step  from 50 .. 59

[09:26:27.780]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:27:03.012]     INFO: Test took 35232ms.

[09:27:03.079]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:27:03.079]     INFO:   dacScan step  from 60 .. 69

[09:27:03.079]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:27:38.150]     INFO: Test took 35071ms.

[09:27:38.216]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:27:38.216]     INFO:   dacScan step  from 70 .. 79

[09:27:38.216]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:28:13.522]     INFO: Test took 35306ms.

[09:28:13.591]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:28:13.591]     INFO:   dacScan step  from 80 .. 89

[09:28:13.592]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:28:49.187]    ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 1 Number of ROCs (12) != Token Chain Length (8)

[09:28:49.187]    ERROR: <datapipe.cc/CheckEventID:L420> Channel 1 Event ID mismatch:  local ID (115) !=  TBM ID (116)

[09:28:49.187]  WARNING: Channel 1 ROC 1: Readback start marker after 15 readouts!

[09:28:49.187]  WARNING: Channel 1 ROC 2: Readback start marker after 15 readouts!

[09:28:49.187]  WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!

[09:28:49.187]  WARNING: Channel 1 ROC 4: Readback start marker after 15 readouts!

[09:28:49.187]  WARNING: Channel 1 ROC 5: Readback start marker after 15 readouts!

[09:28:49.187]  WARNING: Channel 1 ROC 6: Readback start marker after 15 readouts!

[09:28:49.187]  WARNING: Channel 1 ROC 7: Readback start marker after 15 readouts!

[09:28:49.228]     INFO: Test took 35636ms.

[09:28:49.336]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:28:49.339]     INFO:   dacScan step  from 90 .. 99

[09:28:49.339]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:29:26.381]    ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 1 Number of ROCs (2) != Token Chain Length (8)

[09:29:26.381]  WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!

[09:29:26.381]  WARNING: Channel 1 ROC 4: Readback start marker after 15 readouts!

[09:29:26.381]  WARNING: Channel 1 ROC 5: Readback start marker after 15 readouts!

[09:29:26.381]  WARNING: Channel 1 ROC 6: Readback start marker after 15 readouts!

[09:29:26.382]  WARNING: Channel 1 ROC 7: Readback start marker after 15 readouts!

[09:29:28.164]     INFO: Test took 38825ms.

[09:29:28.394]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:29:28.407]     INFO:   dacScan step  from 100 .. 109

[09:29:28.407]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:30:04.937]    ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 1 Number of ROCs (14) != Token Chain Length (8)

[09:30:04.937]    ERROR: <datapipe.cc/CheckEventID:L420> Channel 1 Event ID mismatch:  local ID (102) !=  TBM ID (103)

[09:30:04.937]  WARNING: Channel 1 ROC 1: Readback start marker after 15 readouts!

[09:30:04.937]  WARNING: Channel 1 ROC 2: Readback start marker after 15 readouts!

[09:30:04.937]  WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!

[09:30:04.937]  WARNING: Channel 1 ROC 4: Readback start marker after 15 readouts!

[09:30:04.937]  WARNING: Channel 1 ROC 5: Readback start marker after 15 readouts!

[09:30:04.937]  WARNING: Channel 1 ROC 6: Readback start marker after 15 readouts!

[09:30:04.937]  WARNING: Channel 1 ROC 7: Readback start marker after 15 readouts!

[09:30:15.026]     INFO: Test took 46619ms.

[09:30:15.478]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:30:15.501]     INFO:   dacScan step  from 110 .. 119

[09:30:15.501]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:30:47.271]    ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 1 Number of ROCs (6) != Token Chain Length (8)

[09:30:47.271]  WARNING: Channel 1 ROC 7: Readback start marker after 15 readouts!

[09:31:08.835]    ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 1 Number of ROCs (5) != Token Chain Length (8)

[09:31:08.835]  WARNING: Channel 1 ROC 6: Readback start marker after 31 readouts!

[09:31:08.835]  WARNING: Channel 1 ROC 7: Readback start marker after 31 readouts!

[09:31:11.160]     INFO: Test took 55658ms.

[09:31:11.728]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:31:11.759]     INFO:   dacScan step  from 120 .. 129

[09:31:11.759]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:31:42.743]    ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 1 Number of ROCs (6) != Token Chain Length (8)

[09:31:42.743]  WARNING: Channel 1 ROC 7: Readback start marker after 15 readouts!

[09:32:05.240]    ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 1 Number of ROCs (4) != Token Chain Length (8)

[09:32:05.240]  WARNING: Channel 1 ROC 5: Readback start marker after 15 readouts!

[09:32:05.240]  WARNING: Channel 1 ROC 6: Readback start marker after 15 readouts!

[09:32:05.240]  WARNING: Channel 1 ROC 7: Readback start marker after 15 readouts!

[09:32:10.508]     INFO: Test took 58749ms.

[09:32:11.087]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:32:11.119]     INFO:   dacScan step  from 130 .. 139

[09:32:11.119]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:32:42.163]    ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 1 Number of ROCs (6) != Token Chain Length (8)

[09:32:42.163]  WARNING: Channel 1 ROC 7: Readback start marker after 15 readouts!

[09:33:04.402]    ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 1 Number of ROCs (4) != Token Chain Length (8)

[09:33:04.402]  WARNING: Channel 1 ROC 5: Readback start marker after 15 readouts!

[09:33:04.402]  WARNING: Channel 1 ROC 6: Readback start marker after 15 readouts!

[09:33:04.402]  WARNING: Channel 1 ROC 7: Readback start marker after 15 readouts!

[09:33:09.852]     INFO: Test took 58733ms.

[09:33:10.415]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:33:10.447]     INFO:   dacScan step  from 140 .. 149

[09:33:10.447]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:33:41.148]    ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 1 Number of ROCs (4) != Token Chain Length (8)

[09:33:41.148]  WARNING: Channel 1 ROC 5: Readback start marker after 15 readouts!

[09:33:41.148]  WARNING: Channel 1 ROC 6: Readback start marker after 15 readouts!

[09:33:41.148]  WARNING: Channel 1 ROC 7: Readback start marker after 15 readouts!

[09:34:02.723]    ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 1 Number of ROCs (5) != Token Chain Length (8)

[09:34:02.723]  WARNING: Channel 1 ROC 6: Readback start marker after 31 readouts!

[09:34:02.723]  WARNING: Channel 1 ROC 7: Readback start marker after 31 readouts!

[09:34:07.804]     INFO: Test took 57357ms.

[09:34:08.486]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:34:08.518]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0

[09:34:08.519]     INFO: dumping ASCII scurve output file: SCurveData

[09:34:10.077]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1

[09:34:10.077]     INFO: dumping ASCII scurve output file: SCurveData

[09:34:11.660]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2

[09:34:11.660]     INFO: dumping ASCII scurve output file: SCurveData

[09:34:13.128]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3

[09:34:13.128]     INFO: dumping ASCII scurve output file: SCurveData

[09:34:14.602]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4

[09:34:14.602]     INFO: dumping ASCII scurve output file: SCurveData

[09:34:15.821]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5

[09:34:15.821]     INFO: dumping ASCII scurve output file: SCurveData

[09:34:17.048]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6

[09:34:17.048]     INFO: dumping ASCII scurve output file: SCurveData

[09:34:18.265]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7

[09:34:18.266]     INFO: dumping ASCII scurve output file: SCurveData

[09:34:19.518]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8

[09:34:19.519]     INFO: dumping ASCII scurve output file: SCurveData

[09:34:20.750]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9

[09:34:20.750]     INFO: dumping ASCII scurve output file: SCurveData

[09:34:21.963]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10

[09:34:21.963]     INFO: dumping ASCII scurve output file: SCurveData

[09:34:23.144]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11

[09:34:23.144]     INFO: dumping ASCII scurve output file: SCurveData

[09:34:24.349]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12

[09:34:24.349]     INFO: dumping ASCII scurve output file: SCurveData

[09:34:25.564]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13

[09:34:25.564]     INFO: dumping ASCII scurve output file: SCurveData

[09:34:26.781]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14

[09:34:26.781]     INFO: dumping ASCII scurve output file: SCurveData

[09:34:27.001]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15

[09:34:27.001]     INFO: dumping ASCII scurve output file: SCurveData

[09:34:29.228]    DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 569843712

[09:34:29.273]     INFO: PixTestScurves::scurves() done 

[09:34:29.273]     INFO: Vcal mean:  94.23 108.06 110.57 102.41 100.62  99.90 104.85  93.35  99.15 105.83 115.29 107.96 106.92 105.65 105.16 103.06 

[09:34:29.273]     INFO: Vcal RMS:    5.12   4.73   5.32   5.95   5.26   5.72   5.90   6.59   6.48   5.91   5.67   5.38   5.39   5.10   5.38   6.42 

[09:34:29.273]     INFO: PixTestScurves::fullTest() done, duration: 657 seconds

[09:34:29.273]    DEBUG: <PixTestScurves.cc/~PixTestScurves:L141> PixTestScurves dtor

[09:34:29.337]     INFO: ######################################################################

[09:34:29.337]     INFO: PixTestTrim::doTest()

[09:34:29.337]     INFO: ######################################################################

[09:34:29.339]     INFO:    ----------------------------------------------------------------------

[09:34:29.339]     INFO:    PixTestTrim::trimTest() ntrig = 10, vcal = 35

[09:34:29.339]     INFO:    ----------------------------------------------------------------------

[09:34:29.408]     INFO: ---> VthrComp thr map (minimal VthrComp)

[09:34:29.408]     INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 5 dacrange: 0 .. 159 (20) hits flags = 16 (plus default)

[09:34:29.416]     INFO:   dacScan step  from 0 .. 19

[09:34:29.417]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:34:43.491]     INFO: Test took 14074ms.

[09:34:43.516]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:34:43.516]     INFO:   dacScan step  from 20 .. 39

[09:34:43.516]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:34:57.648]     INFO: Test took 14132ms.

[09:34:57.674]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:34:57.675]     INFO:   dacScan step  from 40 .. 59

[09:34:57.675]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:35:11.848]     INFO: Test took 14173ms.

[09:35:11.872]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:35:11.872]     INFO:   dacScan step  from 60 .. 79

[09:35:11.872]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:35:25.960]     INFO: Test took 14088ms.

[09:35:25.983]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:35:25.983]     INFO:   dacScan step  from 80 .. 99

[09:35:25.983]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:35:40.136]     INFO: Test took 14153ms.

[09:35:40.167]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:35:40.169]     INFO:   dacScan step  from 100 .. 119

[09:35:40.169]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:35:56.107]     INFO: Test took 15938ms.

[09:35:56.228]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:35:56.255]     INFO:   dacScan step  from 120 .. 139

[09:35:56.255]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:36:14.007]     INFO: Test took 17752ms.

[09:36:14.183]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:36:14.241]     INFO:   dacScan step  from 140 .. 159

[09:36:14.241]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:36:29.140]     INFO: Test took 14899ms.

[09:36:29.223]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:36:29.235]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0

[09:36:30.405]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1

[09:36:31.593]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2

[09:36:32.806]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3

[09:36:33.997]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4

[09:36:35.157]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5

[09:36:36.321]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6

[09:36:37.509]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7

[09:36:38.681]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8

[09:36:39.836]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9

[09:36:41.043]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10

[09:36:42.250]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11

[09:36:43.472]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12

[09:36:44.701]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13

[09:36:45.894]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14

[09:36:47.116]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15

[09:36:48.284]    DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 569864192

[09:36:48.286]    DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 95.3883 minThrLimit = 95.3803 minThrNLimit = 117.722 -> result = 95.3883 -> 95

[09:36:48.286]    DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 103.32 minThrLimit = 103.232 minThrNLimit = 123.435 -> result = 103.32 -> 103

[09:36:48.286]    DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 104.808 minThrLimit = 104.737 minThrNLimit = 127.55 -> result = 104.808 -> 104

[09:36:48.287]    DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 98.3086 minThrLimit = 98.3013 minThrNLimit = 118.144 -> result = 98.3086 -> 98

[09:36:48.287]    DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 96.9478 minThrLimit = 96.935 minThrNLimit = 116.607 -> result = 96.9478 -> 96

[09:36:48.287]    DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 96.1517 minThrLimit = 96.148 minThrNLimit = 115.481 -> result = 96.1517 -> 96

[09:36:48.288]    DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 103.096 minThrLimit = 102.961 minThrNLimit = 124.164 -> result = 103.096 -> 103

[09:36:48.288]    DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 94.6699 minThrLimit = 94.6548 minThrNLimit = 117.322 -> result = 94.6699 -> 94

[09:36:48.288]    DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 95.7964 minThrLimit = 95.7785 minThrNLimit = 115.439 -> result = 95.7964 -> 95

[09:36:48.289]    DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 102.774 minThrLimit = 102.757 minThrNLimit = 127.003 -> result = 102.774 -> 102

[09:36:48.289]    DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 108.88 minThrLimit = 108.865 minThrNLimit = 132.9 -> result = 108.88 -> 108

[09:36:48.290]    DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 105.162 minThrLimit = 104.798 minThrNLimit = 131.249 -> result = 105.162 -> 105

[09:36:48.290]    DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 103.792 minThrLimit = 103.709 minThrNLimit = 130.535 -> result = 103.792 -> 103

[09:36:48.290]    DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 102.679 minThrLimit = 102.662 minThrNLimit = 123.388 -> result = 102.679 -> 102

[09:36:48.291]    DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 103.751 minThrLimit = 103.619 minThrNLimit = 127.853 -> result = 103.751 -> 103

[09:36:48.291]    DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 99.5379 minThrLimit = 99.5143 minThrNLimit = 119.951 -> result = 99.5379 -> 99

[09:36:48.291]     INFO: ROC 0 VthrComp = 95

[09:36:48.291]     INFO: ROC 1 VthrComp = 103

[09:36:48.291]     INFO: ROC 2 VthrComp = 104

[09:36:48.292]     INFO: ROC 3 VthrComp = 98

[09:36:48.292]     INFO: ROC 4 VthrComp = 96

[09:36:48.292]     INFO: ROC 5 VthrComp = 96

[09:36:48.292]     INFO: ROC 6 VthrComp = 103

[09:36:48.292]     INFO: ROC 7 VthrComp = 94

[09:36:48.292]     INFO: ROC 8 VthrComp = 95

[09:36:48.292]     INFO: ROC 9 VthrComp = 102

[09:36:48.293]     INFO: ROC 10 VthrComp = 108

[09:36:48.293]     INFO: ROC 11 VthrComp = 105

[09:36:48.293]     INFO: ROC 12 VthrComp = 103

[09:36:48.293]     INFO: ROC 13 VthrComp = 102

[09:36:48.293]     INFO: ROC 14 VthrComp = 103

[09:36:48.293]     INFO: ROC 15 VthrComp = 99

[09:36:48.293]     INFO: ---> Vcal thr map (pixel with maximum Vcal thr)

[09:36:48.293]     INFO: ---> dac: vcal name: TrimThr1 ntrig: 5 dacrange: 0 .. 159 (20) hits flags = 16 (plus default)

[09:36:48.303]     INFO:   dacScan step  from 0 .. 19

[09:36:48.303]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:37:02.324]     INFO: Test took 14021ms.

[09:37:02.351]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:37:02.351]     INFO:   dacScan step  from 20 .. 39

[09:37:02.351]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:37:16.510]     INFO: Test took 14159ms.

[09:37:16.543]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:37:16.557]     INFO:   dacScan step  from 40 .. 59

[09:37:16.570]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:37:33.272]     INFO: Test took 16702ms.

[09:37:33.421]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:37:33.460]     INFO:   dacScan step  from 60 .. 79

[09:37:33.460]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:37:51.921]     INFO: Test took 18461ms.

[09:37:52.095]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:37:52.155]     INFO:   dacScan step  from 80 .. 99

[09:37:52.155]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:38:10.556]     INFO: Test took 18401ms.

[09:38:10.724]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:38:10.785]     INFO:   dacScan step  from 100 .. 119

[09:38:10.785]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:38:29.314]     INFO: Test took 18529ms.

[09:38:29.483]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:38:29.544]     INFO:   dacScan step  from 120 .. 139

[09:38:29.544]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:38:48.651]     INFO: Test took 19107ms.

[09:38:48.825]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:38:48.956]     INFO:   dacScan step  from 140 .. 159

[09:38:48.956]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:39:07.529]     INFO: Test took 18573ms.

[09:39:07.697]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:39:07.757]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0

[09:39:09.109]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1

[09:39:10.484]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2

[09:39:11.875]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3

[09:39:13.258]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4

[09:39:14.622]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5

[09:39:16.031]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6

[09:39:17.431]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7

[09:39:18.803]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8

[09:39:20.174]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9

[09:39:21.539]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10

[09:39:22.929]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11

[09:39:24.301]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12

[09:39:25.667]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13

[09:39:27.040]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14

[09:39:28.406]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15

[09:39:29.782]    DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 569864192

[09:39:29.784]     INFO:    roc 0 with ID = 0  has maximal Vcal 58.1578 for pixel 3/19 mean/min/max = 45.5423/32.8525/58.2321

[09:39:29.784]     INFO:    roc 1 with ID = 1  has maximal Vcal 59.3493 for pixel 13/2 mean/min/max = 46.4801/33.4727/59.4876

[09:39:29.784]     INFO:    roc 2 with ID = 2  has maximal Vcal 63.4798 for pixel 26/3 mean/min/max = 49.2092/34.8971/63.5214

[09:39:29.785]     INFO:    roc 3 with ID = 3  has maximal Vcal 62.1043 for pixel 15/12 mean/min/max = 47.0788/32.051/62.1066

[09:39:29.785]     INFO:    roc 4 with ID = 4  has maximal Vcal 59.7176 for pixel 10/76 mean/min/max = 46.3722/32.8539/59.8905

[09:39:29.785]     INFO:    roc 5 with ID = 5  has maximal Vcal 61.3516 for pixel 16/11 mean/min/max = 46.7743/32.1948/61.3538

[09:39:29.786]     INFO:    roc 6 with ID = 6  has maximal Vcal 58.2426 for pixel 51/2 mean/min/max = 45.7867/33.3126/58.2608

[09:39:29.786]     INFO:    roc 7 with ID = 7  has maximal Vcal 60.1208 for pixel 5/39 mean/min/max = 46.5971/33.0713/60.123

[09:39:29.786]     INFO:    roc 8 with ID = 8  has maximal Vcal 61.9742 for pixel 21/62 mean/min/max = 47.6016/33.195/62.0082

[09:39:29.786]     INFO:    roc 9 with ID = 9  has maximal Vcal 61.277 for pixel 0/6 mean/min/max = 47.0611/32.8216/61.3007

[09:39:29.787]     INFO:    roc 10 with ID = 10  has maximal Vcal 67.2306 for pixel 3/34 mean/min/max = 51.4223/35.1883/67.6562

[09:39:29.787]     INFO:    roc 11 with ID = 11  has maximal Vcal 63.31 for pixel 24/0 mean/min/max = 48.6995/33.9973/63.4018

[09:39:29.787]     INFO:    roc 12 with ID = 12  has maximal Vcal 61.4033 for pixel 30/10 mean/min/max = 47.3606/33.2502/61.4711

[09:39:29.788]     INFO:    roc 13 with ID = 13  has maximal Vcal 59.8509 for pixel 19/8 mean/min/max = 46.5181/33.1577/59.8785

[09:39:29.788]     INFO:    roc 14 with ID = 14  has maximal Vcal 60.2625 for pixel 20/49 mean/min/max = 46.6524/33.027/60.2778

[09:39:29.788]     INFO:    roc 15 with ID = 15  has maximal Vcal 59.9581 for pixel 22/77 mean/min/max = 45.9023/31.8145/59.9901

[09:39:29.788]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[09:40:45.872]     INFO: Test took 76084ms.

[09:40:46.721]    DEBUG: <PixTestTrim.cc/trimTest:L309> vtrim: vcal = 35.246 < 35 for itrim+1 = 114; old thr = 34.9313 ... break

[09:40:46.747]    DEBUG: <PixTestTrim.cc/trimTest:L309> vtrim: vcal = 36.3448 < 35 for itrim+1 = 115; old thr = 33.6702 ... break

[09:40:46.774]    DEBUG: <PixTestTrim.cc/trimTest:L304>  vtrim: vcal = 35.2809 < 35 for itrim = 113; old thr = 32.6124 ... break

[09:40:46.800]    DEBUG: <PixTestTrim.cc/trimTest:L309> vtrim: vcal = 35.4532 < 35 for itrim+1 = 116; old thr = 34.963 ... break

[09:40:46.827]    DEBUG: <PixTestTrim.cc/trimTest:L304>  vtrim: vcal = 35.1566 < 35 for itrim = 114; old thr = 34.8166 ... break

[09:40:46.849]    DEBUG: <PixTestTrim.cc/trimTest:L304>  vtrim: vcal = 35.1316 < 35 for itrim = 108; old thr = 34.6138 ... break

[09:40:46.866]    DEBUG: <PixTestTrim.cc/trimTest:L304>  vtrim: vcal = 35.192 < 35 for itrim = 93; old thr = 33.6644 ... break

[09:40:46.892]    DEBUG: <PixTestTrim.cc/trimTest:L304>  vtrim: vcal = 35.4506 < 35 for itrim = 97; old thr = 34.3384 ... break

[09:40:46.916]    DEBUG: <PixTestTrim.cc/trimTest:L304>  vtrim: vcal = 35.6241 < 35 for itrim = 109; old thr = 33.8293 ... break

[09:40:46.937]    DEBUG: <PixTestTrim.cc/trimTest:L309> vtrim: vcal = 36.352 < 35 for itrim+1 = 108; old thr = 34.3923 ... break

[09:40:46.961]    DEBUG: <PixTestTrim.cc/trimTest:L304>  vtrim: vcal = 35.7768 < 35 for itrim = 133; old thr = 33.5371 ... break

[09:40:46.986]    DEBUG: <PixTestTrim.cc/trimTest:L304>  vtrim: vcal = 35.0604 < 35 for itrim = 114; old thr = 34.3623 ... break

[09:40:47.020]    DEBUG: <PixTestTrim.cc/trimTest:L309> vtrim: vcal = 35.125 < 35 for itrim+1 = 128; old thr = 34.8881 ... break

[09:40:47.045]    DEBUG: <PixTestTrim.cc/trimTest:L309> vtrim: vcal = 36.4458 < 35 for itrim+1 = 104; old thr = 34.9622 ... break

[09:40:47.071]    DEBUG: <PixTestTrim.cc/trimTest:L304>  vtrim: vcal = 35.2811 < 35 for itrim = 106; old thr = 33.2314 ... break

[09:40:47.095]    DEBUG: <PixTestTrim.cc/trimTest:L304>  vtrim: vcal = 35.0455 < 35 for itrim = 105; old thr = 34.3476 ... break

[09:40:47.159]     INFO: ---> dac: vcal name: TrimThr2 ntrig: 10 dacrange: 0 .. 199 (20) hits flags = 16 (plus default)

[09:40:47.168]     INFO:   dacScan step  from 0 .. 19

[09:40:47.168]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:41:07.189]     INFO: Test took 20021ms.

[09:41:07.238]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:41:07.241]     INFO:   dacScan step  from 20 .. 39

[09:41:07.241]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:41:31.409]     INFO: Test took 24168ms.

[09:41:31.637]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:41:31.673]     INFO:   dacScan step  from 40 .. 59

[09:41:31.673]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:42:00.584]     INFO: Test took 28911ms.

[09:42:00.879]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:42:00.934]     INFO:   dacScan step  from 60 .. 79

[09:42:00.934]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:42:29.914]     INFO: Test took 28980ms.

[09:42:30.195]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:42:30.252]     INFO:   dacScan step  from 80 .. 99

[09:42:30.252]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:42:59.238]     INFO: Test took 28986ms.

[09:42:59.519]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:42:59.573]     INFO:   dacScan step  from 100 .. 119

[09:42:59.573]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:43:28.738]     INFO: Test took 29165ms.

[09:43:29.023]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:43:29.078]     INFO:   dacScan step  from 120 .. 139

[09:43:29.079]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:43:58.985]     INFO: Test took 29906ms.

[09:43:59.273]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:43:59.328]     INFO:   dacScan step  from 140 .. 159

[09:43:59.328]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:44:28.426]     INFO: Test took 29098ms.

[09:44:28.710]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:44:28.765]     INFO:   dacScan step  from 160 .. 179

[09:44:28.765]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:44:57.493]     INFO: Test took 28728ms.

[09:44:57.793]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:44:57.848]     INFO:   dacScan step  from 180 .. 199

[09:44:57.848]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:45:27.445]     INFO: Test took 29597ms.

[09:45:27.730]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:45:27.786]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0

[09:45:29.195]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1

[09:45:30.659]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2

[09:45:32.116]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3

[09:45:33.571]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4

[09:45:34.997]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5

[09:45:36.464]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6

[09:45:37.938]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7

[09:45:39.392]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8

[09:45:40.851]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9

[09:45:42.281]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10

[09:45:43.743]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11

[09:45:45.165]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12

[09:45:46.597]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13

[09:45:48.052]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14

[09:45:49.491]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15

[09:45:50.941]    DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 574410752

[09:45:50.943]     INFO: ---> TrimStepCorr4 extremal thresholds: 0.022226 .. 255.000000

[09:45:51.007]     INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 4 dacrange: 0 .. 255 (20) hits flags = 16 (plus default)

[09:45:51.016]     INFO:   dacScan step  from 0 .. 19

[09:45:51.016]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:46:03.893]     INFO: Test took 12877ms.

[09:46:03.919]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:46:03.919]     INFO:   dacScan step  from 20 .. 39

[09:46:03.919]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:46:17.670]     INFO: Test took 13751ms.

[09:46:17.754]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:46:17.770]     INFO:   dacScan step  from 40 .. 59

[09:46:17.770]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:46:33.980]     INFO: Test took 16210ms.

[09:46:34.130]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:46:34.184]     INFO:   dacScan step  from 60 .. 79

[09:46:34.185]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:46:50.566]     INFO: Test took 16381ms.

[09:46:50.712]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:46:50.769]     INFO:   dacScan step  from 80 .. 99

[09:46:50.769]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:47:07.213]     INFO: Test took 16444ms.

[09:47:07.355]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:47:07.409]     INFO:   dacScan step  from 100 .. 119

[09:47:07.409]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:47:23.905]     INFO: Test took 16495ms.

[09:47:24.049]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:47:24.104]     INFO:   dacScan step  from 120 .. 139

[09:47:24.104]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:47:41.249]     INFO: Test took 17145ms.

[09:47:41.397]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:47:41.453]     INFO:   dacScan step  from 140 .. 159

[09:47:41.453]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:47:57.967]     INFO: Test took 16514ms.

[09:47:58.117]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:47:58.173]     INFO:   dacScan step  from 160 .. 179

[09:47:58.173]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:48:14.597]     INFO: Test took 16424ms.

[09:48:14.742]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:48:14.795]     INFO:   dacScan step  from 180 .. 199

[09:48:14.795]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:48:31.576]     INFO: Test took 16781ms.

[09:48:31.730]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:48:31.785]     INFO:   dacScan step  from 200 .. 219

[09:48:31.785]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:48:47.975]     INFO: Test took 16190ms.

[09:48:48.119]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:48:48.176]     INFO:   dacScan step  from 220 .. 239

[09:48:48.176]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:49:04.550]     INFO: Test took 16374ms.

[09:49:04.694]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:49:04.751]     INFO:   dacScan step  from 240 .. 255

[09:49:04.751]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:49:18.424]     INFO: Test took 13673ms.

[09:49:18.542]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:49:18.589]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0

[09:49:20.318]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1

[09:49:22.059]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2

[09:49:23.791]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3

[09:49:25.519]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4

[09:49:27.246]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5

[09:49:28.991]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6

[09:49:30.736]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7

[09:49:32.447]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8

[09:49:34.184]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9

[09:49:35.898]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10

[09:49:37.707]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11

[09:49:39.556]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12

[09:49:41.621]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13

[09:49:43.671]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14

[09:49:45.514]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15

[09:49:47.241]    DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 574410752

[09:49:47.308]     INFO: ---> TrimStepCorr2 extremal thresholds: 12.606713 .. 59.704446

[09:49:47.370]     INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 4 dacrange: 2 .. 69 (20) hits flags = 16 (plus default)

[09:49:47.379]     INFO:   dacScan step  from 2 .. 21

[09:49:47.380]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:50:00.300]     INFO: Test took 12920ms.

[09:50:00.323]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:50:00.323]     INFO:   dacScan step  from 22 .. 41

[09:50:00.324]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:50:14.483]     INFO: Test took 14159ms.

[09:50:14.580]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:50:14.605]     INFO:   dacScan step  from 42 .. 61

[09:50:14.605]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:50:30.837]     INFO: Test took 16232ms.

[09:50:30.987]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:50:31.040]     INFO:   dacScan step  from 62 .. 69

[09:50:31.040]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:50:39.119]     INFO: Test took 8079ms.

[09:50:39.178]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:50:39.202]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0

[09:50:40.176]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1

[09:50:41.158]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2

[09:50:42.147]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3

[09:50:43.136]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4

[09:50:44.114]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5

[09:50:45.091]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6

[09:50:46.065]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7

[09:50:47.032]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8

[09:50:48.006]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9

[09:50:48.980]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10

[09:50:49.955]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11

[09:50:50.924]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12

[09:50:51.884]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13

[09:50:52.843]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14

[09:50:53.802]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15

[09:50:54.771]    DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 574521344

[09:50:54.839]     INFO: ---> TrimStepCorr1a extremal thresholds: 1.559548 .. 50.673842

[09:50:54.903]     INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 4 dacrange: 1 .. 60 (20) hits flags = 16 (plus default)

[09:50:54.911]     INFO:   dacScan step  from 1 .. 20

[09:50:54.912]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:51:07.678]     INFO: Test took 12766ms.

[09:51:07.699]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:51:07.699]     INFO:   dacScan step  from 21 .. 40

[09:51:07.699]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:51:21.398]     INFO: Test took 13699ms.

[09:51:21.485]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:51:21.506]     INFO:   dacScan step  from 41 .. 60

[09:51:21.506]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:51:37.690]     INFO: Test took 16184ms.

[09:51:37.838]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:51:37.892]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0

[09:51:38.781]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1

[09:51:39.708]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2

[09:51:40.606]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3

[09:51:41.505]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4

[09:51:42.401]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5

[09:51:43.295]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6

[09:51:44.186]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7

[09:51:45.077]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8

[09:51:45.972]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9

[09:51:46.867]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10

[09:51:47.758]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11

[09:51:48.650]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12

[09:51:49.539]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13

[09:51:50.433]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14

[09:51:51.329]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15

[09:51:52.231]    DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 574521344

[09:51:52.300]     INFO: ---> TrimStepCorr1b extremal thresholds: 0.338800 .. 50.072501

[09:51:52.364]     INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 4 dacrange: 0 .. 60 (20) hits flags = 16 (plus default)

[09:51:52.373]     INFO:   dacScan step  from 0 .. 19

[09:51:52.373]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:52:05.225]     INFO: Test took 12852ms.

[09:52:05.249]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:52:05.249]     INFO:   dacScan step  from 20 .. 39

[09:52:05.249]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:52:18.737]     INFO: Test took 13488ms.

[09:52:18.814]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:52:18.832]     INFO:   dacScan step  from 40 .. 59

[09:52:18.833]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:52:35.007]     INFO: Test took 16174ms.

[09:52:35.155]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:52:35.210]     INFO:   dacScan step  from 60 .. 60

[09:52:35.210]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:52:38.693]     INFO: Test took 3483ms.

[09:52:38.702]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:52:38.706]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0

[09:52:39.620]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1

[09:52:40.534]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2

[09:52:41.445]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3

[09:52:42.343]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4

[09:52:43.237]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5

[09:52:44.138]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6

[09:52:45.033]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7

[09:52:45.934]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8

[09:52:46.836]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9

[09:52:47.734]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10

[09:52:48.632]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11

[09:52:49.532]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12

[09:52:50.430]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13

[09:52:51.327]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14

[09:52:52.224]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15

[09:52:53.135]    DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 574525440

[09:52:53.204]     INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55

[09:52:53.204]     INFO: ---> dac: vcal name: TrimThrFinal ntrig: 10 dacrange: 15 .. 55 (20) hits flags = 16 (plus default)

[09:52:53.213]     INFO:   dacScan step  from 15 .. 34

[09:52:53.213]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:53:13.599]     INFO: Test took 20386ms.

[09:53:13.678]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:53:13.690]     INFO:   dacScan step  from 35 .. 54

[09:53:13.690]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:53:42.120]     INFO: Test took 28430ms.

[09:53:42.420]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:53:42.476]     INFO:   dacScan step  from 55 .. 55

[09:53:42.476]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:53:46.590]     INFO: Test took 4114ms.

[09:53:46.606]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:53:46.610]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0

[09:53:47.354]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1

[09:53:48.090]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2

[09:53:48.829]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3

[09:53:49.575]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4

[09:53:50.321]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5

[09:53:51.075]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6

[09:53:51.817]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7

[09:53:52.562]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8

[09:53:53.311]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9

[09:53:54.063]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10

[09:53:54.809]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11

[09:53:55.560]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12

[09:53:56.299]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13

[09:53:57.036]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14

[09:53:57.778]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15

[09:53:58.519]    DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 574525440

[09:53:58.572]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C0.dat

[09:53:58.572]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C1.dat

[09:53:58.572]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C2.dat

[09:53:58.572]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C3.dat

[09:53:58.573]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C4.dat

[09:53:58.573]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C5.dat

[09:53:58.573]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C6.dat

[09:53:58.573]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C7.dat

[09:53:58.573]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C8.dat

[09:53:58.573]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C9.dat

[09:53:58.573]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C10.dat

[09:53:58.574]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C11.dat

[09:53:58.574]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C12.dat

[09:53:58.574]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C13.dat

[09:53:58.574]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C14.dat

[09:53:58.574]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C15.dat

[09:53:58.574]     INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//trimParameters35_C0.dat

[09:53:58.580]     INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//trimParameters35_C1.dat

[09:53:58.586]     INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//trimParameters35_C2.dat

[09:53:58.591]     INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//trimParameters35_C3.dat

[09:53:58.596]     INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//trimParameters35_C4.dat

[09:53:58.601]     INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//trimParameters35_C5.dat

[09:53:58.607]     INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//trimParameters35_C6.dat

[09:53:58.612]     INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//trimParameters35_C7.dat

[09:53:58.617]     INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//trimParameters35_C8.dat

[09:53:58.623]     INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//trimParameters35_C9.dat

[09:53:58.628]     INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//trimParameters35_C10.dat

[09:53:58.634]     INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//trimParameters35_C11.dat

[09:53:58.639]     INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//trimParameters35_C12.dat

[09:53:58.644]     INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//trimParameters35_C13.dat

[09:53:58.650]     INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//trimParameters35_C14.dat

[09:53:58.655]     INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//trimParameters35_C15.dat

[09:53:58.660]     INFO: PixTestTrim::trimTest() done

[09:53:58.660]     INFO: vtrim:     114 115 113 116 114 108  93  97 109 108 133 114 128 104 106 105 

[09:53:58.660]     INFO: vthrcomp:   95 103 104  98  96  96 103  94  95 102 108 105 103 102 103  99 

[09:53:58.660]     INFO: vcal mean:  35.02  35.06  35.11  35.05  35.02  35.07  35.07  35.09  35.05  35.06  35.08  35.07  35.04  35.07  35.09  35.10 

[09:53:58.660]     INFO: vcal RMS:    1.09   1.21   1.29   1.38   1.13   1.33   1.59   1.57   1.49   1.11   1.19   1.13   1.15   1.15   1.08   1.15 

[09:53:58.660]     INFO: bits mean:  10.02  10.00   8.94   9.66   9.83   9.90   9.39   9.33   9.37   9.10   8.58   9.07   9.50   9.65   9.16   9.85 

[09:53:58.660]     INFO: bits RMS:    2.38   2.27   2.33   2.57   2.42   2.47   2.64   2.59   2.52   2.66   2.29   2.45   2.42   2.47   2.71   2.64 

[09:53:58.670]     INFO:    ----------------------------------------------------------------------

[09:53:58.670]     INFO:    PixTestTrim::trimBitTest() ntrig = 10, vtrims = 254 126 63 32

[09:53:58.670]     INFO:    ----------------------------------------------------------------------

[09:53:58.674]    DEBUG: <PixTestTrim.cc/trimBitTest:L518> trimBitTest determine threshold map without trims 

[09:53:58.674]     INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 10 dacrange: 0 .. 199 (20) hits flags = 16 (plus default)

[09:53:58.684]     INFO:   dacScan step  from 0 .. 19

[09:53:58.684]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:54:18.638]     INFO: Test took 19954ms.

[09:54:18.676]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:54:18.676]     INFO:   dacScan step  from 20 .. 39

[09:54:18.676]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:54:38.669]     INFO: Test took 19993ms.

[09:54:38.706]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:54:38.706]     INFO:   dacScan step  from 40 .. 59

[09:54:38.706]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:54:58.635]     INFO: Test took 19929ms.

[09:54:58.677]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:54:58.677]     INFO:   dacScan step  from 60 .. 79

[09:54:58.677]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:55:18.631]     INFO: Test took 19954ms.

[09:55:18.671]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:55:18.671]     INFO:   dacScan step  from 80 .. 99

[09:55:18.671]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:55:38.703]     INFO: Test took 20032ms.

[09:55:38.740]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:55:38.740]     INFO:   dacScan step  from 100 .. 119

[09:55:38.740]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:55:58.990]     INFO: Test took 20250ms.

[09:55:59.047]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:55:59.049]     INFO:   dacScan step  from 120 .. 139

[09:55:59.050]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:56:22.586]     INFO: Test took 23537ms.

[09:56:22.784]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:56:22.812]     INFO:   dacScan step  from 140 .. 159

[09:56:22.812]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:56:51.215]     INFO: Test took 28402ms.

[09:56:51.489]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:56:51.542]     INFO:   dacScan step  from 160 .. 179

[09:56:51.542]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:57:20.964]     INFO: Test took 29422ms.

[09:57:21.242]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:57:21.299]     INFO:   dacScan step  from 180 .. 199

[09:57:21.299]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:57:50.822]     INFO: Test took 29523ms.

[09:57:51.105]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:57:51.159]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0

[09:57:52.577]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1

[09:57:53.960]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2

[09:57:55.339]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3

[09:57:56.723]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4

[09:57:58.085]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5

[09:57:59.453]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6

[09:58:00.813]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7

[09:58:02.200]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8

[09:58:03.571]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9

[09:58:04.919]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10

[09:58:06.242]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11

[09:58:07.615]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12

[09:58:08.992]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13

[09:58:10.377]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14

[09:58:11.758]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15

[09:58:13.142]    DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 574541824

[09:58:13.142]    DEBUG: <PixTestTrim.cc/trimBitTest:L533> trimBitTest initDUT with trim bits = 14

[09:58:13.205]    DEBUG: <PixTestTrim.cc/trimBitTest:L539> trimBitTest threshold map with trim = 14

[09:58:13.205]     INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 10 dacrange: 0 .. 190 (20) hits flags = 16 (plus default)

[09:58:13.214]     INFO:   dacScan step  from 0 .. 19

[09:58:13.214]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:58:33.065]     INFO: Test took 19851ms.

[09:58:33.104]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:58:33.105]     INFO:   dacScan step  from 20 .. 39

[09:58:33.105]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:58:53.075]     INFO: Test took 19970ms.

[09:58:53.115]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:58:53.115]     INFO:   dacScan step  from 40 .. 59

[09:58:53.115]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:59:13.032]     INFO: Test took 19917ms.

[09:59:13.069]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:59:13.069]     INFO:   dacScan step  from 60 .. 79

[09:59:13.069]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:59:33.059]     INFO: Test took 19990ms.

[09:59:33.098]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:59:33.098]     INFO:   dacScan step  from 80 .. 99

[09:59:33.098]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[09:59:53.060]     INFO: Test took 19962ms.

[09:59:53.101]     INFO: Fetched DAQ statistics. Counters are being reset now.

[09:59:53.101]     INFO:   dacScan step  from 100 .. 119

[09:59:53.101]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[10:00:13.844]     INFO: Test took 20743ms.

[10:00:13.958]     INFO: Fetched DAQ statistics. Counters are being reset now.

[10:00:13.972]     INFO:   dacScan step  from 120 .. 139

[10:00:13.972]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[10:00:40.628]     INFO: Test took 26656ms.

[10:00:40.898]     INFO: Fetched DAQ statistics. Counters are being reset now.

[10:00:40.942]     INFO:   dacScan step  from 140 .. 159

[10:00:40.942]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[10:01:10.274]     INFO: Test took 29332ms.

[10:01:10.555]     INFO: Fetched DAQ statistics. Counters are being reset now.

[10:01:10.616]     INFO:   dacScan step  from 160 .. 179

[10:01:10.616]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[10:01:39.831]     INFO: Test took 29215ms.

[10:01:40.107]     INFO: Fetched DAQ statistics. Counters are being reset now.

[10:01:40.169]     INFO:   dacScan step  from 180 .. 190

[10:01:40.169]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[10:01:57.674]     INFO: Test took 17504ms.

[10:01:57.827]     INFO: Fetched DAQ statistics. Counters are being reset now.

[10:01:57.861]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0

[10:01:59.238]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1

[10:02:00.576]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2

[10:02:01.888]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3

[10:02:03.226]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4

[10:02:04.563]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5

[10:02:05.919]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6

[10:02:07.263]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7

[10:02:08.646]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8

[10:02:10.017]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9

[10:02:11.376]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10

[10:02:12.697]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11

[10:02:14.032]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12

[10:02:15.364]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13

[10:02:16.691]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14

[10:02:18.019]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15

[10:02:19.352]    DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 574541824

[10:02:19.353]    DEBUG: <PixTestTrim.cc/trimBitTest:L533> trimBitTest initDUT with trim bits = 13

[10:02:19.417]    DEBUG: <PixTestTrim.cc/trimBitTest:L539> trimBitTest threshold map with trim = 13

[10:02:19.417]     INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 10 dacrange: 0 .. 180 (20) hits flags = 16 (plus default)

[10:02:19.426]     INFO:   dacScan step  from 0 .. 19

[10:02:19.426]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[10:02:39.233]     INFO: Test took 19807ms.

[10:02:39.272]     INFO: Fetched DAQ statistics. Counters are being reset now.

[10:02:39.272]     INFO:   dacScan step  from 20 .. 39

[10:02:39.272]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[10:02:59.264]     INFO: Test took 19992ms.

[10:02:59.301]     INFO: Fetched DAQ statistics. Counters are being reset now.

[10:02:59.302]     INFO:   dacScan step  from 40 .. 59

[10:02:59.302]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[10:03:19.399]     INFO: Test took 20097ms.

[10:03:19.437]     INFO: Fetched DAQ statistics. Counters are being reset now.

[10:03:19.437]     INFO:   dacScan step  from 60 .. 79

[10:03:19.437]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[10:03:39.350]     INFO: Test took 19913ms.

[10:03:39.386]     INFO: Fetched DAQ statistics. Counters are being reset now.

[10:03:39.386]     INFO:   dacScan step  from 80 .. 99

[10:03:39.386]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[10:03:58.960]     INFO: Test took 19574ms.

[10:03:58.000]     INFO: Fetched DAQ statistics. Counters are being reset now.

[10:03:58.000]     INFO:   dacScan step  from 100 .. 119

[10:03:58.001]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[10:04:20.126]     INFO: Test took 21125ms.

[10:04:20.240]     INFO: Fetched DAQ statistics. Counters are being reset now.

[10:04:20.254]     INFO:   dacScan step  from 120 .. 139

[10:04:20.254]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[10:04:47.428]     INFO: Test took 27174ms.

[10:04:47.693]     INFO: Fetched DAQ statistics. Counters are being reset now.

[10:04:47.735]     INFO:   dacScan step  from 140 .. 159

[10:04:47.735]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[10:05:16.961]     INFO: Test took 29226ms.

[10:05:17.243]     INFO: Fetched DAQ statistics. Counters are being reset now.

[10:05:17.301]     INFO:   dacScan step  from 160 .. 179

[10:05:17.302]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[10:05:46.647]     INFO: Test took 29345ms.

[10:05:46.930]     INFO: Fetched DAQ statistics. Counters are being reset now.

[10:05:46.989]     INFO:   dacScan step  from 180 .. 180

[10:05:46.990]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[10:05:51.076]     INFO: Test took 4086ms.

[10:05:51.094]     INFO: Fetched DAQ statistics. Counters are being reset now.

[10:05:51.098]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0

[10:05:52.444]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1

[10:05:53.720]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2

[10:05:54.986]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3

[10:05:56.283]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4

[10:05:57.584]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5

[10:05:58.896]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6

[10:06:00.190]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7

[10:06:01.519]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8

[10:06:02.832]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9

[10:06:04.119]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10

[10:06:05.370]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11

[10:06:06.667]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12

[10:06:07.962]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13

[10:06:09.266]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14

[10:06:10.568]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15

[10:06:11.869]    DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 574541824

[10:06:11.870]    DEBUG: <PixTestTrim.cc/trimBitTest:L533> trimBitTest initDUT with trim bits = 11

[10:06:11.934]    DEBUG: <PixTestTrim.cc/trimBitTest:L539> trimBitTest threshold map with trim = 11

[10:06:11.934]     INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 10 dacrange: 0 .. 180 (20) hits flags = 16 (plus default)

[10:06:11.943]     INFO:   dacScan step  from 0 .. 19

[10:06:11.943]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[10:06:31.853]     INFO: Test took 19910ms.

[10:06:31.890]     INFO: Fetched DAQ statistics. Counters are being reset now.

[10:06:31.890]     INFO:   dacScan step  from 20 .. 39

[10:06:31.890]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[10:06:51.812]     INFO: Test took 19922ms.

[10:06:51.849]     INFO: Fetched DAQ statistics. Counters are being reset now.

[10:06:51.849]     INFO:   dacScan step  from 40 .. 59

[10:06:51.849]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[10:07:11.658]     INFO: Test took 19809ms.

[10:07:11.694]     INFO: Fetched DAQ statistics. Counters are being reset now.

[10:07:11.694]     INFO:   dacScan step  from 60 .. 79

[10:07:11.695]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[10:07:31.432]     INFO: Test took 19737ms.

[10:07:31.469]     INFO: Fetched DAQ statistics. Counters are being reset now.

[10:07:31.469]     INFO:   dacScan step  from 80 .. 99

[10:07:31.470]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[10:07:51.426]     INFO: Test took 19956ms.

[10:07:51.468]     INFO: Fetched DAQ statistics. Counters are being reset now.

[10:07:51.468]     INFO:   dacScan step  from 100 .. 119

[10:07:51.468]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[10:08:12.329]     INFO: Test took 20861ms.

[10:08:12.441]     INFO: Fetched DAQ statistics. Counters are being reset now.

[10:08:12.453]     INFO:   dacScan step  from 120 .. 139

[10:08:12.453]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[10:08:40.034]     INFO: Test took 27581ms.

[10:08:40.301]     INFO: Fetched DAQ statistics. Counters are being reset now.

[10:08:40.344]     INFO:   dacScan step  from 140 .. 159

[10:08:40.344]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[10:09:09.559]     INFO: Test took 29215ms.

[10:09:09.841]     INFO: Fetched DAQ statistics. Counters are being reset now.

[10:09:09.900]     INFO:   dacScan step  from 160 .. 179

[10:09:09.900]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[10:09:39.125]     INFO: Test took 29225ms.

[10:09:39.400]     INFO: Fetched DAQ statistics. Counters are being reset now.

[10:09:39.461]     INFO:   dacScan step  from 180 .. 180

[10:09:39.461]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[10:09:43.548]     INFO: Test took 4087ms.

[10:09:43.566]     INFO: Fetched DAQ statistics. Counters are being reset now.

[10:09:43.570]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0

[10:09:44.913]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1

[10:09:46.203]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2

[10:09:47.492]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3

[10:09:48.814]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4

[10:09:50.130]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5

[10:09:51.457]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6

[10:09:52.763]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7

[10:09:54.107]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8

[10:09:55.437]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9

[10:09:56.736]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10

[10:09:57.001]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11

[10:09:59.297]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12

[10:10:00.588]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13

[10:10:01.894]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14

[10:10:03.204]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15

[10:10:04.523]    DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 574541824

[10:10:04.523]    DEBUG: <PixTestTrim.cc/trimBitTest:L533> trimBitTest initDUT with trim bits = 7

[10:10:04.586]    DEBUG: <PixTestTrim.cc/trimBitTest:L539> trimBitTest threshold map with trim = 7

[10:10:04.586]     INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 10 dacrange: 0 .. 179 (20) hits flags = 16 (plus default)

[10:10:04.595]     INFO:   dacScan step  from 0 .. 19

[10:10:04.595]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[10:10:24.595]     INFO: Test took 20000ms.

[10:10:24.632]     INFO: Fetched DAQ statistics. Counters are being reset now.

[10:10:24.632]     INFO:   dacScan step  from 20 .. 39

[10:10:24.632]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[10:10:44.463]     INFO: Test took 19831ms.

[10:10:44.499]     INFO: Fetched DAQ statistics. Counters are being reset now.

[10:10:44.499]     INFO:   dacScan step  from 40 .. 59

[10:10:44.499]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[10:11:04.237]     INFO: Test took 19738ms.

[10:11:04.277]     INFO: Fetched DAQ statistics. Counters are being reset now.

[10:11:04.277]     INFO:   dacScan step  from 60 .. 79

[10:11:04.277]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[10:11:24.364]     INFO: Test took 20087ms.

[10:11:24.401]     INFO: Fetched DAQ statistics. Counters are being reset now.

[10:11:24.401]     INFO:   dacScan step  from 80 .. 99

[10:11:24.402]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[10:11:44.402]     INFO: Test took 20000ms.

[10:11:44.443]     INFO: Fetched DAQ statistics. Counters are being reset now.

[10:11:44.443]     INFO:   dacScan step  from 100 .. 119

[10:11:44.443]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[10:12:05.343]     INFO: Test took 20900ms.

[10:12:05.459]     INFO: Fetched DAQ statistics. Counters are being reset now.

[10:12:05.473]     INFO:   dacScan step  from 120 .. 139

[10:12:05.473]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[10:12:32.941]     INFO: Test took 27468ms.

[10:12:33.207]     INFO: Fetched DAQ statistics. Counters are being reset now.

[10:12:33.249]     INFO:   dacScan step  from 140 .. 159

[10:12:33.249]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[10:13:02.433]     INFO: Test took 29184ms.

[10:13:02.722]     INFO: Fetched DAQ statistics. Counters are being reset now.

[10:13:02.780]     INFO:   dacScan step  from 160 .. 179

[10:13:02.780]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[10:13:31.964]     INFO: Test took 29184ms.

[10:13:32.241]     INFO: Fetched DAQ statistics. Counters are being reset now.

[10:13:32.303]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0

[10:13:33.643]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1

[10:13:34.925]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2

[10:13:36.201]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3

[10:13:37.517]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4

[10:13:38.838]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5

[10:13:40.170]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6

[10:13:41.488]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7

[10:13:42.830]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8

[10:13:44.145]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9

[10:13:45.436]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10

[10:13:46.690]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11

[10:13:47.984]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12

[10:13:49.282]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13

[10:13:50.589]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14

[10:13:51.896]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15

[10:13:53.207]    DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 574541824

[10:13:53.207]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 0 step 0: thr difference mean: 9.54844, thr difference RMS: 1.66566

[10:13:53.208]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 1 step 0: thr difference mean: 11.9943, thr difference RMS: 1.40129

[10:13:53.208]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 2 step 0: thr difference mean: 12.0675, thr difference RMS: 1.31695

[10:13:53.208]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 3 step 0: thr difference mean: 11.6681, thr difference RMS: 1.37633

[10:13:53.208]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 4 step 0: thr difference mean: 10.4538, thr difference RMS: 0.996692

[10:13:53.208]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 5 step 0: thr difference mean: 11.3931, thr difference RMS: 1.28032

[10:13:53.208]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 6 step 0: thr difference mean: 11.1504, thr difference RMS: 1.16144

[10:13:53.209]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 7 step 0: thr difference mean: 10.0968, thr difference RMS: 1.73944

[10:13:53.209]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 8 step 0: thr difference mean: 11.0966, thr difference RMS: 1.29751

[10:13:53.209]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 9 step 0: thr difference mean: 11.1125, thr difference RMS: 1.03971

[10:13:53.209]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 10 step 0: thr difference mean: 11.223, thr difference RMS: 1.48888

[10:13:53.209]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 11 step 0: thr difference mean: 11.9092, thr difference RMS: 1.153

[10:13:53.209]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 12 step 0: thr difference mean: 10.4357, thr difference RMS: 1.04539

[10:13:53.210]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 13 step 0: thr difference mean: 11.2273, thr difference RMS: 1.05547

[10:13:53.210]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 14 step 0: thr difference mean: 12.3607, thr difference RMS: 1.23201

[10:13:53.210]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 15 step 0: thr difference mean: 12.2473, thr difference RMS: 1.20387

[10:13:53.210]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 0 step 1: thr difference mean: 9.38234, thr difference RMS: 1.65106

[10:13:53.210]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 1 step 1: thr difference mean: 11.7493, thr difference RMS: 1.41628

[10:13:53.210]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 2 step 1: thr difference mean: 11.8084, thr difference RMS: 1.33649

[10:13:53.211]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 3 step 1: thr difference mean: 11.5929, thr difference RMS: 1.31635

[10:13:53.211]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 4 step 1: thr difference mean: 10.3433, thr difference RMS: 0.992629

[10:13:53.211]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 5 step 1: thr difference mean: 11.5265, thr difference RMS: 1.25946

[10:13:53.211]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 6 step 1: thr difference mean: 11.2375, thr difference RMS: 1.12939

[10:13:53.211]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 7 step 1: thr difference mean: 10.2879, thr difference RMS: 1.74581

[10:13:53.211]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 8 step 1: thr difference mean: 11.2746, thr difference RMS: 1.28865

[10:13:53.212]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 9 step 1: thr difference mean: 11.2265, thr difference RMS: 1.02415

[10:13:53.212]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 10 step 1: thr difference mean: 11.0111, thr difference RMS: 1.44775

[10:13:53.212]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 11 step 1: thr difference mean: 11.957, thr difference RMS: 1.1306

[10:13:53.212]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 12 step 1: thr difference mean: 10.1883, thr difference RMS: 1.07399

[10:13:53.212]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 13 step 1: thr difference mean: 11.1564, thr difference RMS: 1.05571

[10:13:53.212]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 14 step 1: thr difference mean: 12.2612, thr difference RMS: 1.21334

[10:13:53.213]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 15 step 1: thr difference mean: 11.7576, thr difference RMS: 1.17826

[10:13:53.213]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 0 step 2: thr difference mean: 9.34347, thr difference RMS: 1.65049

[10:13:53.213]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 1 step 2: thr difference mean: 12.0424, thr difference RMS: 1.36996

[10:13:53.213]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 2 step 2: thr difference mean: 12.0614, thr difference RMS: 1.29627

[10:13:53.213]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 3 step 2: thr difference mean: 11.8067, thr difference RMS: 1.34018

[10:13:53.214]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 4 step 2: thr difference mean: 10.3342, thr difference RMS: 0.989321

[10:13:53.214]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 5 step 2: thr difference mean: 11.5472, thr difference RMS: 1.26458

[10:13:53.214]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 6 step 2: thr difference mean: 11.3311, thr difference RMS: 1.12449

[10:13:53.214]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 7 step 2: thr difference mean: 10.3533, thr difference RMS: 1.75805

[10:13:53.214]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 8 step 2: thr difference mean: 11.0824, thr difference RMS: 1.27668

[10:13:53.214]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 9 step 2: thr difference mean: 11.3105, thr difference RMS: 0.997829

[10:13:53.215]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 10 step 2: thr difference mean: 11.231, thr difference RMS: 1.46291

[10:13:53.215]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 11 step 2: thr difference mean: 12.3099, thr difference RMS: 1.11674

[10:13:53.215]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 12 step 2: thr difference mean: 10.6281, thr difference RMS: 1.06571

[10:13:53.215]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 13 step 2: thr difference mean: 11.4457, thr difference RMS: 1.02996

[10:13:53.215]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 14 step 2: thr difference mean: 12.4681, thr difference RMS: 1.2069

[10:13:53.215]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 15 step 2: thr difference mean: 12.1281, thr difference RMS: 1.20528

[10:13:53.216]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 0 step 3: thr difference mean: 9.70093, thr difference RMS: 1.67532

[10:13:53.216]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 1 step 3: thr difference mean: 12.0501, thr difference RMS: 1.3894

[10:13:53.216]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 2 step 3: thr difference mean: 12.2458, thr difference RMS: 1.28682

[10:13:53.216]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 3 step 3: thr difference mean: 12.011, thr difference RMS: 1.34165

[10:13:53.216]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 4 step 3: thr difference mean: 10.4908, thr difference RMS: 0.979056

[10:13:53.216]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 5 step 3: thr difference mean: 12.0236, thr difference RMS: 1.28336

[10:13:53.217]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 6 step 3: thr difference mean: 11.5077, thr difference RMS: 1.13024

[10:13:53.217]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 7 step 3: thr difference mean: 10.7884, thr difference RMS: 1.73515

[10:13:53.217]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 8 step 3: thr difference mean: 11.3329, thr difference RMS: 1.26881

[10:13:53.217]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 9 step 3: thr difference mean: 11.5224, thr difference RMS: 1.00519

[10:13:53.217]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 10 step 3: thr difference mean: 11.2881, thr difference RMS: 1.4215

[10:13:53.217]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 11 step 3: thr difference mean: 12.6486, thr difference RMS: 1.06521

[10:13:53.218]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 12 step 3: thr difference mean: 10.6442, thr difference RMS: 1.05201

[10:13:53.218]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 13 step 3: thr difference mean: 11.6632, thr difference RMS: 1.01145

[10:13:53.218]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 14 step 3: thr difference mean: 12.5915, thr difference RMS: 1.20598

[10:13:53.218]    DEBUG: <PixTestTrim.cc/trimBitTest:L559> ROC 15 step 3: thr difference mean: 11.9822, thr difference RMS: 1.14267

[10:13:53.333]     INFO: PixTestTrim::trimBitTest() done 

[10:13:53.335]     INFO: PixTestTrim::doTest() done, duration: 2363 seconds

[10:13:53.335]    DEBUG: <PixTestTrim.cc/~PixTestTrim:L104> PixTestTrim dtor

[10:13:53.909]    DEBUG: <PixTest.cc/setTestParameter:L569>  setting  ntrig to new value 10

[10:13:53.909]    DEBUG: <PixTestPhOptimization.cc/setParameter:L37>   setting fParNtrig  ->10<- from sval = 10

[10:13:53.909]    DEBUG: <PixTestPhOptimization.cc/setParameter:L42>   setting fSafetyMarginLow  ->20<- from sval = 20

[10:13:53.909]    DEBUG: <PixTestPhOptimization.cc/setParameter:L48>   setting fVcalMax  ->100<- from sval = 100

[10:13:53.909]    DEBUG: <PixTestPhOptimization.cc/setParameter:L53>   setting fQuantMax  ->0.98<- from sval = 0.98

[10:13:53.909]     INFO: ######################################################################

[10:13:53.909]     INFO: PixTestPhOptimization::doTest() Ntrig = 10

[10:13:53.909]     INFO: ######################################################################

[10:13:53.911]    DEBUG: <PixTest.cc/efficiencyMaps:L328>       attempt #0

[10:13:57.861]     INFO: Test took 3950ms.

[10:13:57.884]     INFO: Fetched DAQ statistics. Counters are being reset now.

[10:13:57.884]    DEBUG: <PixTest.cc/efficiencyMaps:L339>  eff result size = 66543

[10:13:57.884]    DEBUG: <PixTest.cc/efficiencyMaps:L344> Create hists PixelAlive_C0 .. PixelAlive_C15

[10:13:57.887]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [2, 40, 74] has eff 0/10

[10:13:57.887]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [2, 40, 74]

[10:13:57.887]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [3, 49, 31] has eff 0/10

[10:13:57.887]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [3, 49, 31]

[10:13:57.887]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [3, 49, 49] has eff 1/10

[10:13:57.887]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [3, 49, 49]

[10:13:57.887]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [3, 43, 66] has eff 0/10

[10:13:57.887]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [3, 43, 66]

[10:13:57.888]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [4, 50, 36] has eff 0/10

[10:13:57.888]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [4, 50, 36]

[10:13:57.888]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [5, 38, 42] has eff 0/10

[10:13:57.888]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [5, 38, 42]

[10:13:57.888]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [5, 41, 43] has eff 3/10

[10:13:57.888]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [5, 41, 43]

[10:13:57.888]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [5, 50, 78] has eff 0/10

[10:13:57.888]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [5, 50, 78]

[10:13:57.888]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [6, 47, 77] has eff 0/10

[10:13:57.888]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [6, 47, 77]

[10:13:57.888]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [6, 48, 79] has eff 0/10

[10:13:57.888]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [6, 48, 79]

[10:13:57.888]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [6, 50, 79] has eff 0/10

[10:13:57.888]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [6, 50, 79]

[10:13:57.888]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [6, 51, 79] has eff 0/10

[10:13:57.888]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [6, 51, 79]

[10:13:57.888]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [7, 49, 0] has eff 0/10

[10:13:57.888]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [7, 49, 0]

[10:13:57.888]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [7, 50, 0] has eff 0/10

[10:13:57.888]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [7, 50, 0]

[10:13:57.888]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [7, 51, 0] has eff 0/10

[10:13:57.888]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [7, 51, 0]

[10:13:57.888]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [7, 51, 1] has eff 0/10

[10:13:57.888]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [7, 51, 1]

[10:13:57.888]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [8, 0, 0] has eff 0/10

[10:13:57.888]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [8, 0, 0]

[10:13:57.888]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [8, 1, 0] has eff 0/10

[10:13:57.888]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [8, 1, 0]

[10:13:57.888]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [8, 2, 0] has eff 0/10

[10:13:57.888]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [8, 2, 0]

[10:13:57.888]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [9, 51, 20] has eff 2/10

[10:13:57.888]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [9, 51, 20]

[10:13:57.893]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L239> Number of bad pixels found: 20

[10:13:57.893]    DEBUG: <PixTestPhOptimization.cc/doTest:L124> **********Ph range will be optimised on the whole ROC***********

[10:13:57.893]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L276> ROC type is newer than digv2

[10:13:57.893]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L277> ROC type is psi46digv21respin

[10:13:58.150]    DEBUG: <PixTest.cc/phMaps:L264>       attempt #0

[10:14:02.094]     INFO: Test took 3944ms.

[10:14:02.160]     INFO: Fetched DAQ statistics. Counters are being reset now.

[10:14:02.160]    DEBUG: <PixTest.cc/phMaps:L275>  eff result size = 66544

[10:14:02.160]    DEBUG: <PixTest.cc/phMaps:L282> Create hists maxphmap_C0 .. maxphmap_C15

[10:14:02.164]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 167.715

[10:14:02.164]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,5] phvalue 168

[10:14:02.164]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 184.375

[10:14:02.164]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,5] phvalue 184

[10:14:02.164]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 185.116

[10:14:02.164]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,6] phvalue 185

[10:14:02.164]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 185.047

[10:14:02.164]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [12 ,5] phvalue 186

[10:14:02.164]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 170.296

[10:14:02.164]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [5 ,15] phvalue 170

[10:14:02.164]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 185.168

[10:14:02.164]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [4 ,5] phvalue 185

[10:14:02.164]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 190.659

[10:14:02.164]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,5] phvalue 191

[10:14:02.165]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 180.801

[10:14:02.165]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,17] phvalue 180

[10:14:02.165]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 178.828

[10:14:02.165]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,10] phvalue 178

[10:14:02.165]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 179.608

[10:14:02.165]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,5] phvalue 180

[10:14:02.165]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 181.33

[10:14:02.165]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [6 ,6] phvalue 181

[10:14:02.165]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 172.686

[10:14:02.165]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,5] phvalue 172

[10:14:02.165]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 174.76

[10:14:02.165]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [8 ,5] phvalue 174

[10:14:02.165]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 178.144

[10:14:02.165]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [4 ,6] phvalue 179

[10:14:02.165]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 191.849

[10:14:02.165]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,6] phvalue 192

[10:14:02.166]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 176.345

[10:14:02.166]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [4 ,5] phvalue 177

[10:14:02.166]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L427> ROC type is newer than digv2

[10:14:02.166]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L428> ROC type is psi46digv21respin

[10:14:02.166]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L450> init_phScale=150, flag_minPh = 0, minph = 0

[10:14:02.174]    DEBUG: <PixTest.cc/phMaps:L264>       attempt #0

[10:14:06.192]     INFO: Test took 4018ms.

[10:14:06.258]     INFO: Fetched DAQ statistics. Counters are being reset now.

[10:14:06.258]    DEBUG: <PixTest.cc/phMaps:L275>  eff result size = 66543

[10:14:06.258]    DEBUG: <PixTest.cc/phMaps:L282> Create hists minphmap_C0 .. minphmap_C15

[10:14:06.261]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L457> result size 0

[10:14:06.262]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L484> done. init_phScale=155, flag_minPh = 1, minph = 60minph_roc = 1

[10:14:06.262]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 65.9086

[10:14:06.262]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [6 ,12] phvalue 66

[10:14:06.262]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 63.0054

[10:14:06.262]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [4 ,50] phvalue 64

[10:14:06.262]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 78.3579

[10:14:06.262]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [4 ,42] phvalue 79

[10:14:06.262]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 85.1693

[10:14:06.262]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,13] phvalue 86

[10:14:06.262]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 60.8241

[10:14:06.262]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,66] phvalue 61

[10:14:06.262]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 80.7758

[10:14:06.262]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,12] phvalue 80

[10:14:06.263]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 92.3308

[10:14:06.263]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,68] phvalue 93

[10:14:06.263]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 80.6863

[10:14:06.263]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,32] phvalue 81

[10:14:06.263]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 78.1457

[10:14:06.263]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,61] phvalue 79

[10:14:06.263]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 75.1494

[10:14:06.263]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [4 ,48] phvalue 76

[10:14:06.263]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 68.1181

[10:14:06.263]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,26] phvalue 69

[10:14:06.263]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 75.4815

[10:14:06.263]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,62] phvalue 76

[10:14:06.263]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 70.9029

[10:14:06.263]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [4 ,14] phvalue 70

[10:14:06.263]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 78.2364

[10:14:06.263]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,12] phvalue 79

[10:14:06.264]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 88.9173

[10:14:06.264]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [4 ,66] phvalue 89

[10:14:06.264]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 64.162

[10:14:06.264]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,25] phvalue 65

[10:14:06.266]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 6, 12, 0 0

[10:14:06.266]     INFO: The DUT currently contains the following objects:

[10:14:06.266]     INFO:  2 TBM Cores tbm08c (2 ON)

[10:14:06.266]     INFO: 	TBM Core alpha (0): 7 registers set

[10:14:06.266]     INFO: 	TBM Core beta  (1): 7 registers set

[10:14:06.266]     INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs

[10:14:06.266]     INFO: 	ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:06.266]     INFO: 	ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:06.266]     INFO: 	ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:06.266]     INFO: 	ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:06.266]     INFO: 	ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:06.266]     INFO: 	ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:06.266]     INFO: 	ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:06.266]     INFO: 	ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:06.266]     INFO: 	ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:06.266]     INFO: 	ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:06.266]     INFO: 	ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:06.266]     INFO: 	ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:06.266]     INFO: 	ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:06.266]     INFO: 	ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:06.266]     INFO: 	ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:06.266]     INFO: 	ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:07.495]     INFO: Test took 1229ms.

[10:14:07.496]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256

[10:14:07.496]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 4, 50, 1 1

[10:14:07.496]     INFO: The DUT currently contains the following objects:

[10:14:07.496]     INFO:  2 TBM Cores tbm08c (2 ON)

[10:14:07.496]     INFO: 	TBM Core alpha (0): 7 registers set

[10:14:07.496]     INFO: 	TBM Core beta  (1): 7 registers set

[10:14:07.496]     INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs

[10:14:07.496]     INFO: 	ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:07.496]     INFO: 	ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:07.496]     INFO: 	ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:07.496]     INFO: 	ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:07.496]     INFO: 	ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:07.496]     INFO: 	ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:07.496]     INFO: 	ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:07.496]     INFO: 	ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:07.496]     INFO: 	ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:07.496]     INFO: 	ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:07.496]     INFO: 	ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:07.496]     INFO: 	ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:07.496]     INFO: 	ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:07.496]     INFO: 	ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:07.496]     INFO: 	ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:07.496]     INFO: 	ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:08.727]     INFO: Test took 1231ms.

[10:14:08.727]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256

[10:14:08.727]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 4, 42, 2 2

[10:14:08.727]     INFO: The DUT currently contains the following objects:

[10:14:08.727]     INFO:  2 TBM Cores tbm08c (2 ON)

[10:14:08.727]     INFO: 	TBM Core alpha (0): 7 registers set

[10:14:08.727]     INFO: 	TBM Core beta  (1): 7 registers set

[10:14:08.727]     INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs

[10:14:08.727]     INFO: 	ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:08.727]     INFO: 	ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:08.727]     INFO: 	ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:08.727]     INFO: 	ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:08.727]     INFO: 	ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:08.727]     INFO: 	ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:08.727]     INFO: 	ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:08.727]     INFO: 	ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:08.727]     INFO: 	ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:08.727]     INFO: 	ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:08.727]     INFO: 	ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:08.727]     INFO: 	ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:08.727]     INFO: 	ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:08.727]     INFO: 	ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:08.728]     INFO: 	ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:08.728]     INFO: 	ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:09.957]     INFO: Test took 1229ms.

[10:14:09.958]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256

[10:14:09.958]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 13, 3 3

[10:14:09.958]     INFO: The DUT currently contains the following objects:

[10:14:09.958]     INFO:  2 TBM Cores tbm08c (2 ON)

[10:14:09.958]     INFO: 	TBM Core alpha (0): 7 registers set

[10:14:09.958]     INFO: 	TBM Core beta  (1): 7 registers set

[10:14:09.958]     INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs

[10:14:09.958]     INFO: 	ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:09.958]     INFO: 	ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:09.958]     INFO: 	ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:09.958]     INFO: 	ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:09.958]     INFO: 	ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:09.958]     INFO: 	ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:09.958]     INFO: 	ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:09.958]     INFO: 	ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:09.958]     INFO: 	ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:09.958]     INFO: 	ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:09.958]     INFO: 	ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:09.958]     INFO: 	ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:09.958]     INFO: 	ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:09.958]     INFO: 	ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:09.958]     INFO: 	ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:09.958]     INFO: 	ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:11.187]     INFO: Test took 1229ms.

[10:14:11.188]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256

[10:14:11.189]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 66, 4 4

[10:14:11.189]     INFO: The DUT currently contains the following objects:

[10:14:11.189]     INFO:  2 TBM Cores tbm08c (2 ON)

[10:14:11.189]     INFO: 	TBM Core alpha (0): 7 registers set

[10:14:11.189]     INFO: 	TBM Core beta  (1): 7 registers set

[10:14:11.189]     INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs

[10:14:11.189]     INFO: 	ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:11.189]     INFO: 	ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:11.189]     INFO: 	ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:11.189]     INFO: 	ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:11.189]     INFO: 	ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:11.189]     INFO: 	ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:11.189]     INFO: 	ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:11.189]     INFO: 	ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:11.189]     INFO: 	ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:11.189]     INFO: 	ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:11.189]     INFO: 	ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:11.189]     INFO: 	ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:11.189]     INFO: 	ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:11.189]     INFO: 	ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:11.189]     INFO: 	ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:11.189]     INFO: 	ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:12.416]     INFO: Test took 1227ms.

[10:14:12.417]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256

[10:14:12.417]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 12, 5 5

[10:14:12.417]     INFO: The DUT currently contains the following objects:

[10:14:12.417]     INFO:  2 TBM Cores tbm08c (2 ON)

[10:14:12.417]     INFO: 	TBM Core alpha (0): 7 registers set

[10:14:12.417]     INFO: 	TBM Core beta  (1): 7 registers set

[10:14:12.417]     INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs

[10:14:12.417]     INFO: 	ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:12.417]     INFO: 	ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:12.417]     INFO: 	ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:12.417]     INFO: 	ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:12.417]     INFO: 	ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:12.417]     INFO: 	ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:12.417]     INFO: 	ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:12.417]     INFO: 	ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:12.417]     INFO: 	ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:12.417]     INFO: 	ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:12.417]     INFO: 	ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:12.417]     INFO: 	ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:12.417]     INFO: 	ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:12.417]     INFO: 	ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:12.417]     INFO: 	ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:12.417]     INFO: 	ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:13.646]     INFO: Test took 1229ms.

[10:14:13.647]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256

[10:14:13.647]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 68, 6 6

[10:14:13.647]     INFO: The DUT currently contains the following objects:

[10:14:13.647]     INFO:  2 TBM Cores tbm08c (2 ON)

[10:14:13.647]     INFO: 	TBM Core alpha (0): 7 registers set

[10:14:13.647]     INFO: 	TBM Core beta  (1): 7 registers set

[10:14:13.647]     INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs

[10:14:13.647]     INFO: 	ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:13.647]     INFO: 	ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:13.647]     INFO: 	ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:13.647]     INFO: 	ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:13.647]     INFO: 	ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:13.647]     INFO: 	ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:13.647]     INFO: 	ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:13.647]     INFO: 	ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:13.647]     INFO: 	ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:13.647]     INFO: 	ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:13.647]     INFO: 	ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:13.647]     INFO: 	ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:13.647]     INFO: 	ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:13.647]     INFO: 	ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:13.647]     INFO: 	ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:13.648]     INFO: 	ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:14.878]     INFO: Test took 1230ms.

[10:14:14.878]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256

[10:14:14.879]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 32, 7 7

[10:14:14.879]     INFO: The DUT currently contains the following objects:

[10:14:14.879]     INFO:  2 TBM Cores tbm08c (2 ON)

[10:14:14.879]     INFO: 	TBM Core alpha (0): 7 registers set

[10:14:14.879]     INFO: 	TBM Core beta  (1): 7 registers set

[10:14:14.879]     INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs

[10:14:14.879]     INFO: 	ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:14.879]     INFO: 	ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:14.879]     INFO: 	ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:14.879]     INFO: 	ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:14.879]     INFO: 	ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:14.879]     INFO: 	ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:14.879]     INFO: 	ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:14.879]     INFO: 	ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:14.879]     INFO: 	ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:14.879]     INFO: 	ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:14.879]     INFO: 	ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:14.879]     INFO: 	ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:14.879]     INFO: 	ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:14.879]     INFO: 	ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:14.879]     INFO: 	ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:14.879]     INFO: 	ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:16.108]     INFO: Test took 1229ms.

[10:14:16.109]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256

[10:14:16.109]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 61, 8 8

[10:14:16.109]     INFO: The DUT currently contains the following objects:

[10:14:16.109]     INFO:  2 TBM Cores tbm08c (2 ON)

[10:14:16.109]     INFO: 	TBM Core alpha (0): 7 registers set

[10:14:16.109]     INFO: 	TBM Core beta  (1): 7 registers set

[10:14:16.109]     INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs

[10:14:16.109]     INFO: 	ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:16.110]     INFO: 	ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:16.110]     INFO: 	ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:16.110]     INFO: 	ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:16.110]     INFO: 	ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:16.110]     INFO: 	ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:16.110]     INFO: 	ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:16.110]     INFO: 	ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:16.110]     INFO: 	ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:16.110]     INFO: 	ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:16.110]     INFO: 	ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:16.110]     INFO: 	ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:16.110]     INFO: 	ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:16.110]     INFO: 	ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:16.110]     INFO: 	ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:16.110]     INFO: 	ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:17.339]     INFO: Test took 1229ms.

[10:14:17.340]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256

[10:14:17.340]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 4, 48, 9 9

[10:14:17.340]     INFO: The DUT currently contains the following objects:

[10:14:17.340]     INFO:  2 TBM Cores tbm08c (2 ON)

[10:14:17.340]     INFO: 	TBM Core alpha (0): 7 registers set

[10:14:17.340]     INFO: 	TBM Core beta  (1): 7 registers set

[10:14:17.340]     INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs

[10:14:17.340]     INFO: 	ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:17.340]     INFO: 	ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:17.340]     INFO: 	ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:17.340]     INFO: 	ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:17.340]     INFO: 	ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:17.340]     INFO: 	ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:17.340]     INFO: 	ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:17.340]     INFO: 	ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:17.340]     INFO: 	ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:17.340]     INFO: 	ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:17.340]     INFO: 	ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:17.340]     INFO: 	ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:17.340]     INFO: 	ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:17.340]     INFO: 	ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:17.341]     INFO: 	ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:17.341]     INFO: 	ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:18.570]     INFO: Test took 1229ms.

[10:14:18.571]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256

[10:14:18.571]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 26, 10 10

[10:14:18.571]     INFO: The DUT currently contains the following objects:

[10:14:18.571]     INFO:  2 TBM Cores tbm08c (2 ON)

[10:14:18.572]     INFO: 	TBM Core alpha (0): 7 registers set

[10:14:18.572]     INFO: 	TBM Core beta  (1): 7 registers set

[10:14:18.572]     INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs

[10:14:18.572]     INFO: 	ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:18.572]     INFO: 	ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:18.572]     INFO: 	ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:18.572]     INFO: 	ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:18.572]     INFO: 	ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:18.572]     INFO: 	ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:18.572]     INFO: 	ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:18.572]     INFO: 	ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:18.572]     INFO: 	ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:18.572]     INFO: 	ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:18.572]     INFO: 	ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:18.572]     INFO: 	ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:18.572]     INFO: 	ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:18.572]     INFO: 	ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:18.572]     INFO: 	ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:18.572]     INFO: 	ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:19.802]     INFO: Test took 1230ms.

[10:14:19.802]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256

[10:14:19.803]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 62, 11 11

[10:14:19.803]     INFO: The DUT currently contains the following objects:

[10:14:19.803]     INFO:  2 TBM Cores tbm08c (2 ON)

[10:14:19.803]     INFO: 	TBM Core alpha (0): 7 registers set

[10:14:19.803]     INFO: 	TBM Core beta  (1): 7 registers set

[10:14:19.803]     INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs

[10:14:19.803]     INFO: 	ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:19.803]     INFO: 	ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:19.803]     INFO: 	ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:19.803]     INFO: 	ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:19.803]     INFO: 	ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:19.803]     INFO: 	ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:19.803]     INFO: 	ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:19.803]     INFO: 	ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:19.803]     INFO: 	ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:19.803]     INFO: 	ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:19.803]     INFO: 	ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:19.803]     INFO: 	ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:19.803]     INFO: 	ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:19.803]     INFO: 	ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:19.803]     INFO: 	ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:19.803]     INFO: 	ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:21.049]     INFO: Test took 1246ms.

[10:14:21.050]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256

[10:14:21.050]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 4, 14, 12 12

[10:14:21.050]     INFO: The DUT currently contains the following objects:

[10:14:21.050]     INFO:  2 TBM Cores tbm08c (2 ON)

[10:14:21.050]     INFO: 	TBM Core alpha (0): 7 registers set

[10:14:21.050]     INFO: 	TBM Core beta  (1): 7 registers set

[10:14:21.050]     INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs

[10:14:21.050]     INFO: 	ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:21.050]     INFO: 	ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:21.050]     INFO: 	ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:21.050]     INFO: 	ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:21.050]     INFO: 	ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:21.050]     INFO: 	ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:21.050]     INFO: 	ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:21.050]     INFO: 	ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:21.050]     INFO: 	ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:21.050]     INFO: 	ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:21.050]     INFO: 	ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:21.050]     INFO: 	ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:21.050]     INFO: 	ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:21.050]     INFO: 	ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:21.050]     INFO: 	ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:21.050]     INFO: 	ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:22.280]     INFO: Test took 1230ms.

[10:14:22.281]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256

[10:14:22.281]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 12, 13 13

[10:14:22.281]     INFO: The DUT currently contains the following objects:

[10:14:22.281]     INFO:  2 TBM Cores tbm08c (2 ON)

[10:14:22.281]     INFO: 	TBM Core alpha (0): 7 registers set

[10:14:22.281]     INFO: 	TBM Core beta  (1): 7 registers set

[10:14:22.281]     INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs

[10:14:22.281]     INFO: 	ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:22.281]     INFO: 	ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:22.281]     INFO: 	ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:22.281]     INFO: 	ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:22.281]     INFO: 	ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:22.281]     INFO: 	ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:22.281]     INFO: 	ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:22.281]     INFO: 	ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:22.281]     INFO: 	ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:22.281]     INFO: 	ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:22.281]     INFO: 	ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:22.281]     INFO: 	ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:22.281]     INFO: 	ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:22.281]     INFO: 	ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:22.281]     INFO: 	ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:22.281]     INFO: 	ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:23.511]     INFO: Test took 1229ms.

[10:14:23.512]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256

[10:14:23.512]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 4, 66, 14 14

[10:14:23.512]     INFO: The DUT currently contains the following objects:

[10:14:23.512]     INFO:  2 TBM Cores tbm08c (2 ON)

[10:14:23.512]     INFO: 	TBM Core alpha (0): 7 registers set

[10:14:23.512]     INFO: 	TBM Core beta  (1): 7 registers set

[10:14:23.512]     INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs

[10:14:23.512]     INFO: 	ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:23.512]     INFO: 	ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:23.512]     INFO: 	ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:23.512]     INFO: 	ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:23.513]     INFO: 	ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:23.513]     INFO: 	ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:23.513]     INFO: 	ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:23.513]     INFO: 	ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:23.513]     INFO: 	ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:23.513]     INFO: 	ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:23.513]     INFO: 	ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:23.513]     INFO: 	ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:23.513]     INFO: 	ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:23.513]     INFO: 	ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:23.513]     INFO: 	ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:23.513]     INFO: 	ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:24.743]     INFO: Test took 1230ms.

[10:14:24.744]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256

[10:14:24.744]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 25, 15 15

[10:14:24.744]     INFO: The DUT currently contains the following objects:

[10:14:24.744]     INFO:  2 TBM Cores tbm08c (2 ON)

[10:14:24.744]     INFO: 	TBM Core alpha (0): 7 registers set

[10:14:24.744]     INFO: 	TBM Core beta  (1): 7 registers set

[10:14:24.744]     INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs

[10:14:24.744]     INFO: 	ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:24.744]     INFO: 	ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:24.744]     INFO: 	ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:24.744]     INFO: 	ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:24.744]     INFO: 	ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:24.744]     INFO: 	ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:24.744]     INFO: 	ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:24.744]     INFO: 	ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:24.744]     INFO: 	ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:24.744]     INFO: 	ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:24.744]     INFO: 	ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:24.744]     INFO: 	ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:24.744]     INFO: 	ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:24.744]     INFO: 	ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:24.744]     INFO: 	ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:24.744]     INFO: 	ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.

[10:14:25.973]     INFO: Test took 1229ms.

[10:14:25.974]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256

[10:14:25.974]    DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 30 on ROC0

[10:14:25.974]    DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 28 on ROC1

[10:14:25.974]    DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 32 on ROC2

[10:14:25.974]    DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 29 on ROC3

[10:14:25.974]    DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 31 on ROC4

[10:14:25.974]    DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 33 on ROC5

[10:14:25.974]    DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 31 on ROC6

[10:14:25.974]    DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 32 on ROC7

[10:14:25.974]    DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 31 on ROC8

[10:14:25.974]    DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 32 on ROC9

[10:14:25.974]    DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 33 on ROC10

[10:14:25.974]    DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 33 on ROC11

[10:14:25.974]    DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 31 on ROC12

[10:14:25.974]    DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 32 on ROC13

[10:14:25.974]    DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 28 on ROC14

[10:14:25.974]    DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 32 on ROC15

[10:14:25.978]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[10:17:20.780]     INFO: Test took 174802ms.

[10:17:22.454]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[10:20:16.548]     INFO: Test took 174094ms.

[10:20:18.170]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component

[10:20:18.170]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip0

[10:20:18.170]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component

[10:20:18.171]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip1

[10:20:18.171]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component

[10:20:18.171]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip2

[10:20:18.171]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component

[10:20:18.171]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip3

[10:20:18.171]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component

[10:20:18.172]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip4

[10:20:18.172]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component

[10:20:18.172]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip5

[10:20:18.172]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component

[10:20:18.172]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip6

[10:20:18.172]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component

[10:20:18.173]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip7

[10:20:18.173]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component

[10:20:18.173]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip8

[10:20:18.173]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component

[10:20:18.174]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip9

[10:20:18.174]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component

[10:20:18.174]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip10

[10:20:18.174]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component

[10:20:18.174]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip11

[10:20:18.174]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component

[10:20:18.175]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip12

[10:20:18.175]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component

[10:20:18.175]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip13

[10:20:18.175]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component

[10:20:18.175]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip14

[10:20:18.175]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component

[10:20:18.176]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip15

[10:20:18.176]     INFO: safety margin for low PH: adding 0, margin is now 20

[10:20:18.181]     INFO: safety margin for low PH: adding 0, margin is now 20

[10:20:18.187]     INFO: safety margin for low PH: adding 0, margin is now 20

[10:20:18.192]     INFO: safety margin for low PH: adding 1, margin is now 21

[10:20:18.197]     INFO: safety margin for low PH: adding 2, margin is now 22

[10:20:18.203]     INFO: safety margin for low PH: adding 3, margin is now 23

[10:20:18.208]     INFO: safety margin for low PH: adding 4, margin is now 24

[10:20:18.214]     INFO: safety margin for low PH: adding 5, margin is now 25

[10:20:18.219]     INFO: safety margin for low PH: adding 0, margin is now 20

[10:20:18.225]     INFO: safety margin for low PH: adding 0, margin is now 20

[10:20:18.230]     INFO: safety margin for low PH: adding 0, margin is now 20

[10:20:18.236]     INFO: safety margin for low PH: adding 0, margin is now 20

[10:20:18.241]     INFO: safety margin for low PH: adding 0, margin is now 20

[10:20:18.247]     INFO: safety margin for low PH: adding 0, margin is now 20

[10:20:18.252]     INFO: safety margin for low PH: adding 1, margin is now 21

[10:20:18.257]     INFO: safety margin for low PH: adding 2, margin is now 22

[10:20:18.263]     INFO: safety margin for low PH: adding 3, margin is now 23

[10:20:18.268]     INFO: safety margin for low PH: adding 4, margin is now 24

[10:20:18.274]     INFO: safety margin for low PH: adding 5, margin is now 25

[10:20:18.279]     INFO: safety margin for low PH: adding 0, margin is now 20

[10:20:18.285]     INFO: safety margin for low PH: adding 0, margin is now 20

[10:20:18.290]     INFO: safety margin for low PH: adding 0, margin is now 20

[10:20:18.296]     INFO: safety margin for low PH: adding 0, margin is now 20

[10:20:18.301]     INFO: safety margin for low PH: adding 0, margin is now 20

[10:20:18.307]     INFO: safety margin for low PH: adding 1, margin is now 21

[10:20:18.312]     INFO: safety margin for low PH: adding 2, margin is now 22

[10:20:18.317]     INFO: safety margin for low PH: adding 3, margin is now 23

[10:20:18.323]     INFO: safety margin for low PH: adding 4, margin is now 24

[10:20:18.328]     INFO: safety margin for low PH: adding 0, margin is now 20

[10:20:18.334]     INFO: safety margin for low PH: adding 0, margin is now 20

[10:20:18.340]    DEBUG: <PixTestPhOptimization.cc/doTest:L172> optimisation done

[10:20:18.388]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C0.dat

[10:20:18.388]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C1.dat

[10:20:18.388]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C2.dat

[10:20:18.388]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C3.dat

[10:20:18.388]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C4.dat

[10:20:18.388]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C5.dat

[10:20:18.389]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C6.dat

[10:20:18.389]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C7.dat

[10:20:18.389]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C8.dat

[10:20:18.389]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C9.dat

[10:20:18.389]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C10.dat

[10:20:18.389]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C11.dat

[10:20:18.389]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C12.dat

[10:20:18.389]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C13.dat

[10:20:18.389]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C14.dat

[10:20:18.389]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//dacParameters35_C15.dat

[10:20:22.283]     INFO: Test took 3889ms.

[10:20:26.482]     INFO: Test took 3856ms.

[10:20:30.722]     INFO: Test took 3894ms.

[10:20:31.071]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[10:20:32.042]     INFO: Test took 972ms.

[10:20:32.045]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[10:20:33.273]     INFO: Test took 1228ms.

[10:20:33.276]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[10:20:34.505]     INFO: Test took 1229ms.

[10:20:34.508]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[10:20:35.741]     INFO: Test took 1233ms.

[10:20:35.744]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[10:20:36.974]     INFO: Test took 1230ms.

[10:20:36.977]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[10:20:38.207]     INFO: Test took 1230ms.

[10:20:38.210]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[10:20:39.438]     INFO: Test took 1228ms.

[10:20:39.442]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[10:20:40.671]     INFO: Test took 1229ms.

[10:20:40.674]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[10:20:41.902]     INFO: Test took 1228ms.

[10:20:41.906]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[10:20:43.133]     INFO: Test took 1227ms.

[10:20:43.137]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[10:20:44.365]     INFO: Test took 1228ms.

[10:20:44.368]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[10:20:45.597]     INFO: Test took 1229ms.

[10:20:45.600]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[10:20:46.829]     INFO: Test took 1229ms.

[10:20:46.832]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[10:20:48.060]     INFO: Test took 1228ms.

[10:20:48.063]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[10:20:49.293]     INFO: Test took 1230ms.

[10:20:49.297]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[10:20:50.525]     INFO: Test took 1229ms.

[10:20:50.528]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[10:20:51.758]     INFO: Test took 1230ms.

[10:20:51.762]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[10:20:52.989]     INFO: Test took 1227ms.

[10:20:52.993]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[10:20:54.220]     INFO: Test took 1227ms.

[10:20:54.223]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[10:20:55.450]     INFO: Test took 1227ms.

[10:20:55.453]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[10:20:56.681]     INFO: Test took 1228ms.

[10:20:56.684]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[10:20:57.912]     INFO: Test took 1228ms.

[10:20:57.915]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[10:20:59.143]     INFO: Test took 1228ms.

[10:20:59.147]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[10:21:00.374]     INFO: Test took 1227ms.

[10:21:00.378]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[10:21:01.606]     INFO: Test took 1229ms.

[10:21:01.609]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[10:21:02.837]     INFO: Test took 1229ms.

[10:21:02.840]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[10:21:04.068]     INFO: Test took 1228ms.

[10:21:04.071]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[10:21:05.301]     INFO: Test took 1230ms.

[10:21:05.304]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[10:21:06.533]     INFO: Test took 1229ms.

[10:21:06.536]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[10:21:07.765]     INFO: Test took 1229ms.

[10:21:07.769]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[10:21:08.999]     INFO: Test took 1230ms.

[10:21:09.002]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[10:21:10.231]     INFO: Test took 1229ms.

[10:21:10.884]     INFO: PixTestPhOptimization::doTest() done, duration: 436 seconds

[10:21:10.884]     INFO: PH scale (per ROC):    67  79  69  68  68  69  70  69  67  68  65  62  70  67  69  74

[10:21:10.884]     INFO: PH offset (per ROC):  187 180 176 173 191 175 161 175 176 177 184 179 182 176 166 186

[10:21:11.027]    DEBUG: <PixTestGainPedestal.cc/setParameter:L83> PixTestGainPedestal::PixTest() fVcalStep = 10

[10:21:11.029]     INFO: ######################################################################

[10:21:11.029]     INFO: PixTestGainPedestal::fullTest() ntrig = 10

[10:21:11.029]     INFO: ######################################################################

[10:21:11.029]    DEBUG: <PixTestGainPedestal.cc/measure:L192>  using FLAGS = 16

[10:21:11.040]     INFO: scanning low vcal = 10

[10:21:14.646]     INFO: Test took 3606ms.

[10:21:14.650]     INFO: scanning low vcal = 20

[10:21:18.340]     INFO: Test took 3690ms.

[10:21:18.344]     INFO: scanning low vcal = 30

[10:21:22.053]     INFO: Test took 3709ms.

[10:21:22.062]     INFO: scanning low vcal = 40

[10:21:26.121]     INFO: Test took 4059ms.

[10:21:26.179]     INFO: scanning low vcal = 50

[10:21:30.298]     INFO: Test took 4119ms.

[10:21:30.356]     INFO: scanning low vcal = 60

[10:21:34.501]     INFO: Test took 4145ms.

[10:21:34.561]     INFO: scanning low vcal = 70

[10:21:38.677]     INFO: Test took 4115ms.

[10:21:38.739]     INFO: scanning low vcal = 80

[10:21:42.851]     INFO: Test took 4111ms.

[10:21:42.911]     INFO: scanning low vcal = 90

[10:21:47.040]     INFO: Test took 4129ms.

[10:21:47.099]     INFO: scanning low vcal = 100

[10:21:51.224]     INFO: Test took 4125ms.

[10:21:51.284]     INFO: scanning low vcal = 110

[10:21:55.418]     INFO: Test took 4134ms.

[10:21:55.476]     INFO: scanning low vcal = 120

[10:21:59.612]     INFO: Test took 4136ms.

[10:21:59.670]     INFO: scanning low vcal = 130

[10:22:03.844]     INFO: Test took 4173ms.

[10:22:03.902]     INFO: scanning low vcal = 140

[10:22:08.077]     INFO: Test took 4175ms.

[10:22:08.135]     INFO: scanning low vcal = 150

[10:22:12.262]     INFO: Test took 4127ms.

[10:22:12.320]     INFO: scanning low vcal = 160

[10:22:16.449]     INFO: Test took 4129ms.

[10:22:16.508]     INFO: scanning low vcal = 170

[10:22:20.638]     INFO: Test took 4130ms.

[10:22:20.699]     INFO: scanning low vcal = 180

[10:22:24.831]     INFO: Test took 4131ms.

[10:22:24.891]     INFO: scanning low vcal = 190

[10:22:29.015]     INFO: Test took 4124ms.

[10:22:29.074]     INFO: scanning low vcal = 200

[10:22:33.200]     INFO: Test took 4126ms.

[10:22:33.264]     INFO: scanning low vcal = 210

[10:22:37.389]     INFO: Test took 4125ms.

[10:22:37.447]     INFO: scanning low vcal = 220

[10:22:41.570]     INFO: Test took 4123ms.

[10:22:41.628]     INFO: scanning low vcal = 230

[10:22:45.748]     INFO: Test took 4120ms.

[10:22:45.809]     INFO: scanning low vcal = 240

[10:22:49.928]     INFO: Test took 4119ms.

[10:22:49.987]     INFO: scanning low vcal = 250

[10:22:54.105]     INFO: Test took 4118ms.

[10:22:54.166]     INFO: scanning high vcal = 30 (= 210 in low range)

[10:22:58.283]     INFO: Test took 4117ms.

[10:22:58.344]     INFO: scanning high vcal = 50 (= 350 in low range)

[10:23:02.464]     INFO: Test took 4120ms.

[10:23:02.526]     INFO: scanning high vcal = 70 (= 490 in low range)

[10:23:06.647]     INFO: Test took 4121ms.

[10:23:06.706]     INFO: scanning high vcal = 90 (= 630 in low range)

[10:23:10.828]     INFO: Test took 4122ms.

[10:23:10.887]     INFO: scanning high vcal = 200 (= 1400 in low range)

[10:23:15.014]     INFO: Test took 4127ms.

[10:23:15.549]     INFO: PixTestGainPedestal::measure() done 

[10:23:15.551]    DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C0

[10:23:15.551]    DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C1

[10:23:15.551]    DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C2

[10:23:15.551]    DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C3

[10:23:15.552]    DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C4

[10:23:15.552]    DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C5

[10:23:15.552]    DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C6

[10:23:15.552]    DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C7

[10:23:15.552]    DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C8

[10:23:15.552]    DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C9

[10:23:15.552]    DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C10

[10:23:15.552]    DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C11

[10:23:15.553]    DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C12

[10:23:15.553]    DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C13

[10:23:15.553]    DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C14

[10:23:15.553]    DEBUG: <PixTestGainPedestal.cc/fit:L380> Create hist gainPedestalP1_C15

[10:23:45.776]     INFO: PixTestGainPedestal::fit() done

[10:23:45.776]     INFO: non-linearity mean:  0.960 0.959 0.965 0.965 0.956 0.965 0.964 0.956 0.959 0.958 0.954 0.951 0.960 0.970 0.955 0.957

[10:23:45.776]     INFO: non-linearity RMS:   0.006 0.008 0.005 0.006 0.007 0.005 0.006 0.006 0.005 0.007 0.010 0.007 0.005 0.004 0.006 0.006

[10:23:45.776]     INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//phCalibrationFitErr35_C0.dat

[10:23:45.793]     INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//phCalibrationFitErr35_C1.dat

[10:23:45.809]     INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//phCalibrationFitErr35_C2.dat

[10:23:45.826]     INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//phCalibrationFitErr35_C3.dat

[10:23:45.842]     INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//phCalibrationFitErr35_C4.dat

[10:23:45.859]     INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//phCalibrationFitErr35_C5.dat

[10:23:45.875]     INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//phCalibrationFitErr35_C6.dat

[10:23:45.892]     INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//phCalibrationFitErr35_C7.dat

[10:23:45.908]     INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//phCalibrationFitErr35_C8.dat

[10:23:45.925]     INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//phCalibrationFitErr35_C9.dat

[10:23:45.941]     INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//phCalibrationFitErr35_C10.dat

[10:23:45.958]     INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//phCalibrationFitErr35_C11.dat

[10:23:45.975]     INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//phCalibrationFitErr35_C12.dat

[10:23:45.991]     INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//phCalibrationFitErr35_C13.dat

[10:23:46.008]     INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//phCalibrationFitErr35_C14.dat

[10:23:46.024]     INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3022_FullQualification_2015-07-31_09h17m_1438327071//000_Fulltest_p17//phCalibrationFitErr35_C15.dat

[10:23:46.041]     INFO: PixTestGainPedestal::doTest() done, duration: 155 seconds

[10:23:46.041]    DEBUG: <PixTestGainPedestal.cc/~PixTestGainPedestal:L125> PixTestGainPedestal dtor

[10:23:46.047]    DEBUG: <PixTestFullTest.cc/~PixTestFullTest:L78> PixTestFullTest dtor

[10:23:46.047]     INFO: enter test to run

[10:23:46.047]     INFO:   test: q no parameter change

[10:23:46.047]    DEBUG: <PixMonitor.cc/dumpSummaries:L34> PixMonitor::dumpSummaries

[10:23:46.199]    QUIET: Connection to board 98 closed.

[10:23:46.200]     INFO: pXar: this is the end, my friend

[10:23:46.200]    DEBUG: <PixSetup.cc/~PixSetup:L68> PixSetup free fPxarMemory
MoReWeb-v0.6.7-17-g62372b6 on branch psi46master