MORE-Web

Test Date: 2015-06-26 09:57
Analysis date: 2015-10-28 15:42
Logfile
LogfileView
[17:34:23.481]     INFO: *** Welcome to pxar ***

[17:34:23.481]     INFO: *** Today: 2015/06/26

[17:34:23.481]     INFO: readRocDacs: /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//dacParameters_C0.dat .. /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//dacParameters_C15.dat

[17:34:23.481]     INFO: readTbmDacs: /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//tbmParameters_C0a.dat .. /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//tbmParameters_C0b.dat

[17:34:23.481]     INFO: readMaskFile: /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//defaultMaskFile.dat

[17:34:23.481]     INFO: readTrimFile: /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//trimParameters_C0.dat .. /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//trimParameters_C15.dat

[17:34:23.541]     INFO:         clk: 4

[17:34:23.541]     INFO:         ctr: 4

[17:34:23.541]     INFO:         sda: 19

[17:34:23.541]     INFO:         tin: 9

[17:34:23.541]     INFO:         level: 15

[17:34:23.541]     INFO:         triggerdelay: 0

[17:34:23.541]    QUIET: Instanciating API for pxar v2.2.4+51~gdb2a247

[17:34:23.541]     INFO: Log level: DEBUG

[17:34:23.554]    QUIET: Connection to board DTB_WV7UX2 opened.

[17:34:23.557]     INFO: DTB startup information

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

Board id:    105

HW version:  DTB1.2

FW version:  4.2

SW version:  4.2

USB id:      DTB_WV7UX2

MAC address: 40D855118069

Hostname:    pixelDTB105

Comment:     with CMOS buffer

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

[17:34:23.560]     INFO: RPC call hashes of host and DTB match: 447413373

[17:34:25.109]     INFO: DUT info: 

[17:34:25.109]     INFO: The DUT currently contains the following objects:

[17:34:25.109]     INFO:  2 TBM Cores tbm08c (2 ON)

[17:34:25.109]     INFO: 	TBM Core alpha (0): 7 registers set

[17:34:25.109]     INFO: 	TBM Core beta  (1): 7 registers set

[17:34:25.109]     INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs

[17:34:25.109]     INFO: 	ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.

[17:34:25.109]     INFO: 	ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.

[17:34:25.109]     INFO: 	ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.

[17:34:25.109]     INFO: 	ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.

[17:34:25.109]     INFO: 	ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.

[17:34:25.109]     INFO: 	ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.

[17:34:25.109]     INFO: 	ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.

[17:34:25.109]     INFO: 	ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.

[17:34:25.109]     INFO: 	ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.

[17:34:25.109]     INFO: 	ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.

[17:34:25.109]     INFO: 	ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.

[17:34:25.109]     INFO: 	ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.

[17:34:25.109]     INFO: 	ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.

[17:34:25.109]     INFO: 	ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.

[17:34:25.109]     INFO: 	ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.

[17:34:25.109]     INFO: 	ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.

[17:34:25.109]    DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->BB<-

[17:34:25.109]    DEBUG: <PixTestParameters.cc/dump:L107>   dumpall: checkbox(0)

[17:34:25.109]    DEBUG: <PixTestParameters.cc/dump:L107>   dumpproblematic: checkbox(0)

[17:34:25.109]    DEBUG: <PixTestParameters.cc/dump:L107>   ntrig: 5

[17:34:25.109]    DEBUG: <PixTestParameters.cc/dump:L107>   vcals: 250

[17:34:25.109]    DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->BB2<-

[17:34:25.109]    DEBUG: <PixTestParameters.cc/dump:L107>   ntrig: 10

[17:34:25.109]    DEBUG: <PixTestParameters.cc/dump:L107>   vcals: 222

[17:34:25.109]    DEBUG: <PixTestParameters.cc/dump:L107>   plwidth: 35

[17:34:25.109]    DEBUG: <PixTestParameters.cc/dump:L107>   pix: 11,20

[17:34:25.109]    DEBUG: <PixTestParameters.cc/dump:L107>   targetia: 24

[17:34:25.109]    DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->BB3<-

[17:34:25.109]    DEBUG: <PixTestParameters.cc/dump:L107>   dumpall: checkbox(0)

[17:34:25.109]    DEBUG: <PixTestParameters.cc/dump:L107>   dumpproblematic: checkbox(0)

[17:34:25.109]    DEBUG: <PixTestParameters.cc/dump:L107>   ntrig: 5

[17:34:25.109]    DEBUG: <PixTestParameters.cc/dump:L107>   vcals: 250

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->DacDacScan<-

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   phmap: checkbox

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   ntrig: 10

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   dac1: caldel

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   dac1lo: 0

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   dac1hi: 255

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   dac2: vthrcomp

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   dac2lo: 0

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   dac2hi: 255

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   pix: 11,20

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->DacScan<-

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   phmap: checkbox(1)

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   allpixels: checkbox(0)

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   unmasked: checkbox(0)

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   ntrig: 10

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   dac: vcal

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   daclo: 0

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   dachi: 255

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   pix: 11,20

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->GainPedestal<-

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   showfits: checkbox(0)

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   extended: checkbox(0)

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   dumphists: checkbox(0)

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   ntrig: 10

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   measure: button

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   fit: button

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   save: button

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->HighRate<-

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   pix: 11,20

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   maskhotpixels: button

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   savemaskfile: checkbox(0)

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   maskfilename: default

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   caldelscan: button

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   xpixelalive: button

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   ntrig: 50

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   vcal: 200

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   xnoisemaps: button

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   daclo: 0

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   dachi: 100

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   dacs/step: 20

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   rundaq: button

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   trgfrequency(khz): 20

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   runseconds: 2

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   triggerdelay: 20

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   delaytbm: checkbox

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   filltree: checkbox

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->IV<-

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   port: /dev/FIXME

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   voltagestart: 0

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   voltagestop: 600

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   voltagestep: 5

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   delay: 1

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   compliance(ua): 100

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->PhOptimization<-

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   ntrig: 10

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   safetymarginlow: 20

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   saturationvcal: 100

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   quantilesaturation: 0.98

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->PixelAlive<-

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   ntrig: 10

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   vcal: 200

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   alivetest: button

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   masktest: button

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   addressdecodingtest: button

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Pretest<-

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   programroc: button

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   targetia: 24

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   setvana: button

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   iterations: 100

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   settimings: button

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   findworkingpixel: button

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   setvthrcompcaldel: button

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   pix: 11,20

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   vcal: 250

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   deltavthrcomp: 50

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   fraccaldel: 0.5

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   ntrig: 5

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   savedacs: button

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Readback<-

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   calibratevd: button

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   calibrateva: button

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   calibrateia: button

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   readbackvbg: button

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   getcalibratedvbg: button

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   usecalvd: checkbox(1)

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   usecalva: checkbox(0)

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   setvana: button

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Scurves<-

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   adjustvcal: checkbox(1)

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   dumpall: checkbox(0)

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   dumpproblematic: checkbox(0)

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   dumpoutputfile: checkbox(0)

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   ntrig: 50

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   dac: VthrComp

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   daclo: 0

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   dachi: 200

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   dacs/step: 10

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   scurves: button

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Timing<-

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   fastscan: checkbox(0)

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   targetclk: 4

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   ntrig: 10

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   clocksdascan: button

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   phasescan: button

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   levelscan: button

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   tbmphasescan: button

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   rocdelayscan: button

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   timingtest: button

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   saveparameters: button

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Trim<-

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   trim: button

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   ntrig: 10

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   vcal: 35

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   trimbits: button

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Xray<-

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   maskhotpixels: button

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   savemaskfile: checkbox(0)

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   maskfilename: default

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   source: Ag

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   phrun: button

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   runseconds: 100

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   trgfrequency(khz): 100

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   ratescan: button

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   vthrcompmin: 10

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   vthrcompmax: 80

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   stepseconds: 5

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   delaytbm: checkbox

[17:34:25.110]    DEBUG: <PixTestParameters.cc/dump:L107>   filltree: checkbox

[17:34:25.111]    DEBUG: <PixSetup.cc/init:L81> PixSetup init start; getCurrentRSS() = 31670272

[17:34:25.111]    DEBUG: <PixSetup.cc/init:L87> fPixTestParameters = 0x198a7d0

[17:34:25.111]    DEBUG: <PixSetup.cc/init:L88>  fConfigParameters = 0x16e3980

[17:34:25.111]    DEBUG: <PixSetup.cc/init:L89>        fPxarMemory = 0x7f0f6dd94010

[17:34:25.111]    DEBUG: <PixSetup.cc/init:L90>         fPxarMemHi = 0x7f0f73fff510

[17:34:25.111]    DEBUG: <PixSetup.cc/init:L106> PixSetup init done;  getCurrentRSS() = 31727616 fPxarMemory = 0x7f0f6dd94010

[17:34:25.111]    DEBUG: <PixTestFactory.cc/PixTestFactory:L51> PixTestFactory::PixTestFactory()

[17:34:25.516]     INFO: enter 'restricted' command line mode

[17:34:25.516]     INFO: enter test to run

[17:34:25.516]     INFO:   test: Pretest no parameter change

[17:34:25.516]     INFO:   running: pretest

[17:34:25.521]     INFO: ######################################################################

[17:34:25.521]     INFO: PixTestPretest::doTest()

[17:34:25.521]     INFO: ######################################################################

[17:34:25.522]     INFO:    ----------------------------------------------------------------------

[17:34:25.522]     INFO:    PixTestPretest::programROC() 

[17:34:25.522]     INFO:    ----------------------------------------------------------------------

[17:34:43.545]     INFO: PixTestPretest::programROC() done: ROCs are all programmable

[17:34:43.545]     INFO: IA differences per ROC:  18.5 17.7 17.7 18.5 18.5 15.3 17.7 19.3 16.1 17.7 19.3 16.9 19.3 16.9 17.7 18.5

[17:34:43.613]     INFO:    ----------------------------------------------------------------------

[17:34:43.613]     INFO:    PixTestPretest::setVana() target Ia = 24 mA/ROC

[17:34:43.613]     INFO:    ----------------------------------------------------------------------

[17:34:43.716]    DEBUG: <PixTestPretest.cc/setVana:L254> offset current from other 15 ROCs is 68.5312 mA

[17:34:43.817]    DEBUG: <PixTestPretest.cc/setVana:L280> ROC 0 iter 0 Vana 78 Ia 23.8687 mA

[17:34:43.918]    DEBUG: <PixTestPretest.cc/setVana:L280> ROC 1 iter 0 Vana 78 Ia 23.0687 mA

[17:34:44.019]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC  1 iter  1 Vana  84 Ia 24.6688 mA

[17:34:44.120]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC  1 iter  2 Vana  81 Ia 24.6688 mA

[17:34:44.220]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC  1 iter  3 Vana  78 Ia 23.0687 mA

[17:34:44.321]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC  1 iter  4 Vana  84 Ia 24.6688 mA

[17:34:44.422]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC  1 iter  5 Vana  81 Ia 24.6688 mA

[17:34:44.523]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC  1 iter  6 Vana  78 Ia 23.0687 mA

[17:34:44.624]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC  1 iter  7 Vana  84 Ia 24.6688 mA

[17:34:44.725]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC  1 iter  8 Vana  81 Ia 24.6688 mA

[17:34:44.825]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC  1 iter  9 Vana  78 Ia 23.0687 mA

[17:34:44.925]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC  1 iter 10 Vana  84 Ia 24.6688 mA

[17:34:45.026]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC  1 iter 11 Vana  81 Ia 24.6688 mA

[17:34:45.127]    DEBUG: <PixTestPretest.cc/setVana:L280> ROC 2 iter 0 Vana 78 Ia 23.0687 mA

[17:34:45.228]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC  2 iter  1 Vana  84 Ia 23.8687 mA

[17:34:45.330]    DEBUG: <PixTestPretest.cc/setVana:L280> ROC 3 iter 0 Vana 78 Ia 23.0687 mA

[17:34:45.431]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC  3 iter  1 Vana  84 Ia 25.4688 mA

[17:34:45.531]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC  3 iter  2 Vana  76 Ia 23.0687 mA

[17:34:45.632]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC  3 iter  3 Vana  82 Ia 24.6688 mA

[17:34:45.733]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC  3 iter  4 Vana  79 Ia 23.0687 mA

[17:34:45.834]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC  3 iter  5 Vana  85 Ia 25.4688 mA

[17:34:45.935]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC  3 iter  6 Vana  77 Ia 23.0687 mA

[17:34:46.035]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC  3 iter  7 Vana  83 Ia 25.4688 mA

[17:34:46.136]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC  3 iter  8 Vana  75 Ia 23.0687 mA

[17:34:46.237]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC  3 iter  9 Vana  81 Ia 24.6688 mA

[17:34:46.337]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC  3 iter 10 Vana  78 Ia 23.0687 mA

[17:34:46.438]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC  3 iter 11 Vana  84 Ia 24.6688 mA

[17:34:46.540]    DEBUG: <PixTestPretest.cc/setVana:L280> ROC 4 iter 0 Vana 78 Ia 24.6688 mA

[17:34:46.640]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC  4 iter  1 Vana  75 Ia 23.8687 mA

[17:34:46.742]    DEBUG: <PixTestPretest.cc/setVana:L280> ROC 5 iter 0 Vana 78 Ia 20.6688 mA

[17:34:46.843]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC  5 iter  1 Vana  98 Ia 24.6688 mA

[17:34:46.944]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC  5 iter  2 Vana  95 Ia 24.6688 mA

[17:34:47.044]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC  5 iter  3 Vana  92 Ia 23.0687 mA

[17:34:47.145]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC  5 iter  4 Vana  98 Ia 24.6688 mA

[17:34:47.246]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC  5 iter  5 Vana  95 Ia 23.8687 mA

[17:34:47.347]    DEBUG: <PixTestPretest.cc/setVana:L280> ROC 6 iter 0 Vana 78 Ia 23.8687 mA

[17:34:47.449]    DEBUG: <PixTestPretest.cc/setVana:L280> ROC 7 iter 0 Vana 78 Ia 24.6688 mA

[17:34:47.549]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC  7 iter  1 Vana  75 Ia 23.8687 mA

[17:34:47.651]    DEBUG: <PixTestPretest.cc/setVana:L280> ROC 8 iter 0 Vana 78 Ia 22.2688 mA

[17:34:47.751]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC  8 iter  1 Vana  88 Ia 23.8687 mA

[17:34:47.853]    DEBUG: <PixTestPretest.cc/setVana:L280> ROC 9 iter 0 Vana 78 Ia 22.2688 mA

[17:34:47.953]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC  9 iter  1 Vana  88 Ia 24.6688 mA

[17:34:48.054]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC  9 iter  2 Vana  85 Ia 24.6688 mA

[17:34:48.155]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC  9 iter  3 Vana  82 Ia 23.8687 mA

[17:34:48.256]    DEBUG: <PixTestPretest.cc/setVana:L280> ROC 10 iter 0 Vana 78 Ia 23.8687 mA

[17:34:48.358]    DEBUG: <PixTestPretest.cc/setVana:L280> ROC 11 iter 0 Vana 78 Ia 22.2688 mA

[17:34:48.459]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter  1 Vana  88 Ia 24.6688 mA

[17:34:48.559]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter  2 Vana  85 Ia 24.6688 mA

[17:34:48.660]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC 11 iter  3 Vana  82 Ia 23.8687 mA

[17:34:48.761]    DEBUG: <PixTestPretest.cc/setVana:L280> ROC 12 iter 0 Vana 78 Ia 24.6688 mA

[17:34:48.862]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC 12 iter  1 Vana  75 Ia 23.8687 mA

[17:34:48.964]    DEBUG: <PixTestPretest.cc/setVana:L280> ROC 13 iter 0 Vana 78 Ia 22.2688 mA

[17:34:49.064]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter  1 Vana  88 Ia 24.6688 mA

[17:34:49.165]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC 13 iter  2 Vana  85 Ia 23.8687 mA

[17:34:49.267]    DEBUG: <PixTestPretest.cc/setVana:L280> ROC 14 iter 0 Vana 78 Ia 23.0687 mA

[17:34:49.368]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter  1 Vana  84 Ia 24.6688 mA

[17:34:49.468]    DEBUG: <PixTestPretest.cc/setVana:L312> ROC 14 iter  2 Vana  81 Ia 23.8687 mA

[17:34:49.570]    DEBUG: <PixTestPretest.cc/setVana:L280> ROC 15 iter 0 Vana 78 Ia 23.8687 mA

[17:34:49.614]    DEBUG: <PixTestPretest.cc/setVana:L343> ROC  0 Vana  78

[17:34:49.615]    DEBUG: <PixTestPretest.cc/setVana:L343> ROC  1 Vana  81

[17:34:49.615]    DEBUG: <PixTestPretest.cc/setVana:L343> ROC  2 Vana  84

[17:34:49.615]    DEBUG: <PixTestPretest.cc/setVana:L343> ROC  3 Vana  84

[17:34:49.615]    DEBUG: <PixTestPretest.cc/setVana:L343> ROC  4 Vana  75

[17:34:49.616]    DEBUG: <PixTestPretest.cc/setVana:L343> ROC  5 Vana  95

[17:34:49.616]    DEBUG: <PixTestPretest.cc/setVana:L343> ROC  6 Vana  78

[17:34:49.616]    DEBUG: <PixTestPretest.cc/setVana:L343> ROC  7 Vana  75

[17:34:49.616]    DEBUG: <PixTestPretest.cc/setVana:L343> ROC  8 Vana  88

[17:34:49.616]    DEBUG: <PixTestPretest.cc/setVana:L343> ROC  9 Vana  82

[17:34:49.616]    DEBUG: <PixTestPretest.cc/setVana:L343> ROC 10 Vana  78

[17:34:49.616]    DEBUG: <PixTestPretest.cc/setVana:L343> ROC 11 Vana  82

[17:34:49.617]    DEBUG: <PixTestPretest.cc/setVana:L343> ROC 12 Vana  75

[17:34:49.617]    DEBUG: <PixTestPretest.cc/setVana:L343> ROC 13 Vana  85

[17:34:49.617]    DEBUG: <PixTestPretest.cc/setVana:L343> ROC 14 Vana  81

[17:34:49.617]    DEBUG: <PixTestPretest.cc/setVana:L343> ROC 15 Vana  78

[17:34:49.720]     INFO: PixTestPretest::setVana() done, Module Ia 379.4 mA = 23.7125 mA/ROC

[17:34:49.721]     INFO:    ----------------------------------------------------------------------

[17:34:49.721]     INFO:    PixTestPreTest::setTimings()

[17:34:49.721]     INFO:    ----------------------------------------------------------------------

[17:34:49.721]    DEBUG: <PixTestPretest.cc/setTimings:L392> Testing Timing: Attempt #1

[17:34:50.686]     INFO: Fetched DAQ statistics. Counters are being reset now.

[17:34:50.686]     INFO: Decoding statistics:

[17:34:50.686]     INFO:   General information:

[17:34:50.686]     INFO: 	 16bit words read:         120

[17:34:50.686]     INFO: 	 valid events total:       10

[17:34:50.686]     INFO: 	 empty events:             10

[17:34:50.686]     INFO: 	 valid events with pixels: 0

[17:34:50.686]     INFO: 	 valid pixel hits:         0

[17:34:50.686]     INFO:   Event errors: 	           0

[17:34:50.686]     INFO: 	 start marker:             0

[17:34:50.686]     INFO: 	 stop marker:              0

[17:34:50.686]     INFO: 	 overflow:                 0

[17:34:50.686]     INFO: 	 invalid 5bit words:       0

[17:34:50.686]     INFO: 	 invalid XOR eye diagram:  0

[17:34:50.686]     INFO:   TBM errors: 		           0

[17:34:50.686]     INFO: 	 flawed TBM headers:       0

[17:34:50.686]     INFO: 	 flawed TBM trailers:      0

[17:34:50.686]     INFO: 	 event ID mismatches:      0

[17:34:50.686]     INFO:   ROC errors: 		           0

[17:34:50.686]     INFO: 	 missing ROC header(s):    0

[17:34:50.686]     INFO: 	 misplaced readback start: 0

[17:34:50.686]     INFO:   Pixel decoding errors:	   0

[17:34:50.686]     INFO: 	 pixel data incomplete:    0

[17:34:50.686]     INFO: 	 pixel address:            0

[17:34:50.686]     INFO: 	 pulse height fill bit:    0

[17:34:50.686]     INFO: 	 buffer corruption:        0

[17:34:50.686]     INFO:    ----------------------------------------------------------------------

[17:34:50.686]     INFO:    Default timings are good. No timing scan needed.

[17:34:50.686]     INFO:    ----------------------------------------------------------------------

[17:34:50.686]     INFO: Test took 965 ms.

[17:34:50.686]     INFO: PixTestPretest::setTimings() done.

[17:34:50.878]     INFO:    ----------------------------------------------------------------------

[17:34:50.878]     INFO:    PixTestPretest::findWorkingPixel()

[17:34:50.878]     INFO:    ----------------------------------------------------------------------

[17:34:58.042]     INFO: Test took 7161ms.

[17:34:58.269]    DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C0 OK, with vthrComp = 94 and Delta(CalDel) = 63

[17:34:58.271]    DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C1 OK, with vthrComp = 89 and Delta(CalDel) = 54

[17:34:58.273]    DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C2 OK, with vthrComp = 98 and Delta(CalDel) = 60

[17:34:58.275]    DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C3 OK, with vthrComp = 92 and Delta(CalDel) = 57

[17:34:58.277]    DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C4 OK, with vthrComp = 92 and Delta(CalDel) = 60

[17:34:58.279]    DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C5 OK, with vthrComp = 96 and Delta(CalDel) = 61

[17:34:58.281]    DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C6 OK, with vthrComp = 88 and Delta(CalDel) = 61

[17:34:58.283]    DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C7 OK, with vthrComp = 107 and Delta(CalDel) = 58

[17:34:58.285]    DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C8 OK, with vthrComp = 81 and Delta(CalDel) = 60

[17:34:58.288]    DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C9 OK, with vthrComp = 65 and Delta(CalDel) = 63

[17:34:58.290]    DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C10 OK, with vthrComp = 75 and Delta(CalDel) = 63

[17:34:58.292]    DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C11 OK, with vthrComp = 76 and Delta(CalDel) = 62

[17:34:58.294]    DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C12 OK, with vthrComp = 88 and Delta(CalDel) = 62

[17:34:58.296]    DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C13 OK, with vthrComp = 88 and Delta(CalDel) = 57

[17:34:58.298]    DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C14 OK, with vthrComp = 89 and Delta(CalDel) = 63

[17:34:58.300]    DEBUG: <PixTestPretest.cc/findWorkingPixel:L1051> fwp_c12_r22_C15 OK, with vthrComp = 95 and Delta(CalDel) = 57

[17:34:58.324]     INFO: Found working pixel in all ROCs: col/row = 12/22

[17:34:58.373]     INFO:    ----------------------------------------------------------------------

[17:34:58.373]     INFO:    PixTestPretest::setVthrCompCalDel()

[17:34:58.373]     INFO:    ----------------------------------------------------------------------

[17:35:05.560]     INFO: Test took 7182ms.

[17:35:05.611]    DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 138 +/- 31

[17:35:05.786]    DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 102 +/- 27

[17:35:05.788]    DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 109 +/- 29.5

[17:35:05.790]    DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 119 +/- 28

[17:35:05.792]    DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 127 +/- 30.5

[17:35:05.794]    DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 133 +/- 30.5

[17:35:05.796]    DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 133 +/- 31

[17:35:05.799]    DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 125 +/- 29.5

[17:35:05.801]    DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 133 +/- 31

[17:35:05.803]    DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 150 +/- 31

[17:35:05.805]    DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 143 +/- 32

[17:35:05.807]    DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 131 +/- 29.5

[17:35:05.810]    DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 138 +/- 30

[17:35:05.812]    DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 127 +/- 29.5

[17:35:05.814]    DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 138 +/- 31.5

[17:35:05.816]    DEBUG: <PixTestPretest.cc/setVthrCompCalDel:L580> CalDel: 110 +/- 30

[17:35:05.868]     INFO: PixTestPretest::setVthrCompCalDel() done

[17:35:05.868]     INFO: CalDel:      138   102   109   119   127   133   133   125   133   150   143   131   138   127   138   110

[17:35:05.868]     INFO: VthrComp:     51    51    54    51    51    51    51    51    51    51    51    51    51    51    51    51

[17:35:05.870]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//dacParameters_C0.dat

[17:35:05.871]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//dacParameters_C1.dat

[17:35:05.871]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//dacParameters_C2.dat

[17:35:05.871]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//dacParameters_C3.dat

[17:35:05.871]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//dacParameters_C4.dat

[17:35:05.871]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//dacParameters_C5.dat

[17:35:05.871]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//dacParameters_C6.dat

[17:35:05.871]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//dacParameters_C7.dat

[17:35:05.871]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//dacParameters_C8.dat

[17:35:05.871]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//dacParameters_C9.dat

[17:35:05.871]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//dacParameters_C10.dat

[17:35:05.871]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//dacParameters_C11.dat

[17:35:05.872]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//dacParameters_C12.dat

[17:35:05.872]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//dacParameters_C13.dat

[17:35:05.872]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//dacParameters_C14.dat

[17:35:05.872]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//dacParameters_C15.dat

[17:35:05.872]     INFO: PixTestPretest::doTest() done, duration: 40 seconds

[17:35:05.872]    DEBUG: <PixTestPretest.cc/~PixTestPretest:L134> PixTestPretest dtor

[17:35:05.941]     INFO: enter test to run

[17:35:05.941]     INFO:   test: Fulltest no parameter change

[17:35:05.941]     INFO:   running: fulltest

[17:35:05.941]    DEBUG: <PixTestFullTest.cc/init:L49> PixTestFullTest::init()

[17:35:05.941]    DEBUG: <PixTestFullTest.cc/PixTestFullTest:L20> PixTestFullTest ctor(PixSetup &a, string, TGTab *)

[17:35:05.941]     INFO: ######################################################################

[17:35:05.941]     INFO: PixTestFullTest::doTest()

[17:35:05.941]     INFO: ######################################################################

[17:35:05.941]    DEBUG: <PixTestAlive.cc/init:L77> PixTestAlive::init()

[17:35:05.941]    DEBUG: <PixTestAlive.cc/PixTestAlive:L21> PixTestAlive ctor(PixSetup &a, string, TGTab *)

[17:35:05.943]     INFO: ######################################################################

[17:35:05.943]     INFO: PixTestAlive::doTest()

[17:35:05.943]     INFO: ######################################################################

[17:35:05.945]     INFO:    ----------------------------------------------------------------------

[17:35:05.945]     INFO:    PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)

[17:35:05.945]     INFO:    ----------------------------------------------------------------------

[17:35:05.947]    DEBUG: <PixTest.cc/efficiencyMaps:L328>       attempt #0

[17:35:09.639]     INFO: Test took 3692ms.

[17:35:09.657]     INFO: Fetched DAQ statistics. Counters are being reset now.

[17:35:09.657]    DEBUG: <PixTest.cc/efficiencyMaps:L339>  eff result size = 66541

[17:35:09.657]    DEBUG: <PixTest.cc/efficiencyMaps:L344> Create hists PixelAlive_C0 .. PixelAlive_C15

[17:35:09.896]     INFO: PixTestAlive::aliveTest() done

[17:35:09.897]     INFO: number of dead pixels (per ROC):     4    4    1    0    0    0    0    0    1    0    0    0    2    4    1    2

[17:35:09.897]    DEBUG: <PixTestAlive.cc/aliveTest:L188> number of red-efficiency pixels:     4    4    1    0    0    0    0    0    1    0    0    0    2    4    1    2

[17:35:09.898]     INFO:    ----------------------------------------------------------------------

[17:35:09.898]     INFO:    PixTestAlive::maskTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)

[17:35:09.898]     INFO:    ----------------------------------------------------------------------

[17:35:09.900]    DEBUG: <PixTest.cc/efficiencyMaps:L328>       attempt #0

[17:35:12.547]     INFO: Test took 2647ms.

[17:35:12.548]     INFO: Fetched DAQ statistics. Counters are being reset now.

[17:35:12.548]    DEBUG: <PixTest.cc/efficiencyMaps:L339>  eff result size = 0

[17:35:12.548]    DEBUG: <PixTest.cc/efficiencyMaps:L344> Create hists MaskTest_C0 .. MaskTest_C15

[17:35:12.549]     INFO: mask vs. old pixelAlive PixelAlive_C0_V0 ..  PixelAlive_C15_V0

[17:35:12.787]     INFO: PixTestAlive::maskTest() done

[17:35:12.787]     INFO: number of mask-defect pixels (per ROC):     0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0

[17:35:12.789]     INFO:    ----------------------------------------------------------------------

[17:35:12.789]     INFO:    PixTestAlive::addressDecodingTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)

[17:35:12.789]     INFO:    ----------------------------------------------------------------------

[17:35:12.791]    DEBUG: <PixTest.cc/efficiencyMaps:L328>       attempt #0

[17:35:16.481]     INFO: Test took 3690ms.

[17:35:16.498]     INFO: Fetched DAQ statistics. Counters are being reset now.

[17:35:16.498]    DEBUG: <PixTest.cc/efficiencyMaps:L339>  eff result size = 66541

[17:35:16.498]    DEBUG: <PixTest.cc/efficiencyMaps:L344> Create hists AddressDecodingTest_C0 .. AddressDecodingTest_C15

[17:35:16.740]     INFO: PixTestAlive::addressDecodingTest() done

[17:35:16.740]     INFO: number of address-decoding pixels (per ROC):     0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0

[17:35:16.740]     INFO: PixTestAlive::doTest() done, duration: 10 seconds

[17:35:16.740]    DEBUG: <PixTestAlive.cc/~PixTestAlive:L109> PixTestAlive dtor

[17:35:16.744]    DEBUG: <PixTestBBMap.cc/init:L79> PixTestBBMap::init()

[17:35:16.744]    DEBUG: <PixTestBBMap.cc/PixTestBBMap:L27> PixTestBBMap ctor(PixSetup &a, string, TGTab *)

[17:35:16.746]     INFO: ######################################################################

[17:35:16.746]     INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)

[17:35:16.746]     INFO: ######################################################################

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

[17:35:16.761]     INFO:   dacScan step  from 0 .. 29

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

[17:35:34.390]     INFO: Test took 17629ms.

[17:35:34.427]     INFO: Fetched DAQ statistics. Counters are being reset now.

[17:35:34.427]     INFO:   dacScan step  from 30 .. 59

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

[17:35:52.694]     INFO: Test took 18267ms.

[17:35:52.779]     INFO: Fetched DAQ statistics. Counters are being reset now.

[17:35:52.788]     INFO:   dacScan step  from 60 .. 89

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

[17:36:16.141]     INFO: Test took 23353ms.

[17:36:16.404]     INFO: Fetched DAQ statistics. Counters are being reset now.

[17:36:16.446]     INFO:   dacScan step  from 90 .. 119

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

[17:36:40.478]     INFO: Test took 24032ms.

[17:36:40.734]     INFO: Fetched DAQ statistics. Counters are being reset now.

[17:36:40.775]     INFO:   dacScan step  from 120 .. 149

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

[17:37:03.250]     INFO: Test took 22475ms.

[17:37:03.440]     INFO: Fetched DAQ statistics. Counters are being reset now.

[17:37:03.466]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0

[17:37:04.715]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1

[17:37:05.977]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2

[17:37:07.265]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3

[17:37:08.536]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4

[17:37:09.770]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5

[17:37:10.996]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6

[17:37:12.206]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7

[17:37:13.479]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8

[17:37:14.677]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9

[17:37:15.830]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10

[17:37:17.024]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11

[17:37:18.233]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12

[17:37:19.434]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13

[17:37:20.646]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14

[17:37:21.876]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15

[17:37:23.116]    DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 269938688

[17:37:23.164]    DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C0_V0

[17:37:23.164]    DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 100 (obtained for minval = 0) start: 100 .. 121 last peak: 63.2592 last sigma: 5.78104 lcuts[0] = 80.6023 lcuts[1] = 121.07

[17:37:23.165]    DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C1_V0

[17:37:23.165]    DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 99 (obtained for minval = 0) start: 99 .. 122 last peak: 57.345 last sigma: 6.47611 lcuts[0] = 76.7733 lcuts[1] = 122.106

[17:37:23.166]    DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C2_V0

[17:37:23.166]    DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 106 (obtained for minval = 0) start: 106 .. 129 last peak: 62.552 last sigma: 6.70904 lcuts[0] = 82.6791 lcuts[1] = 129.642

[17:37:23.166]    DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C3_V0

[17:37:23.167]    DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 108 (obtained for minval = 0) start: 108 .. 130 last peak: 67.1854 last sigma: 6.3373 lcuts[0] = 86.1973 lcuts[1] = 130.558

[17:37:23.167]    DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C4_V0

[17:37:23.167]    DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 96 (obtained for minval = 0) start: 96 .. 117 last peak: 57.8914 last sigma: 5.92899 lcuts[0] = 75.6784 lcuts[1] = 117.181

[17:37:23.167]    DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C5_V0

[17:37:23.168]    DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 98 (obtained for minval = 0) start: 98 .. 117 last peak: 62.8727 last sigma: 5.42295 lcuts[0] = 79.1416 lcuts[1] = 117.102

[17:37:23.168]    DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C6_V0

[17:37:23.168]    DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 95 (obtained for minval = 0) start: 95 .. 115 last peak: 59.3724 last sigma: 5.62461 lcuts[0] = 76.2463 lcuts[1] = 115.619

[17:37:23.169]    DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C7_V0

[17:37:23.169]    DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 108 (obtained for minval = 0) start: 108 .. 132 last peak: 65.9072 last sigma: 6.61795 lcuts[0] = 85.7611 lcuts[1] = 132.087

[17:37:23.169]    DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C8_V0

[17:37:23.169]    DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 93 (obtained for minval = 0) start: 93 .. 112 last peak: 59.9465 last sigma: 5.22356 lcuts[0] = 75.6172 lcuts[1] = 112.182

[17:37:23.170]    DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C9_V0

[17:37:23.170]    DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 86 (obtained for minval = 0) start: 86 .. 103 last peak: 55.1789 last sigma: 4.8572 lcuts[0] = 69.7505 lcuts[1] = 103.751

[17:37:23.170]    DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C10_V0

[17:37:23.171]    DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 94 (obtained for minval = 0) start: 94 .. 113 last peak: 59.6388 last sigma: 5.36176 lcuts[0] = 75.7241 lcuts[1] = 113.256

[17:37:23.171]    DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C11_V0

[17:37:23.171]    DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 96 (obtained for minval = 0) start: 96 .. 114 last peak: 61.2942 last sigma: 5.36626 lcuts[0] = 77.393 lcuts[1] = 114.957

[17:37:23.172]    DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C12_V0

[17:37:23.172]    DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 88 (obtained for minval = 0) start: 88 .. 106 last peak: 54.1915 last sigma: 5.22907 lcuts[0] = 69.8787 lcuts[1] = 106.482

[17:37:23.172]    DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C13_V0

[17:37:23.172]    DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 87 (obtained for minval = 0) start: 87 .. 105 last peak: 54.3112 last sigma: 5.10363 lcuts[0] = 69.622 lcuts[1] = 105.347

[17:37:23.173]    DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C14_V0

[17:37:23.173]    DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 91 (obtained for minval = 0) start: 91 .. 112 last peak: 52.17 last sigma: 5.98363 lcuts[0] = 70.1209 lcuts[1] = 112.006

[17:37:23.173]    DEBUG: <PixTestBBMap.cc/doTest:L152> found 1 peaks in dist_thr_calSMap_VthrComp_C15_V0

[17:37:23.174]    DEBUG: <PixTestBBMap.cc/fitPeaks:L259> cut for dead bump bonds: 99 (obtained for minval = 0) start: 99 .. 120 last peak: 60.1293 last sigma: 6.03704 lcuts[0] = 78.2404 lcuts[1] = 120.5

[17:37:23.175]     INFO: PixTestBBMap::doTest() done, duration: 126 seconds

[17:37:23.175]     INFO: number of dead bumps (per ROC):     5    2    2    2    0    2    0    1    2    3    2    4    1    1    3    2

[17:37:23.175]     INFO: separation cut       (per ROC):   101  100  107  109   97   99   96  109   94   87   95   97   89   88   92  100

[17:37:23.175]    DEBUG: <PixTestBBMap.cc/~PixTestBBMap:L97> PixTestBBMap dtor

[17:37:23.239]    DEBUG: <PixTestScurves.cc/setParameter:L92> set fOutputFilename = 

[17:37:23.241]     INFO: ######################################################################

[17:37:23.241]     INFO: PixTestScurves::fullTest() ntrig = 50

[17:37:23.241]     INFO: ######################################################################

[17:37:23.241]     INFO:    ----------------------------------------------------------------------

[17:37:23.241]     INFO:    PixTestScurves::scurves(Vcal), ntrig = 50

[17:37:23.241]     INFO:    ----------------------------------------------------------------------

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

[17:37:23.250]     INFO:   dacScan step  from 0 .. 9

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

[17:37:56.727]     INFO: Test took 33477ms.

[17:37:56.795]     INFO: Fetched DAQ statistics. Counters are being reset now.

[17:37:56.795]     INFO:   dacScan step  from 10 .. 19

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

[17:38:30.272]     INFO: Test took 33477ms.

[17:38:30.336]     INFO: Fetched DAQ statistics. Counters are being reset now.

[17:38:30.336]     INFO:   dacScan step  from 20 .. 29

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

[17:39:03.840]     INFO: Test took 33504ms.

[17:39:03.905]     INFO: Fetched DAQ statistics. Counters are being reset now.

[17:39:03.905]     INFO:   dacScan step  from 30 .. 39

[17:39:03.905]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[17:39:37.383]     INFO: Test took 33478ms.

[17:39:37.450]     INFO: Fetched DAQ statistics. Counters are being reset now.

[17:39:37.450]     INFO:   dacScan step  from 40 .. 49

[17:39:37.450]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[17:40:10.921]     INFO: Test took 33471ms.

[17:40:10.987]     INFO: Fetched DAQ statistics. Counters are being reset now.

[17:40:10.987]     INFO:   dacScan step  from 50 .. 59

[17:40:10.987]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[17:40:44.497]     INFO: Test took 33510ms.

[17:40:44.562]     INFO: Fetched DAQ statistics. Counters are being reset now.

[17:40:44.563]     INFO:   dacScan step  from 60 .. 69

[17:40:44.563]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[17:41:18.179]     INFO: Test took 33616ms.

[17:41:18.244]     INFO: Fetched DAQ statistics. Counters are being reset now.

[17:41:18.244]     INFO:   dacScan step  from 70 .. 79

[17:41:18.244]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[17:41:51.881]    ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (12) != Token Chain Length (8)

[17:41:51.881]    ERROR: <datapipe.cc/CheckEventID:L420>    Event ID mismatch:  local ID (170) !=  TBM ID (171)

[17:41:51.881]  WARNING: ROC 4: Readback start marker after 15 readouts!

[17:41:51.881]  WARNING: ROC 3: Readback start marker after 15 readouts!

[17:41:51.881]  WARNING: ROC 5: Readback start marker after 15 readouts!

[17:41:51.881]  WARNING: ROC 6: Readback start marker after 15 readouts!

[17:41:51.881]  WARNING: ROC 0: Readback start marker after 15 readouts!

[17:41:51.881]  WARNING: ROC 1: Readback start marker after 15 readouts!

[17:41:51.881]  WARNING: ROC 7: Readback start marker after 15 readouts!

[17:41:51.881]  WARNING: ROC 2: Readback start marker after 15 readouts!

[17:41:51.907]     INFO: Test took 33663ms.

[17:41:51.977]     INFO: Fetched DAQ statistics. Counters are being reset now.

[17:41:51.978]     INFO:   dacScan step  from 80 .. 89

[17:41:51.978]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[17:42:24.865]    ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (12) != Token Chain Length (8)

[17:42:24.865]    ERROR: <datapipe.cc/CheckEventID:L420>    Event ID mismatch:  local ID (145) !=  TBM ID (146)

[17:42:24.865]  WARNING: ROC 2: Readback start marker after 15 readouts!

[17:42:24.865]  WARNING: ROC 4: Readback start marker after 15 readouts!

[17:42:24.865]  WARNING: ROC 3: Readback start marker after 15 readouts!

[17:42:24.865]  WARNING: ROC 5: Readback start marker after 15 readouts!

[17:42:24.865]  WARNING: ROC 6: Readback start marker after 15 readouts!

[17:42:24.865]  WARNING: ROC 0: Readback start marker after 15 readouts!

[17:42:24.865]  WARNING: ROC 1: Readback start marker after 15 readouts!

[17:42:24.865]  WARNING: ROC 7: Readback start marker after 15 readouts!

[17:42:27.072]     INFO: Test took 35094ms.

[17:42:27.227]     INFO: Fetched DAQ statistics. Counters are being reset now.

[17:42:27.232]     INFO:   dacScan step  from 90 .. 99

[17:42:27.232]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[17:42:58.888]    ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (6) != Token Chain Length (8)

[17:42:58.888]  WARNING: ROC 6: Readback start marker after 15 readouts!

[17:42:58.888]  WARNING: ROC 7: Readback start marker after 15 readouts!

[17:43:07.925]     INFO: Test took 40693ms.

[17:43:08.238]     INFO: Fetched DAQ statistics. Counters are being reset now.

[17:43:08.250]     INFO:   dacScan step  from 100 .. 109

[17:43:08.250]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[17:43:36.711]    ERROR: <datapipe.cc/CheckEventID:L420>    Event ID mismatch:  local ID (146) !=  TBM ID (190)

[17:43:36.711]    ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (6) != Token Chain Length (8)

[17:43:36.711]    ERROR: <datapipe.cc/CheckEventID:L420>    Event ID mismatch:  local ID (191) !=  TBM ID (147)

[17:43:36.711]  WARNING: ROC 6: Readback start marker after 15 readouts!

[17:43:36.711]  WARNING: ROC 7: Readback start marker after 15 readouts!

[17:43:54.345]    ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (4) != Token Chain Length (8)

[17:43:54.345]  WARNING: ROC 4: Readback start marker after 15 readouts!

[17:43:54.345]  WARNING: ROC 5: Readback start marker after 15 readouts!

[17:43:54.345]  WARNING: ROC 6: Readback start marker after 15 readouts!

[17:43:54.345]  WARNING: ROC 7: Readback start marker after 15 readouts!

[17:43:55.544]     INFO: Test took 47294ms.

[17:43:56.032]     INFO: Fetched DAQ statistics. Counters are being reset now.

[17:43:56.048]     INFO:   dacScan step  from 110 .. 119

[17:43:56.048]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[17:44:24.590]    ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (4) != Token Chain Length (8)

[17:44:24.590]  WARNING: ROC 4: Readback start marker after 15 readouts!

[17:44:24.590]  WARNING: ROC 5: Readback start marker after 15 readouts!

[17:44:24.590]  WARNING: ROC 6: Readback start marker after 15 readouts!

[17:44:24.590]  WARNING: ROC 7: Readback start marker after 15 readouts!

[17:44:45.691]    ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (14) != Token Chain Length (8)

[17:44:45.691]    ERROR: <datapipe.cc/CheckEventID:L420>    Event ID mismatch:  local ID (246) !=  TBM ID (247)

[17:44:45.691]  WARNING: ROC 2: Readback start marker after 15 readouts!

[17:44:45.691]  WARNING: ROC 4: Readback start marker after 15 readouts!

[17:44:45.691]  WARNING: ROC 3: Readback start marker after 15 readouts!

[17:44:45.691]  WARNING: ROC 5: Readback start marker after 15 readouts!

[17:44:45.691]  WARNING: ROC 6: Readback start marker after 15 readouts!

[17:44:45.691]  WARNING: ROC 0: Readback start marker after 15 readouts!

[17:44:45.691]  WARNING: ROC 1: Readback start marker after 15 readouts!

[17:44:45.691]  WARNING: ROC 7: Readback start marker after 15 readouts!

[17:44:50.752]     INFO: Test took 54704ms.

[17:44:51.343]     INFO: Fetched DAQ statistics. Counters are being reset now.

[17:44:51.359]     INFO:   dacScan step  from 120 .. 129

[17:44:51.359]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[17:45:20.649]    ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (5) != Token Chain Length (8)

[17:45:20.649]  WARNING: ROC 6: Readback start marker after 15 readouts!

[17:45:20.649]  WARNING: ROC 7: Readback start marker after 15 readouts!

[17:45:20.651]  WARNING: ROC 3: Readback start marker after 32 readouts!

[17:45:20.651]  WARNING: ROC 5: Readback start marker after 31 readouts!

[17:45:41.607]    ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (6) != Token Chain Length (8)

[17:45:41.607]  WARNING: ROC 6: Readback start marker after 15 readouts!

[17:45:41.607]  WARNING: ROC 7: Readback start marker after 15 readouts!

[17:45:47.224]     INFO: Test took 55865ms.

[17:45:47.799]     INFO: Fetched DAQ statistics. Counters are being reset now.

[17:45:47.815]     INFO:   dacScan step  from 130 .. 139

[17:45:47.815]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[17:46:17.839]  WARNING: ROC 4: Readback start marker after 2 readouts!

[17:46:17.839]    ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (6) != Token Chain Length (8)

[17:46:17.839]  WARNING: ROC 7: Readback start marker after 15 readouts!

[17:46:17.839]  WARNING: ROC 4: Readback start marker after 14 readouts!

[17:46:17.839]  WARNING: ROC 6: Readback start marker after 31 readouts!

[17:46:39.722]  WARNING: ROC 5: Readback start marker after 2 readouts!

[17:46:39.722]    ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (6) != Token Chain Length (8)

[17:46:39.722]  WARNING: ROC 5: Readback start marker after 14 readouts!

[17:46:39.722]  WARNING: ROC 6: Readback start marker after 15 readouts!

[17:46:39.722]  WARNING: ROC 7: Readback start marker after 31 readouts!

[17:46:45.349]     INFO: Test took 57534ms.

[17:46:45.910]     INFO: Fetched DAQ statistics. Counters are being reset now.

[17:46:45.926]     INFO:   dacScan step  from 140 .. 149

[17:46:45.926]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[17:47:15.165]    ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (6) != Token Chain Length (8)

[17:47:15.168]  WARNING: ROC 6: Readback start marker after 15 readouts!

[17:47:15.168]  WARNING: ROC 7: Readback start marker after 15 readouts!

[17:47:35.821]    ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (4) != Token Chain Length (8)

[17:47:35.821]  WARNING: ROC 4: Readback start marker after 15 readouts!

[17:47:35.821]  WARNING: ROC 5: Readback start marker after 15 readouts!

[17:47:35.821]  WARNING: ROC 6: Readback start marker after 15 readouts!

[17:47:35.821]  WARNING: ROC 7: Readback start marker after 15 readouts!

[17:47:41.112]     INFO: Test took 55186ms.

[17:47:41.678]     INFO: Fetched DAQ statistics. Counters are being reset now.

[17:47:41.693]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0

[17:47:41.693]     INFO: dumping ASCII scurve output file: SCurveData

[17:47:42.913]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1

[17:47:42.913]     INFO: dumping ASCII scurve output file: SCurveData

[17:47:44.123]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2

[17:47:44.123]     INFO: dumping ASCII scurve output file: SCurveData

[17:47:45.315]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3

[17:47:45.315]     INFO: dumping ASCII scurve output file: SCurveData

[17:47:46.509]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4

[17:47:46.509]     INFO: dumping ASCII scurve output file: SCurveData

[17:47:47.749]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5

[17:47:47.749]     INFO: dumping ASCII scurve output file: SCurveData

[17:47:48.954]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6

[17:47:48.954]     INFO: dumping ASCII scurve output file: SCurveData

[17:47:50.184]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7

[17:47:50.184]     INFO: dumping ASCII scurve output file: SCurveData

[17:47:51.408]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8

[17:47:51.408]     INFO: dumping ASCII scurve output file: SCurveData

[17:47:52.645]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9

[17:47:52.645]     INFO: dumping ASCII scurve output file: SCurveData

[17:47:53.889]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10

[17:47:53.889]     INFO: dumping ASCII scurve output file: SCurveData

[17:47:55.105]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11

[17:47:55.105]     INFO: dumping ASCII scurve output file: SCurveData

[17:47:56.331]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12

[17:47:56.332]     INFO: dumping ASCII scurve output file: SCurveData

[17:47:57.574]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13

[17:47:57.574]     INFO: dumping ASCII scurve output file: SCurveData

[17:47:58.812]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14

[17:47:58.812]     INFO: dumping ASCII scurve output file: SCurveData

[17:48:00.048]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15

[17:48:00.048]     INFO: dumping ASCII scurve output file: SCurveData

[17:48:01.257]    DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 563875840

[17:48:01.303]     INFO: PixTestScurves::scurves() done 

[17:48:01.303]     INFO: Vcal mean: 105.56 107.43 112.53 110.00  94.26 109.37  96.48 100.23  93.69  89.57 101.83  97.97  87.80  90.98  95.83 106.11 

[17:48:01.303]     INFO: Vcal RMS:    6.54   6.66   6.35   5.86   5.23   6.10   5.20   6.04   6.22   5.34   6.35   5.44   5.83   5.56   5.73   5.62 

[17:48:01.303]     INFO: PixTestScurves::fullTest() done, duration: 638 seconds

[17:48:01.303]    DEBUG: <PixTestScurves.cc/~PixTestScurves:L141> PixTestScurves dtor

[17:48:01.364]     INFO: ######################################################################

[17:48:01.364]     INFO: PixTestTrim::doTest()

[17:48:01.364]     INFO: ######################################################################

[17:48:01.365]     INFO:    ----------------------------------------------------------------------

[17:48:01.365]     INFO:    PixTestTrim::trimTest() ntrig = 10, vcal = 35

[17:48:01.365]     INFO:    ----------------------------------------------------------------------

[17:48:01.433]     INFO: ---> VthrComp thr map (minimal VthrComp)

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

[17:48:01.441]     INFO:   dacScan step  from 0 .. 19

[17:48:01.441]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[17:48:13.840]     INFO: Test took 12399ms.

[17:48:13.861]     INFO: Fetched DAQ statistics. Counters are being reset now.

[17:48:13.861]     INFO:   dacScan step  from 20 .. 39

[17:48:13.862]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[17:48:26.327]     INFO: Test took 12465ms.

[17:48:26.351]     INFO: Fetched DAQ statistics. Counters are being reset now.

[17:48:26.351]     INFO:   dacScan step  from 40 .. 59

[17:48:26.351]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[17:48:38.777]     INFO: Test took 12426ms.

[17:48:38.798]     INFO: Fetched DAQ statistics. Counters are being reset now.

[17:48:38.798]     INFO:   dacScan step  from 60 .. 79

[17:48:38.798]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[17:48:51.215]     INFO: Test took 12417ms.

[17:48:51.236]     INFO: Fetched DAQ statistics. Counters are being reset now.

[17:48:51.236]     INFO:   dacScan step  from 80 .. 99

[17:48:51.236]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[17:49:03.851]     INFO: Test took 12615ms.

[17:49:03.891]     INFO: Fetched DAQ statistics. Counters are being reset now.

[17:49:03.897]     INFO:   dacScan step  from 100 .. 119

[17:49:03.897]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[17:49:18.604]     INFO: Test took 14707ms.

[17:49:18.746]     INFO: Fetched DAQ statistics. Counters are being reset now.

[17:49:18.772]     INFO:   dacScan step  from 120 .. 139

[17:49:18.772]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[17:49:35.350]     INFO: Test took 16578ms.

[17:49:35.498]     INFO: Fetched DAQ statistics. Counters are being reset now.

[17:49:35.522]     INFO:   dacScan step  from 140 .. 159

[17:49:35.522]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[17:49:48.696]     INFO: Test took 13174ms.

[17:49:48.754]     INFO: Fetched DAQ statistics. Counters are being reset now.

[17:49:48.764]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0

[17:49:49.905]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1

[17:49:51.074]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2

[17:49:52.240]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3

[17:49:53.424]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4

[17:49:54.559]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5

[17:49:55.684]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6

[17:49:56.795]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7

[17:49:57.976]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8

[17:49:59.082]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9

[17:50:00.139]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10

[17:50:01.231]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11

[17:50:02.339]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12

[17:50:03.443]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13

[17:50:04.561]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14

[17:50:05.703]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15

[17:50:06.852]    DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 563900416

[17:50:06.854]    DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 99.9523 minThrLimit = 99.9456 minThrNLimit = 120.179 -> result = 99.9523 -> 99

[17:50:06.854]    DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 103.093 minThrLimit = 103.075 minThrNLimit = 125.32 -> result = 103.093 -> 103

[17:50:06.854]    DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 105.614 minThrLimit = 105.561 minThrNLimit = 127.945 -> result = 105.614 -> 105

[17:50:06.855]    DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 102.942 minThrLimit = 102.931 minThrNLimit = 126.992 -> result = 102.942 -> 102

[17:50:06.855]    DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 95.0443 minThrLimit = 95.0127 minThrNLimit = 117.036 -> result = 95.0443 -> 95

[17:50:06.855]    DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 97.8041 minThrLimit = 97.7856 minThrNLimit = 115.329 -> result = 97.8041 -> 97

[17:50:06.856]    DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 92.5212 minThrLimit = 92.5082 minThrNLimit = 111.184 -> result = 92.5212 -> 92

[17:50:06.856]    DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 101.008 minThrLimit = 100.959 minThrNLimit = 123.721 -> result = 101.008 -> 101

[17:50:06.856]    DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 90.0425 minThrLimit = 89.9764 minThrNLimit = 108.914 -> result = 90.0425 -> 90

[17:50:06.857]    DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 84.4979 minThrLimit = 84.4934 minThrNLimit = 100.956 -> result = 84.4979 -> 84

[17:50:06.857]    DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 92.5938 minThrLimit = 92.5907 minThrNLimit = 109.235 -> result = 92.5938 -> 92

[17:50:06.857]    DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 94.1289 minThrLimit = 94.1137 minThrNLimit = 112.509 -> result = 94.1289 -> 94

[17:50:06.858]    DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 88.1592 minThrLimit = 88.1151 minThrNLimit = 107.883 -> result = 88.1592 -> 88

[17:50:06.858]    DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 91.1681 minThrLimit = 91.153 minThrNLimit = 111.578 -> result = 91.1681 -> 91

[17:50:06.858]    DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 96.2263 minThrLimit = 96.2195 minThrNLimit = 117.239 -> result = 96.2263 -> 96

[17:50:06.859]    DEBUG: <PixTest.cc/getMinimumVthrComp:L1208> minThr = 100.557 minThrLimit = 100.425 minThrNLimit = 119.491 -> result = 100.557 -> 100

[17:50:06.859]     INFO: ROC 0 VthrComp = 99

[17:50:06.859]     INFO: ROC 1 VthrComp = 103

[17:50:06.859]     INFO: ROC 2 VthrComp = 105

[17:50:06.859]     INFO: ROC 3 VthrComp = 102

[17:50:06.859]     INFO: ROC 4 VthrComp = 95

[17:50:06.859]     INFO: ROC 5 VthrComp = 97

[17:50:06.860]     INFO: ROC 6 VthrComp = 92

[17:50:06.860]     INFO: ROC 7 VthrComp = 101

[17:50:06.860]     INFO: ROC 8 VthrComp = 90

[17:50:06.860]     INFO: ROC 9 VthrComp = 84

[17:50:06.860]     INFO: ROC 10 VthrComp = 92

[17:50:06.860]     INFO: ROC 11 VthrComp = 94

[17:50:06.860]     INFO: ROC 12 VthrComp = 88

[17:50:06.860]     INFO: ROC 13 VthrComp = 91

[17:50:06.861]     INFO: ROC 14 VthrComp = 96

[17:50:06.861]     INFO: ROC 15 VthrComp = 100

[17:50:06.861]     INFO: ---> Vcal thr map (pixel with maximum Vcal thr)

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

[17:50:06.869]     INFO:   dacScan step  from 0 .. 19

[17:50:06.870]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[17:50:19.273]     INFO: Test took 12403ms.

[17:50:19.295]     INFO: Fetched DAQ statistics. Counters are being reset now.

[17:50:19.295]     INFO:   dacScan step  from 20 .. 39

[17:50:19.295]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[17:50:31.789]     INFO: Test took 12494ms.

[17:50:31.819]     INFO: Fetched DAQ statistics. Counters are being reset now.

[17:50:31.822]     INFO:   dacScan step  from 40 .. 59

[17:50:31.822]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[17:50:46.778]     INFO: Test took 14956ms.

[17:50:46.925]     INFO: Fetched DAQ statistics. Counters are being reset now.

[17:50:46.950]     INFO:   dacScan step  from 60 .. 79

[17:50:46.950]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[17:51:03.795]     INFO: Test took 16845ms.

[17:51:03.959]     INFO: Fetched DAQ statistics. Counters are being reset now.

[17:51:03.987]     INFO:   dacScan step  from 80 .. 99

[17:51:03.987]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[17:51:20.710]     INFO: Test took 16723ms.

[17:51:20.875]     INFO: Fetched DAQ statistics. Counters are being reset now.

[17:51:20.903]     INFO:   dacScan step  from 100 .. 119

[17:51:20.903]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[17:51:37.703]     INFO: Test took 16800ms.

[17:51:37.866]     INFO: Fetched DAQ statistics. Counters are being reset now.

[17:51:37.894]     INFO:   dacScan step  from 120 .. 139

[17:51:37.894]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[17:51:56.131]     INFO: Test took 18237ms.

[17:51:56.294]     INFO: Fetched DAQ statistics. Counters are being reset now.

[17:51:56.321]     INFO:   dacScan step  from 140 .. 159

[17:51:56.322]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[17:52:13.272]     INFO: Test took 16950ms.

[17:52:13.435]     INFO: Fetched DAQ statistics. Counters are being reset now.

[17:52:13.462]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0

[17:52:14.835]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1

[17:52:16.229]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2

[17:52:17.623]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3

[17:52:18.992]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4

[17:52:20.338]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5

[17:52:21.730]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6

[17:52:23.093]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7

[17:52:24.449]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8

[17:52:25.808]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9

[17:52:27.166]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10

[17:52:28.543]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11

[17:52:29.898]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12

[17:52:31.256]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13

[17:52:32.614]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14

[17:52:33.979]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15

[17:52:35.351]    DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 563900416

[17:52:35.353]     INFO:    roc 0 with ID = 0  has maximal Vcal 62.802 for pixel 9/22 mean/min/max = 47.7371/32.5041/62.9701

[17:52:35.353]     INFO:    roc 1 with ID = 1  has maximal Vcal 62.1977 for pixel 21/79 mean/min/max = 47.0991/31.9944/62.2039

[17:52:35.353]     INFO:    roc 2 with ID = 2  has maximal Vcal 67.3789 for pixel 23/73 mean/min/max = 50.9658/34.3938/67.5379

[17:52:35.353]     INFO:    roc 3 with ID = 3  has maximal Vcal 65.6863 for pixel 0/5 mean/min/max = 49.3793/32.9746/65.784

[17:52:35.354]     INFO:    roc 4 with ID = 4  has maximal Vcal 57.4443 for pixel 7/2 mean/min/max = 44.9673/32.3339/57.6007

[17:52:35.354]     INFO:    roc 5 with ID = 5  has maximal Vcal 66.1024 for pixel 24/0 mean/min/max = 49.3244/32.4565/66.1923

[17:52:35.354]     INFO:    roc 6 with ID = 6  has maximal Vcal 59.3533 for pixel 20/3 mean/min/max = 46.649/33.8991/59.399

[17:52:35.354]     INFO:    roc 7 with ID = 7  has maximal Vcal 61.1044 for pixel 12/78 mean/min/max = 46.5872/32.02/61.1545

[17:52:35.355]     INFO:    roc 8 with ID = 8  has maximal Vcal 60.9829 for pixel 0/43 mean/min/max = 46.6353/32.2413/61.0292

[17:52:35.355]     INFO:    roc 9 with ID = 9  has maximal Vcal 59.0261 for pixel 14/72 mean/min/max = 46.1582/32.9901/59.3262

[17:52:35.355]     INFO:    roc 10 with ID = 10  has maximal Vcal 64.7614 for pixel 0/69 mean/min/max = 48.7861/32.681/64.8913

[17:52:35.355]     INFO:    roc 11 with ID = 11  has maximal Vcal 58.9743 for pixel 20/76 mean/min/max = 46.1308/33.2788/58.9828

[17:52:35.356]     INFO:    roc 12 with ID = 12  has maximal Vcal 60.1742 for pixel 0/6 mean/min/max = 46.6666/33.1565/60.1768

[17:52:35.356]     INFO:    roc 13 with ID = 13  has maximal Vcal 57.1783 for pixel 5/13 mean/min/max = 45.3458/33.3366/57.3549

[17:52:35.356]     INFO:    roc 14 with ID = 14  has maximal Vcal 59.3369 for pixel 0/70 mean/min/max = 45.5271/31.6013/59.4529

[17:52:35.356]     INFO:    roc 15 with ID = 15  has maximal Vcal 62.0424 for pixel 7/1 mean/min/max = 47.4827/32.7483/62.2171

[17:52:35.356]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[17:53:49.610]     INFO: Test took 74255ms.

[17:53:50.370]    DEBUG: <PixTestTrim.cc/trimTest:L309> vtrim: vcal = 36.3654 < 35 for itrim+1 = 127; old thr = 34.3123 ... break

[17:53:50.396]    DEBUG: <PixTestTrim.cc/trimTest:L304>  vtrim: vcal = 35.401 < 35 for itrim = 120; old thr = 33.9116 ... break

[17:53:50.416]    DEBUG: <PixTestTrim.cc/trimTest:L304>  vtrim: vcal = 36.0041 < 35 for itrim = 123; old thr = 31.6866 ... break

[17:53:50.438]    DEBUG: <PixTestTrim.cc/trimTest:L304>  vtrim: vcal = 35.3324 < 35 for itrim = 125; old thr = 33.6263 ... break

[17:53:50.470]    DEBUG: <PixTestTrim.cc/trimTest:L309> vtrim: vcal = 36.3155 < 35 for itrim+1 = 107; old thr = 34.3582 ... break

[17:53:50.494]    DEBUG: <PixTestTrim.cc/trimTest:L309> vtrim: vcal = 36.2411 < 35 for itrim+1 = 129; old thr = 34.9452 ... break

[17:53:50.520]    DEBUG: <PixTestTrim.cc/trimTest:L309> vtrim: vcal = 35.679 < 35 for itrim+1 = 109; old thr = 34.541 ... break

[17:53:50.553]    DEBUG: <PixTestTrim.cc/trimTest:L309> vtrim: vcal = 35.6854 < 35 for itrim+1 = 129; old thr = 34.8737 ... break

[17:53:50.578]    DEBUG: <PixTestTrim.cc/trimTest:L304>  vtrim: vcal = 35.6995 < 35 for itrim = 114; old thr = 34.2396 ... break

[17:53:50.599]    DEBUG: <PixTestTrim.cc/trimTest:L304>  vtrim: vcal = 35.4182 < 35 for itrim = 106; old thr = 31.8427 ... break

[17:53:50.615]    DEBUG: <PixTestTrim.cc/trimTest:L304>  vtrim: vcal = 35.3458 < 35 for itrim = 112; old thr = 32.4345 ... break

[17:53:50.636]    DEBUG: <PixTestTrim.cc/trimTest:L304>  vtrim: vcal = 35.3089 < 35 for itrim = 98; old thr = 33.9372 ... break

[17:53:50.659]    DEBUG: <PixTestTrim.cc/trimTest:L304>  vtrim: vcal = 35.2143 < 35 for itrim = 102; old thr = 32.7389 ... break

[17:53:50.687]    DEBUG: <PixTestTrim.cc/trimTest:L304>  vtrim: vcal = 35.0052 < 35 for itrim = 111; old thr = 34.616 ... break

[17:53:50.704]    DEBUG: <PixTestTrim.cc/trimTest:L304>  vtrim: vcal = 35.1629 < 35 for itrim = 101; old thr = 33.5115 ... break

[17:53:50.733]    DEBUG: <PixTestTrim.cc/trimTest:L309> vtrim: vcal = 36.3341 < 35 for itrim+1 = 125; old thr = 34.4147 ... break

[17:53:50.796]     INFO: ---> dac: vcal name: TrimThr2 ntrig: 10 dacrange: 0 .. 199 (20) hits flags = 16 (plus default)

[17:53:50.805]     INFO:   dacScan step  from 0 .. 19

[17:53:50.805]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[17:54:09.064]     INFO: Test took 18259ms.

[17:54:09.114]     INFO: Fetched DAQ statistics. Counters are being reset now.

[17:54:09.116]     INFO:   dacScan step  from 20 .. 39

[17:54:09.116]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[17:54:31.300]     INFO: Test took 22184ms.

[17:54:31.529]     INFO: Fetched DAQ statistics. Counters are being reset now.

[17:54:31.556]     INFO:   dacScan step  from 40 .. 59

[17:54:31.556]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[17:54:58.363]     INFO: Test took 26807ms.

[17:54:58.648]     INFO: Fetched DAQ statistics. Counters are being reset now.

[17:54:58.676]     INFO:   dacScan step  from 60 .. 79

[17:54:58.676]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[17:55:25.586]     INFO: Test took 26910ms.

[17:55:25.863]     INFO: Fetched DAQ statistics. Counters are being reset now.

[17:55:25.892]     INFO:   dacScan step  from 80 .. 99

[17:55:25.892]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[17:55:52.836]     INFO: Test took 26944ms.

[17:55:53.114]     INFO: Fetched DAQ statistics. Counters are being reset now.

[17:55:53.143]     INFO:   dacScan step  from 100 .. 119

[17:55:53.143]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[17:56:20.076]     INFO: Test took 26933ms.

[17:56:20.353]     INFO: Fetched DAQ statistics. Counters are being reset now.

[17:56:20.381]     INFO:   dacScan step  from 120 .. 139

[17:56:20.381]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[17:56:48.761]     INFO: Test took 28380ms.

[17:56:49.038]     INFO: Fetched DAQ statistics. Counters are being reset now.

[17:56:49.066]     INFO:   dacScan step  from 140 .. 159

[17:56:49.066]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[17:57:16.209]     INFO: Test took 27143ms.

[17:57:16.491]     INFO: Fetched DAQ statistics. Counters are being reset now.

[17:57:16.518]     INFO:   dacScan step  from 160 .. 179

[17:57:16.519]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[17:57:43.548]     INFO: Test took 27029ms.

[17:57:43.825]     INFO: Fetched DAQ statistics. Counters are being reset now.

[17:57:43.853]     INFO:   dacScan step  from 180 .. 199

[17:57:43.853]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[17:58:11.667]     INFO: Test took 27814ms.

[17:58:11.945]     INFO: Fetched DAQ statistics. Counters are being reset now.

[17:58:11.973]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0

[17:58:13.384]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1

[17:58:14.812]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2

[17:58:16.251]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3

[17:58:17.645]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4

[17:58:19.045]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5

[17:58:20.469]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6

[17:58:21.870]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7

[17:58:23.281]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8

[17:58:24.672]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9

[17:58:26.082]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10

[17:58:27.491]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11

[17:58:28.889]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12

[17:58:30.272]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13

[17:58:31.651]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14

[17:58:33.049]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15

[17:58:34.460]    DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 568512512

[17:58:34.461]     INFO: ---> TrimStepCorr4 extremal thresholds: 0.003217 .. 255.000000

[17:58:34.523]     INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 4 dacrange: 0 .. 255 (20) hits flags = 16 (plus default)

[17:58:34.532]     INFO:   dacScan step  from 0 .. 19

[17:58:34.532]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[17:58:45.777]     INFO: Test took 11245ms.

[17:58:45.798]     INFO: Fetched DAQ statistics. Counters are being reset now.

[17:58:45.798]     INFO:   dacScan step  from 20 .. 39

[17:58:45.798]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[17:58:57.869]     INFO: Test took 12071ms.

[17:58:57.950]     INFO: Fetched DAQ statistics. Counters are being reset now.

[17:58:57.966]     INFO:   dacScan step  from 40 .. 59

[17:58:57.966]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[17:59:12.495]     INFO: Test took 14529ms.

[17:59:12.646]     INFO: Fetched DAQ statistics. Counters are being reset now.

[17:59:12.675]     INFO:   dacScan step  from 60 .. 79

[17:59:12.675]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[17:59:27.452]     INFO: Test took 14777ms.

[17:59:27.594]     INFO: Fetched DAQ statistics. Counters are being reset now.

[17:59:27.622]     INFO:   dacScan step  from 80 .. 99

[17:59:27.622]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[17:59:42.399]     INFO: Test took 14777ms.

[17:59:42.543]     INFO: Fetched DAQ statistics. Counters are being reset now.

[17:59:42.571]     INFO:   dacScan step  from 100 .. 119

[17:59:42.571]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[17:59:57.434]     INFO: Test took 14863ms.

[17:59:57.577]     INFO: Fetched DAQ statistics. Counters are being reset now.

[17:59:57.604]     INFO:   dacScan step  from 120 .. 139

[17:59:57.604]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[18:00:13.934]     INFO: Test took 16329ms.

[18:00:14.077]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:00:14.104]     INFO:   dacScan step  from 140 .. 159

[18:00:14.105]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[18:00:29.118]     INFO: Test took 15013ms.

[18:00:29.262]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:00:29.289]     INFO:   dacScan step  from 160 .. 179

[18:00:29.289]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[18:00:44.222]     INFO: Test took 14933ms.

[18:00:44.366]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:00:44.394]     INFO:   dacScan step  from 180 .. 199

[18:00:44.394]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[18:01:00.069]     INFO: Test took 15675ms.

[18:01:00.212]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:01:00.243]     INFO:   dacScan step  from 200 .. 219

[18:01:00.243]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[18:01:15.041]     INFO: Test took 14798ms.

[18:01:15.184]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:01:15.212]     INFO:   dacScan step  from 220 .. 239

[18:01:15.212]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[18:01:30.025]     INFO: Test took 14813ms.

[18:01:30.168]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:01:30.196]     INFO:   dacScan step  from 240 .. 255

[18:01:30.197]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[18:01:42.511]     INFO: Test took 12314ms.

[18:01:42.630]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:01:42.653]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0

[18:01:44.377]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1

[18:01:46.108]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2

[18:01:47.833]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3

[18:01:49.541]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4

[18:01:51.247]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5

[18:01:52.986]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6

[18:01:54.710]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7

[18:01:56.439]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8

[18:01:58.160]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9

[18:01:59.898]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10

[18:02:01.625]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11

[18:02:03.361]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12

[18:02:05.081]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13

[18:02:06.802]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14

[18:02:08.511]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15

[18:02:10.226]    DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 568516608

[18:02:10.292]     INFO: ---> TrimStepCorr2 extremal thresholds: 10.076691 .. 60.600046

[18:02:10.355]     INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 4 dacrange: 0 .. 70 (20) hits flags = 16 (plus default)

[18:02:10.363]     INFO:   dacScan step  from 0 .. 19

[18:02:10.363]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[18:02:21.620]     INFO: Test took 11257ms.

[18:02:21.640]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:02:21.640]     INFO:   dacScan step  from 20 .. 39

[18:02:21.640]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[18:02:33.688]     INFO: Test took 12047ms.

[18:02:33.766]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:02:33.782]     INFO:   dacScan step  from 40 .. 59

[18:02:33.782]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[18:02:48.424]     INFO: Test took 14643ms.

[18:02:48.576]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:02:48.605]     INFO:   dacScan step  from 60 .. 70

[18:02:48.605]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[18:02:57.836]     INFO: Test took 9231ms.

[18:02:57.914]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:02:57.932]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0

[18:02:58.894]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1

[18:02:59.853]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2

[18:03:00.814]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3

[18:03:01.770]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4

[18:03:02.729]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5

[18:03:03.695]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6

[18:03:04.653]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7

[18:03:05.613]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8

[18:03:06.570]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9

[18:03:07.539]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10

[18:03:08.505]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11

[18:03:09.467]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12

[18:03:10.430]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13

[18:03:11.392]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14

[18:03:12.352]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15

[18:03:13.315]    DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 568635392

[18:03:13.382]     INFO: ---> TrimStepCorr1a extremal thresholds: 2.852151 .. 56.012661

[18:03:13.445]     INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 4 dacrange: 2 .. 66 (20) hits flags = 16 (plus default)

[18:03:13.454]     INFO:   dacScan step  from 2 .. 21

[18:03:13.454]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[18:03:24.707]     INFO: Test took 11253ms.

[18:03:24.728]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:03:24.728]     INFO:   dacScan step  from 22 .. 41

[18:03:24.728]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[18:03:37.062]     INFO: Test took 12334ms.

[18:03:37.152]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:03:37.171]     INFO:   dacScan step  from 42 .. 61

[18:03:37.171]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[18:03:51.902]     INFO: Test took 14731ms.

[18:03:52.046]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:03:52.074]     INFO:   dacScan step  from 62 .. 66

[18:03:52.074]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[18:03:57.640]     INFO: Test took 5566ms.

[18:03:57.677]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:03:57.692]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0

[18:03:58.617]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1

[18:03:59.550]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2

[18:04:00.479]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3

[18:04:01.409]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4

[18:04:02.346]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5

[18:04:03.282]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6

[18:04:04.221]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7

[18:04:05.157]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8

[18:04:06.081]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9

[18:04:07.016]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10

[18:04:07.951]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11

[18:04:08.886]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12

[18:04:09.821]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13

[18:04:10.751]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14

[18:04:11.692]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15

[18:04:12.632]    DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 568635392

[18:04:12.699]     INFO: ---> TrimStepCorr1b extremal thresholds: 1.356015 .. 56.012661

[18:04:12.762]     INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 4 dacrange: 1 .. 66 (20) hits flags = 16 (plus default)

[18:04:12.771]     INFO:   dacScan step  from 1 .. 20

[18:04:12.771]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[18:04:24.036]     INFO: Test took 11265ms.

[18:04:24.056]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:04:24.056]     INFO:   dacScan step  from 21 .. 40

[18:04:24.056]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[18:04:36.196]     INFO: Test took 12140ms.

[18:04:36.278]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:04:36.294]     INFO:   dacScan step  from 41 .. 60

[18:04:36.295]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[18:04:50.988]     INFO: Test took 14693ms.

[18:04:51.137]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:04:51.166]     INFO:   dacScan step  from 61 .. 66

[18:04:51.166]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[18:04:57.338]     INFO: Test took 6172ms.

[18:04:57.382]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:04:57.398]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0

[18:04:58.325]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1

[18:04:59.256]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2

[18:05:00.185]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3

[18:05:01.121]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4

[18:05:02.056]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5

[18:05:02.990]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6

[18:05:03.928]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7

[18:05:04.863]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8

[18:05:05.798]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9

[18:05:06.725]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10

[18:05:07.659]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11

[18:05:08.593]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12

[18:05:09.523]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13

[18:05:10.456]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14

[18:05:11.389]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15

[18:05:12.318]    DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 568635392

[18:05:12.385]     INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55

[18:05:12.385]     INFO: ---> dac: vcal name: TrimThrFinal ntrig: 10 dacrange: 15 .. 55 (20) hits flags = 16 (plus default)

[18:05:12.394]     INFO:   dacScan step  from 15 .. 34

[18:05:12.394]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[18:05:30.901]     INFO: Test took 18507ms.

[18:05:30.973]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:05:30.987]     INFO:   dacScan step  from 35 .. 54

[18:05:30.987]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[18:05:57.093]     INFO: Test took 26106ms.

[18:05:57.387]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:05:57.417]     INFO:   dacScan step  from 55 .. 55

[18:05:57.417]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[18:06:01.133]     INFO: Test took 3716ms.

[18:06:01.149]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:06:01.152]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0

[18:06:01.888]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1

[18:06:02.627]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2

[18:06:03.361]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3

[18:06:04.100]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4

[18:06:04.839]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5

[18:06:05.564]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6

[18:06:06.290]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7

[18:06:07.020]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8

[18:06:07.753]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9

[18:06:08.483]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10

[18:06:09.216]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11

[18:06:09.949]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12

[18:06:10.684]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13

[18:06:11.416]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14

[18:06:12.145]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15

[18:06:12.878]    DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 568639488

[18:06:12.929]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//dacParameters35_C0.dat

[18:06:12.929]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//dacParameters35_C1.dat

[18:06:12.929]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//dacParameters35_C2.dat

[18:06:12.929]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//dacParameters35_C3.dat

[18:06:12.929]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//dacParameters35_C4.dat

[18:06:12.929]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//dacParameters35_C5.dat

[18:06:12.929]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//dacParameters35_C6.dat

[18:06:12.929]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//dacParameters35_C7.dat

[18:06:12.930]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//dacParameters35_C8.dat

[18:06:12.930]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//dacParameters35_C9.dat

[18:06:12.930]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//dacParameters35_C10.dat

[18:06:12.930]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//dacParameters35_C11.dat

[18:06:12.930]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//dacParameters35_C12.dat

[18:06:12.930]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//dacParameters35_C13.dat

[18:06:12.930]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//dacParameters35_C14.dat

[18:06:12.930]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//dacParameters35_C15.dat

[18:06:12.930]     INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//trimParameters35_C0.dat

[18:06:12.936]     INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//trimParameters35_C1.dat

[18:06:12.941]     INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//trimParameters35_C2.dat

[18:06:12.946]     INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//trimParameters35_C3.dat

[18:06:12.952]     INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//trimParameters35_C4.dat

[18:06:12.957]     INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//trimParameters35_C5.dat

[18:06:12.963]     INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//trimParameters35_C6.dat

[18:06:12.968]     INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//trimParameters35_C7.dat

[18:06:12.973]     INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//trimParameters35_C8.dat

[18:06:12.979]     INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//trimParameters35_C9.dat

[18:06:12.984]     INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//trimParameters35_C10.dat

[18:06:12.990]     INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//trimParameters35_C11.dat

[18:06:12.995]     INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//trimParameters35_C12.dat

[18:06:12.001]     INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//trimParameters35_C13.dat

[18:06:12.006]     INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//trimParameters35_C14.dat

[18:06:13.012]     INFO: write trim parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//trimParameters35_C15.dat

[18:06:13.017]     INFO: PixTestTrim::trimTest() done

[18:06:13.017]     INFO: vtrim:     127 120 123 125 107 129 109 129 114 106 112  98 102 111 101 125 

[18:06:13.017]     INFO: vthrcomp:   99 103 105 102  95  97  92 101  90  84  92  94  88  91  96 100 

[18:06:13.017]     INFO: vcal mean:  35.00  35.04  35.09  35.06  35.04  34.97  35.09  34.98  34.97  34.95  34.99  35.05  34.97  34.90  35.02  35.02 

[18:06:13.017]     INFO: vcal RMS:    1.55   1.58   1.56   1.35   1.11   1.73   1.22   1.19   1.21   1.33   1.12   1.09   1.26   1.51   1.14   1.35 

[18:06:13.017]     INFO: bits mean:   9.47   9.71   9.02   8.76  10.13   9.51   9.77   9.64   9.58   9.90   9.08   9.55   8.91   9.86   9.85   9.43 

[18:06:13.017]     INFO: bits RMS:    2.47   2.52   2.22   2.62   2.45   2.38   2.27   2.60   2.54   2.34   2.57   2.48   2.71   2.39   2.54   2.57 

[18:06:13.022]     INFO:    ----------------------------------------------------------------------

[18:06:13.022]     INFO:    PixTestTrim::trimBitTest() ntrig = 10, vtrims = 255 240 150 100

[18:06:13.022]     INFO:    ----------------------------------------------------------------------

[18:06:13.027]    DEBUG: <PixTestTrim.cc/trimBitTest:L515> trimBitTest determine threshold map without trims 

[18:06:13.027]     INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 10 dacrange: 0 .. 199 (20) hits flags = 16 (plus default)

[18:06:13.036]     INFO:   dacScan step  from 0 .. 19

[18:06:13.036]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[18:06:31.175]     INFO: Test took 18139ms.

[18:06:31.210]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:06:31.210]     INFO:   dacScan step  from 20 .. 39

[18:06:31.211]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[18:06:49.496]     INFO: Test took 18285ms.

[18:06:49.547]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:06:49.550]     INFO:   dacScan step  from 40 .. 59

[18:06:49.550]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[18:07:12.669]     INFO: Test took 23119ms.

[18:07:12.912]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:07:12.940]     INFO:   dacScan step  from 60 .. 79

[18:07:12.940]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[18:07:39.880]     INFO: Test took 26940ms.

[18:07:40.154]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:07:40.182]     INFO:   dacScan step  from 80 .. 99

[18:07:40.182]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[18:08:07.109]     INFO: Test took 26927ms.

[18:08:07.383]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:08:07.411]     INFO:   dacScan step  from 100 .. 119

[18:08:07.411]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[18:08:34.408]     INFO: Test took 26997ms.

[18:08:34.682]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:08:34.709]     INFO:   dacScan step  from 120 .. 139

[18:08:34.709]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[18:09:03.225]     INFO: Test took 28516ms.

[18:09:03.500]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:09:03.528]     INFO:   dacScan step  from 140 .. 159

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

[18:09:30.651]     INFO: Test took 27123ms.

[18:09:30.924]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:09:30.951]     INFO:   dacScan step  from 160 .. 179

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

[18:09:58.013]     INFO: Test took 27061ms.

[18:09:58.285]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:09:58.312]     INFO:   dacScan step  from 180 .. 199

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

[18:10:26.114]     INFO: Test took 27802ms.

[18:10:26.384]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:10:26.411]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0

[18:10:27.803]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1

[18:10:29.203]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2

[18:10:30.631]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3

[18:10:32.021]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4

[18:10:33.385]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5

[18:10:34.808]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6

[18:10:36.194]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7

[18:10:37.565]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8

[18:10:38.951]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9

[18:10:40.340]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10

[18:10:41.743]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11

[18:10:43.111]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12

[18:10:44.481]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13

[18:10:45.845]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14

[18:10:47.226]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15

[18:10:48.619]    DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 568651776

[18:10:48.620]    DEBUG: <PixTestTrim.cc/trimBitTest:L530> trimBitTest initDUT with trim bits = 14

[18:10:48.682]    DEBUG: <PixTestTrim.cc/trimBitTest:L536> trimBitTest threshold map with trim = 14

[18:10:48.682]     INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 10 dacrange: 0 .. 140 (20) hits flags = 16 (plus default)

[18:10:48.691]     INFO:   dacScan step  from 0 .. 19

[18:10:48.691]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[18:11:06.829]     INFO: Test took 18138ms.

[18:11:06.865]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:11:06.865]     INFO:   dacScan step  from 20 .. 39

[18:11:06.865]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[18:11:25.572]     INFO: Test took 18707ms.

[18:11:25.653]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:11:25.665]     INFO:   dacScan step  from 40 .. 59

[18:11:25.665]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[18:11:50.432]     INFO: Test took 24767ms.

[18:11:50.706]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:11:50.736]     INFO:   dacScan step  from 60 .. 79

[18:11:50.736]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[18:12:17.751]     INFO: Test took 27015ms.

[18:12:18.026]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:12:18.054]     INFO:   dacScan step  from 80 .. 99

[18:12:18.054]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[18:12:45.048]     INFO: Test took 26994ms.

[18:12:45.321]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:12:45.348]     INFO:   dacScan step  from 100 .. 119

[18:12:45.349]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[18:13:12.331]     INFO: Test took 26982ms.

[18:13:12.602]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:13:12.629]     INFO:   dacScan step  from 120 .. 139

[18:13:12.629]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[18:13:41.163]     INFO: Test took 28534ms.

[18:13:41.435]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:13:41.464]     INFO:   dacScan step  from 140 .. 140

[18:13:41.464]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[18:13:45.295]     INFO: Test took 3831ms.

[18:13:45.311]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:13:45.314]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0

[18:13:46.517]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1

[18:13:47.728]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2

[18:13:48.943]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3

[18:13:50.151]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4

[18:13:51.359]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5

[18:13:52.568]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6

[18:13:53.774]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7

[18:13:54.981]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8

[18:13:56.196]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9

[18:13:57.411]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10

[18:13:58.620]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11

[18:13:59.834]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12

[18:14:01.037]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13

[18:14:02.240]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14

[18:14:03.446]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15

[18:14:04.653]    DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 568651776

[18:14:04.654]    DEBUG: <PixTestTrim.cc/trimBitTest:L530> trimBitTest initDUT with trim bits = 13

[18:14:04.716]    DEBUG: <PixTestTrim.cc/trimBitTest:L536> trimBitTest threshold map with trim = 13

[18:14:04.716]     INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 10 dacrange: 0 .. 123 (20) hits flags = 16 (plus default)

[18:14:04.725]     INFO:   dacScan step  from 0 .. 19

[18:14:04.725]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[18:14:22.861]     INFO: Test took 18136ms.

[18:14:22.898]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:14:22.898]     INFO:   dacScan step  from 20 .. 39

[18:14:22.899]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[18:14:42.439]     INFO: Test took 19540ms.

[18:14:42.566]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:14:42.584]     INFO:   dacScan step  from 40 .. 59

[18:14:42.584]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[18:15:08.539]     INFO: Test took 25955ms.

[18:15:08.825]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:15:08.854]     INFO:   dacScan step  from 60 .. 79

[18:15:08.854]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[18:15:35.874]     INFO: Test took 27020ms.

[18:15:36.145]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:15:36.172]     INFO:   dacScan step  from 80 .. 99

[18:15:36.173]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[18:16:03.091]     INFO: Test took 26918ms.

[18:16:03.368]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:16:03.396]     INFO:   dacScan step  from 100 .. 119

[18:16:03.396]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[18:16:30.395]     INFO: Test took 26999ms.

[18:16:30.671]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:16:30.699]     INFO:   dacScan step  from 120 .. 123

[18:16:30.699]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[18:16:38.047]     INFO: Test took 7348ms.

[18:16:38.102]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:16:38.113]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0

[18:16:39.263]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1

[18:16:40.408]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2

[18:16:41.559]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3

[18:16:42.700]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4

[18:16:43.848]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5

[18:16:44.997]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6

[18:16:46.140]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7

[18:16:47.279]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8

[18:16:48.421]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9

[18:16:49.570]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10

[18:16:50.711]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11

[18:16:51.850]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12

[18:16:52.987]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13

[18:16:54.131]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14

[18:16:55.280]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15

[18:16:56.418]    DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 568655872

[18:16:56.419]    DEBUG: <PixTestTrim.cc/trimBitTest:L530> trimBitTest initDUT with trim bits = 11

[18:16:56.481]    DEBUG: <PixTestTrim.cc/trimBitTest:L536> trimBitTest threshold map with trim = 11

[18:16:56.481]     INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 10 dacrange: 0 .. 112 (20) hits flags = 16 (plus default)

[18:16:56.490]     INFO:   dacScan step  from 0 .. 19

[18:16:56.490]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[18:17:14.641]     INFO: Test took 18151ms.

[18:17:14.679]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:17:14.680]     INFO:   dacScan step  from 20 .. 39

[18:17:14.680]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[18:17:34.887]     INFO: Test took 20207ms.

[18:17:35.042]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:17:35.064]     INFO:   dacScan step  from 40 .. 59

[18:17:35.065]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[18:18:01.425]     INFO: Test took 26360ms.

[18:18:01.707]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:18:01.736]     INFO:   dacScan step  from 60 .. 79

[18:18:01.736]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[18:18:28.787]     INFO: Test took 27051ms.

[18:18:29.061]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:18:29.088]     INFO:   dacScan step  from 80 .. 99

[18:18:29.089]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[18:18:56.076]     INFO: Test took 26987ms.

[18:18:56.355]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:18:56.382]     INFO:   dacScan step  from 100 .. 112

[18:18:56.382]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[18:19:14.684]     INFO: Test took 18302ms.

[18:19:14.865]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:19:14.883]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0

[18:19:15.964]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1

[18:19:17.045]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2

[18:19:18.120]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3

[18:19:19.199]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4

[18:19:20.283]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5

[18:19:21.363]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6

[18:19:22.445]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7

[18:19:23.521]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8

[18:19:24.597]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9

[18:19:25.677]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10

[18:19:26.758]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11

[18:19:27.839]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12

[18:19:28.914]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13

[18:19:29.996]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14

[18:19:31.077]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15

[18:19:32.155]    DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 568655872

[18:19:32.156]    DEBUG: <PixTestTrim.cc/trimBitTest:L530> trimBitTest initDUT with trim bits = 7

[18:19:32.218]    DEBUG: <PixTestTrim.cc/trimBitTest:L536> trimBitTest threshold map with trim = 7

[18:19:32.218]     INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 10 dacrange: 0 .. 255 (20) hits flags = 16 (plus default)

[18:19:32.227]     INFO:   dacScan step  from 0 .. 19

[18:19:32.227]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[18:19:50.405]     INFO: Test took 18178ms.

[18:19:50.447]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:19:50.449]     INFO:   dacScan step  from 20 .. 39

[18:19:50.449]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[18:20:11.875]     INFO: Test took 21426ms.

[18:20:12.075]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:20:12.102]     INFO:   dacScan step  from 40 .. 59

[18:20:12.102]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[18:20:38.691]     INFO: Test took 26589ms.

[18:20:38.975]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:20:38.004]     INFO:   dacScan step  from 60 .. 79

[18:20:38.004]    DEBUG: <PixTest.cc/dacScan:L1518>       attempt #0

[18:21:05.837]     INFO: Test took 26833ms.

[18:21:06.115]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:21:06.143]     INFO:   dacScan step  from 80 .. 99

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

[18:21:32.991]     INFO: Test took 26848ms.

[18:21:33.270]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:21:33.298]     INFO:   dacScan step  from 100 .. 119

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

[18:22:00.313]     INFO: Test took 27015ms.

[18:22:00.590]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:22:00.618]     INFO:   dacScan step  from 120 .. 139

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

[18:22:29.100]     INFO: Test took 28482ms.

[18:22:29.373]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:22:29.400]     INFO:   dacScan step  from 140 .. 159

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

[18:22:56.568]     INFO: Test took 27168ms.

[18:22:56.847]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:22:56.875]     INFO:   dacScan step  from 160 .. 179

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

[18:23:23.815]     INFO: Test took 26940ms.

[18:23:24.092]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:23:24.120]     INFO:   dacScan step  from 180 .. 199

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

[18:23:51.951]     INFO: Test took 27831ms.

[18:23:52.225]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:23:52.253]     INFO:   dacScan step  from 200 .. 219

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

[18:24:19.180]     INFO: Test took 26927ms.

[18:24:19.453]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:24:19.481]     INFO:   dacScan step  from 220 .. 239

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

[18:24:46.403]     INFO: Test took 26922ms.

[18:24:46.685]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:24:46.712]     INFO:   dacScan step  from 240 .. 255

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

[18:25:08.526]     INFO: Test took 21814ms.

[18:25:08.749]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:25:08.772]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 0

[18:25:10.287]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 1

[18:25:11.813]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 2

[18:25:13.355]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 3

[18:25:14.850]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 4

[18:25:16.334]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 5

[18:25:17.894]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 6

[18:25:19.388]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 7

[18:25:20.920]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 8

[18:25:22.420]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 9

[18:25:23.943]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 10

[18:25:25.453]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 11

[18:25:26.940]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 12

[18:25:28.419]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 13

[18:25:29.902]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 14

[18:25:31.412]    DEBUG: <PixTest.cc/scurveAna:L1579> analyzing ROC 15

[18:25:32.932]    DEBUG: <PixTest.cc/scurveMaps:L251> PixTest::scurveMaps end: getCurrentRSS() = 568655872

[18:25:33.048]     INFO: PixTestTrim::trimBitTest() done 

[18:25:33.050]     INFO: PixTestTrim::doTest() done, duration: 2251 seconds

[18:25:33.050]    DEBUG: <PixTestTrim.cc/~PixTestTrim:L104> PixTestTrim dtor

[18:25:33.627]    DEBUG: <PixTest.cc/setTestParameter:L569>  setting  ntrig to new value 10

[18:25:33.627]    DEBUG: <PixTestPhOptimization.cc/setParameter:L37>   setting fParNtrig  ->10<- from sval = 10

[18:25:33.627]    DEBUG: <PixTestPhOptimization.cc/setParameter:L42>   setting fSafetyMarginLow  ->20<- from sval = 20

[18:25:33.627]    DEBUG: <PixTestPhOptimization.cc/setParameter:L48>   setting fVcalMax  ->100<- from sval = 100

[18:25:33.627]    DEBUG: <PixTestPhOptimization.cc/setParameter:L53>   setting fQuantMax  ->0.98<- from sval = 0.98

[18:25:33.627]     INFO: ######################################################################

[18:25:33.627]     INFO: PixTestPhOptimization::doTest() Ntrig = 10

[18:25:33.627]     INFO: ######################################################################

[18:25:33.629]    DEBUG: <PixTest.cc/efficiencyMaps:L328>       attempt #0

[18:25:37.315]     INFO: Test took 3686ms.

[18:25:37.333]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:25:37.333]    DEBUG: <PixTest.cc/efficiencyMaps:L339>  eff result size = 66530

[18:25:37.333]    DEBUG: <PixTest.cc/efficiencyMaps:L344> Create hists PixelAlive_C0 .. PixelAlive_C15

[18:25:37.336]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [0, 0, 0] has eff 0/10

[18:25:37.336]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [0, 0, 0]

[18:25:37.336]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [0, 0, 1] has eff 0/10

[18:25:37.336]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [0, 0, 1]

[18:25:37.336]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [0, 28, 49] has eff 0/10

[18:25:37.336]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [0, 28, 49]

[18:25:37.336]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [0, 7, 69] has eff 6/10

[18:25:37.336]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [0, 7, 69]

[18:25:37.336]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [1, 16, 9] has eff 0/10

[18:25:37.336]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [1, 16, 9]

[18:25:37.336]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [1, 17, 9] has eff 0/10

[18:25:37.336]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [1, 17, 9]

[18:25:37.336]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [1, 16, 10] has eff 0/10

[18:25:37.336]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [1, 16, 10]

[18:25:37.336]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [1, 17, 10] has eff 0/10

[18:25:37.336]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [1, 17, 10]

[18:25:37.337]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [2, 23, 40] has eff 0/10

[18:25:37.337]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [2, 23, 40]

[18:25:37.337]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [2, 51, 56] has eff 0/10

[18:25:37.337]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [2, 51, 56]

[18:25:37.337]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [2, 36, 69] has eff 0/10

[18:25:37.337]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [2, 36, 69]

[18:25:37.337]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [2, 42, 75] has eff 0/10

[18:25:37.337]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [2, 42, 75]

[18:25:37.337]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [3, 49, 33] has eff 0/10

[18:25:37.337]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [3, 49, 33]

[18:25:37.337]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [3, 30, 39] has eff 0/10

[18:25:37.337]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [3, 30, 39]

[18:25:37.337]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [3, 47, 47] has eff 0/10

[18:25:37.337]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [3, 47, 47]

[18:25:37.337]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [5, 33, 9] has eff 2/10

[18:25:37.337]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [5, 33, 9]

[18:25:37.337]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [5, 33, 26] has eff 0/10

[18:25:37.337]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [5, 33, 26]

[18:25:37.337]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [5, 43, 32] has eff 0/10

[18:25:37.337]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [5, 43, 32]

[18:25:37.337]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [5, 38, 43] has eff 0/10

[18:25:37.337]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [5, 38, 43]

[18:25:37.337]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [5, 11, 52] has eff 5/10

[18:25:37.337]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [5, 11, 52]

[18:25:37.337]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [5, 44, 62] has eff 0/10

[18:25:37.337]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [5, 44, 62]

[18:25:37.337]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [6, 0, 30] has eff 0/10

[18:25:37.337]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [6, 0, 30]

[18:25:37.337]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [7, 50, 26] has eff 0/10

[18:25:37.337]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [7, 50, 26]

[18:25:37.338]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [8, 0, 70] has eff 0/10

[18:25:37.338]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [8, 0, 70]

[18:25:37.338]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [9, 47, 22] has eff 2/10

[18:25:37.338]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [9, 47, 22]

[18:25:37.338]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [9, 38, 43] has eff 0/10

[18:25:37.338]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [9, 38, 43]

[18:25:37.338]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [12, 21, 22] has eff 0/10

[18:25:37.338]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [12, 21, 22]

[18:25:37.338]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [12, 30, 49] has eff 0/10

[18:25:37.338]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [12, 30, 49]

[18:25:37.338]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [13, 49, 14] has eff 0/10

[18:25:37.338]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [13, 49, 14]

[18:25:37.338]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [13, 2, 73] has eff 0/10

[18:25:37.338]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [13, 2, 73]

[18:25:37.338]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [13, 18, 76] has eff 0/10

[18:25:37.338]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [13, 18, 76]

[18:25:37.338]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [13, 19, 76] has eff 0/10

[18:25:37.338]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [13, 19, 76]

[18:25:37.338]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [15, 50, 0] has eff 0/10

[18:25:37.338]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [15, 50, 0]

[18:25:37.338]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L227> Pixel [15, 51, 0] has eff 0/10

[18:25:37.338]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L231> bad Pixel found and blacklisted: [15, 51, 0]

[18:25:37.343]    DEBUG: <PixTestPhOptimization.cc/BlacklistPixels:L239> Number of bad pixels found: 34

[18:25:37.343]    DEBUG: <PixTestPhOptimization.cc/doTest:L124> **********Ph range will be optimised on the whole ROC***********

[18:25:37.343]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L276> ROC type is newer than digv2

[18:25:37.343]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L277> ROC type is psi46digv21respin

[18:25:37.533]    DEBUG: <PixTest.cc/phMaps:L264>       attempt #0

[18:25:41.218]     INFO: Test took 3685ms.

[18:25:41.279]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:25:41.279]    DEBUG: <PixTest.cc/phMaps:L275>  eff result size = 66532

[18:25:41.279]    DEBUG: <PixTest.cc/phMaps:L282> Create hists maxphmap_C0 .. maxphmap_C15

[18:25:41.283]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 175.234

[18:25:41.283]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,6] phvalue 175

[18:25:41.283]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 174.048

[18:25:41.283]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [4 ,6] phvalue 175

[18:25:41.283]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 170.825

[18:25:41.283]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [6 ,9] phvalue 170

[18:25:41.283]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 175.719

[18:25:41.283]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [14 ,7] phvalue 175

[18:25:41.284]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 165.074

[18:25:41.284]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [6 ,5] phvalue 165

[18:25:41.284]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 171.57

[18:25:41.284]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [4 ,5] phvalue 172

[18:25:41.284]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 181.528

[18:25:41.284]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [6 ,12] phvalue 182

[18:25:41.284]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 176.447

[18:25:41.284]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,5] phvalue 177

[18:25:41.284]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 171.524

[18:25:41.284]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [4 ,7] phvalue 171

[18:25:41.284]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 165.09

[18:25:41.284]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [4 ,6] phvalue 165

[18:25:41.284]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 179.547

[18:25:41.284]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,7] phvalue 180

[18:25:41.285]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 184.053

[18:25:41.285]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,16] phvalue 184

[18:25:41.285]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 177.066

[18:25:41.285]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,5] phvalue 177

[18:25:41.285]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 167.264

[18:25:41.285]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,6] phvalue 168

[18:25:41.285]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 165.68

[18:25:41.285]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [4 ,6] phvalue 165

[18:25:41.285]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L347> maxph quantile 172.633

[18:25:41.285]    DEBUG: <PixTestPhOptimization.cc/GetMaxPhPixel:L371> Max pixel is [3 ,10] phvalue 172

[18:25:41.285]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L427> ROC type is newer than digv2

[18:25:41.285]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L428> ROC type is psi46digv21respin

[18:25:41.285]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L450> init_phScale=150, flag_minPh = 0, minph = 0

[18:25:41.293]    DEBUG: <PixTest.cc/phMaps:L264>       attempt #0

[18:25:44.996]     INFO: Test took 3703ms.

[18:25:45.056]     INFO: Fetched DAQ statistics. Counters are being reset now.

[18:25:45.056]    DEBUG: <PixTest.cc/phMaps:L275>  eff result size = 66531

[18:25:45.056]    DEBUG: <PixTest.cc/phMaps:L282> Create hists minphmap_C0 .. minphmap_C15

[18:25:45.059]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L457> result size 0

[18:25:45.060]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L484> done. init_phScale=155, flag_minPh = 1, minph = 55minph_roc = 4

[18:25:45.060]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 71.3169

[18:25:45.060]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [4 ,25] phvalue 72

[18:25:45.060]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 75.6782

[18:25:45.060]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,44] phvalue 75

[18:25:45.060]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 60.475

[18:25:45.060]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,6] phvalue 61

[18:25:45.061]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 70.365

[18:25:45.061]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,32] phvalue 71

[18:25:45.061]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 60.2741

[18:25:45.061]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,10] phvalue 61

[18:25:45.061]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 61.5827

[18:25:45.061]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,43] phvalue 62

[18:25:45.061]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 76.7473

[18:25:45.061]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,13] phvalue 77

[18:25:45.061]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 71.1817

[18:25:45.061]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [4 ,12] phvalue 72

[18:25:45.061]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 66.1642

[18:25:45.061]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [6 ,49] phvalue 67

[18:25:45.061]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 67.2967

[18:25:45.061]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,6] phvalue 68

[18:25:45.061]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 67.582

[18:25:45.061]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [6 ,14] phvalue 68

[18:25:45.062]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 78.7856

[18:25:45.062]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [14 ,44] phvalue 79

[18:25:45.062]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 70.6307

[18:25:45.062]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [5 ,62] phvalue 71

[18:25:45.062]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 64.9891

[18:25:45.062]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [8 ,42] phvalue 65

[18:25:45.062]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 64.0959

[18:25:45.062]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [3 ,12] phvalue 65

[18:25:45.062]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L502> minph quantile 0.02 61.8177

[18:25:45.062]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L525> Min pixel is [8 ,9] phvalue 62

[18:25:45.064]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 4, 25, 0 0

[18:25:45.064]     INFO: The DUT currently contains the following objects:

[18:25:45.064]     INFO:  2 TBM Cores tbm08c (2 ON)

[18:25:45.064]     INFO: 	TBM Core alpha (0): 7 registers set

[18:25:45.064]     INFO: 	TBM Core beta  (1): 7 registers set

[18:25:45.064]     INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs

[18:25:45.064]     INFO: 	ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:45.064]     INFO: 	ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:45.064]     INFO: 	ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:45.064]     INFO: 	ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:45.064]     INFO: 	ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:45.064]     INFO: 	ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:45.064]     INFO: 	ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:45.064]     INFO: 	ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:45.064]     INFO: 	ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:45.064]     INFO: 	ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:45.065]     INFO: 	ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:45.065]     INFO: 	ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:45.065]     INFO: 	ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:45.065]     INFO: 	ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:45.065]     INFO: 	ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:45.065]     INFO: 	ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:46.155]     INFO: Test took 1090ms.

[18:25:46.155]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256

[18:25:46.156]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 44, 1 1

[18:25:46.156]     INFO: The DUT currently contains the following objects:

[18:25:46.156]     INFO:  2 TBM Cores tbm08c (2 ON)

[18:25:46.156]     INFO: 	TBM Core alpha (0): 7 registers set

[18:25:46.156]     INFO: 	TBM Core beta  (1): 7 registers set

[18:25:46.156]     INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs

[18:25:46.156]     INFO: 	ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:46.156]     INFO: 	ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:46.156]     INFO: 	ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:46.156]     INFO: 	ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:46.156]     INFO: 	ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:46.156]     INFO: 	ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:46.156]     INFO: 	ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:46.156]     INFO: 	ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:46.156]     INFO: 	ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:46.156]     INFO: 	ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:46.156]     INFO: 	ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:46.156]     INFO: 	ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:46.156]     INFO: 	ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:46.156]     INFO: 	ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:46.156]     INFO: 	ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:46.156]     INFO: 	ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:47.246]     INFO: Test took 1090ms.

[18:25:47.247]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256

[18:25:47.247]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 6, 2 2

[18:25:47.247]     INFO: The DUT currently contains the following objects:

[18:25:47.247]     INFO:  2 TBM Cores tbm08c (2 ON)

[18:25:47.247]     INFO: 	TBM Core alpha (0): 7 registers set

[18:25:47.247]     INFO: 	TBM Core beta  (1): 7 registers set

[18:25:47.247]     INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs

[18:25:47.247]     INFO: 	ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:47.247]     INFO: 	ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:47.247]     INFO: 	ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:47.247]     INFO: 	ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:47.247]     INFO: 	ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:47.247]     INFO: 	ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:47.247]     INFO: 	ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:47.247]     INFO: 	ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:47.247]     INFO: 	ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:47.247]     INFO: 	ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:47.247]     INFO: 	ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:47.247]     INFO: 	ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:47.247]     INFO: 	ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:47.247]     INFO: 	ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:47.247]     INFO: 	ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:47.248]     INFO: 	ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:48.338]     INFO: Test took 1090ms.

[18:25:48.338]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256

[18:25:48.338]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 32, 3 3

[18:25:48.339]     INFO: The DUT currently contains the following objects:

[18:25:48.339]     INFO:  2 TBM Cores tbm08c (2 ON)

[18:25:48.339]     INFO: 	TBM Core alpha (0): 7 registers set

[18:25:48.339]     INFO: 	TBM Core beta  (1): 7 registers set

[18:25:48.339]     INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs

[18:25:48.339]     INFO: 	ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:48.339]     INFO: 	ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:48.339]     INFO: 	ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:48.339]     INFO: 	ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:48.339]     INFO: 	ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:48.339]     INFO: 	ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:48.339]     INFO: 	ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:48.339]     INFO: 	ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:48.339]     INFO: 	ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:48.339]     INFO: 	ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:48.339]     INFO: 	ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:48.339]     INFO: 	ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:48.339]     INFO: 	ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:48.339]     INFO: 	ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:48.339]     INFO: 	ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:48.339]     INFO: 	ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:49.429]     INFO: Test took 1090ms.

[18:25:49.430]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256

[18:25:49.430]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 10, 4 4

[18:25:49.430]     INFO: The DUT currently contains the following objects:

[18:25:49.430]     INFO:  2 TBM Cores tbm08c (2 ON)

[18:25:49.430]     INFO: 	TBM Core alpha (0): 7 registers set

[18:25:49.430]     INFO: 	TBM Core beta  (1): 7 registers set

[18:25:49.430]     INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs

[18:25:49.430]     INFO: 	ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:49.430]     INFO: 	ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:49.430]     INFO: 	ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:49.430]     INFO: 	ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:49.430]     INFO: 	ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:49.430]     INFO: 	ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:49.430]     INFO: 	ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:49.430]     INFO: 	ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:49.430]     INFO: 	ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:49.430]     INFO: 	ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:49.430]     INFO: 	ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:49.430]     INFO: 	ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:49.430]     INFO: 	ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:49.430]     INFO: 	ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:49.430]     INFO: 	ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:49.430]     INFO: 	ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:50.521]     INFO: Test took 1091ms.

[18:25:50.521]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256

[18:25:50.521]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 43, 5 5

[18:25:50.522]     INFO: The DUT currently contains the following objects:

[18:25:50.522]     INFO:  2 TBM Cores tbm08c (2 ON)

[18:25:50.522]     INFO: 	TBM Core alpha (0): 7 registers set

[18:25:50.522]     INFO: 	TBM Core beta  (1): 7 registers set

[18:25:50.522]     INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs

[18:25:50.522]     INFO: 	ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:50.522]     INFO: 	ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:50.522]     INFO: 	ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:50.522]     INFO: 	ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:50.522]     INFO: 	ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:50.522]     INFO: 	ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:50.522]     INFO: 	ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:50.522]     INFO: 	ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:50.522]     INFO: 	ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:50.522]     INFO: 	ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:50.522]     INFO: 	ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:50.522]     INFO: 	ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:50.522]     INFO: 	ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:50.522]     INFO: 	ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:50.522]     INFO: 	ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:50.522]     INFO: 	ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:51.612]     INFO: Test took 1090ms.

[18:25:51.613]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256

[18:25:51.613]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 13, 6 6

[18:25:51.613]     INFO: The DUT currently contains the following objects:

[18:25:51.613]     INFO:  2 TBM Cores tbm08c (2 ON)

[18:25:51.613]     INFO: 	TBM Core alpha (0): 7 registers set

[18:25:51.613]     INFO: 	TBM Core beta  (1): 7 registers set

[18:25:51.613]     INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs

[18:25:51.613]     INFO: 	ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:51.613]     INFO: 	ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:51.613]     INFO: 	ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:51.613]     INFO: 	ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:51.613]     INFO: 	ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:51.613]     INFO: 	ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:51.613]     INFO: 	ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:51.613]     INFO: 	ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:51.613]     INFO: 	ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:51.613]     INFO: 	ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:51.613]     INFO: 	ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:51.613]     INFO: 	ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:51.613]     INFO: 	ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:51.613]     INFO: 	ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:51.613]     INFO: 	ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:51.613]     INFO: 	ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:52.704]     INFO: Test took 1091ms.

[18:25:52.704]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256

[18:25:52.704]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 4, 12, 7 7

[18:25:52.704]     INFO: The DUT currently contains the following objects:

[18:25:52.704]     INFO:  2 TBM Cores tbm08c (2 ON)

[18:25:52.704]     INFO: 	TBM Core alpha (0): 7 registers set

[18:25:52.704]     INFO: 	TBM Core beta  (1): 7 registers set

[18:25:52.704]     INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs

[18:25:52.704]     INFO: 	ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:52.704]     INFO: 	ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:52.704]     INFO: 	ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:52.705]     INFO: 	ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:52.705]     INFO: 	ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:52.705]     INFO: 	ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:52.705]     INFO: 	ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:52.705]     INFO: 	ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:52.705]     INFO: 	ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:52.705]     INFO: 	ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:52.705]     INFO: 	ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:52.705]     INFO: 	ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:52.705]     INFO: 	ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:52.705]     INFO: 	ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:52.705]     INFO: 	ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:52.705]     INFO: 	ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:53.796]     INFO: Test took 1091ms.

[18:25:53.796]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256

[18:25:53.796]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 6, 49, 8 8

[18:25:53.796]     INFO: The DUT currently contains the following objects:

[18:25:53.796]     INFO:  2 TBM Cores tbm08c (2 ON)

[18:25:53.796]     INFO: 	TBM Core alpha (0): 7 registers set

[18:25:53.796]     INFO: 	TBM Core beta  (1): 7 registers set

[18:25:53.796]     INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs

[18:25:53.796]     INFO: 	ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:53.796]     INFO: 	ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:53.797]     INFO: 	ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:53.797]     INFO: 	ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:53.797]     INFO: 	ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:53.797]     INFO: 	ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:53.797]     INFO: 	ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:53.797]     INFO: 	ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:53.797]     INFO: 	ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:53.797]     INFO: 	ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:53.797]     INFO: 	ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:53.797]     INFO: 	ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:53.797]     INFO: 	ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:53.797]     INFO: 	ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:53.797]     INFO: 	ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:53.797]     INFO: 	ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:54.887]     INFO: Test took 1090ms.

[18:25:54.888]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256

[18:25:54.888]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 6, 9 9

[18:25:54.888]     INFO: The DUT currently contains the following objects:

[18:25:54.888]     INFO:  2 TBM Cores tbm08c (2 ON)

[18:25:54.888]     INFO: 	TBM Core alpha (0): 7 registers set

[18:25:54.888]     INFO: 	TBM Core beta  (1): 7 registers set

[18:25:54.888]     INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs

[18:25:54.888]     INFO: 	ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:54.888]     INFO: 	ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:54.888]     INFO: 	ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:54.888]     INFO: 	ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:54.888]     INFO: 	ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:54.888]     INFO: 	ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:54.888]     INFO: 	ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:54.888]     INFO: 	ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:54.888]     INFO: 	ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:54.888]     INFO: 	ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:54.888]     INFO: 	ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:54.888]     INFO: 	ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:54.888]     INFO: 	ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:54.888]     INFO: 	ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:54.888]     INFO: 	ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:54.888]     INFO: 	ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:55.979]     INFO: Test took 1091ms.

[18:25:55.980]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256

[18:25:55.980]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 6, 14, 10 10

[18:25:55.980]     INFO: The DUT currently contains the following objects:

[18:25:55.980]     INFO:  2 TBM Cores tbm08c (2 ON)

[18:25:55.980]     INFO: 	TBM Core alpha (0): 7 registers set

[18:25:55.980]     INFO: 	TBM Core beta  (1): 7 registers set

[18:25:55.980]     INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs

[18:25:55.980]     INFO: 	ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:55.980]     INFO: 	ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:55.980]     INFO: 	ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:55.980]     INFO: 	ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:55.980]     INFO: 	ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:55.980]     INFO: 	ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:55.980]     INFO: 	ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:55.980]     INFO: 	ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:55.980]     INFO: 	ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:55.980]     INFO: 	ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:55.980]     INFO: 	ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:55.980]     INFO: 	ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:55.980]     INFO: 	ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:55.980]     INFO: 	ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:55.980]     INFO: 	ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:55.980]     INFO: 	ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:57.071]     INFO: Test took 1091ms.

[18:25:57.071]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256

[18:25:57.071]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 14, 44, 11 11

[18:25:57.071]     INFO: The DUT currently contains the following objects:

[18:25:57.071]     INFO:  2 TBM Cores tbm08c (2 ON)

[18:25:57.071]     INFO: 	TBM Core alpha (0): 7 registers set

[18:25:57.071]     INFO: 	TBM Core beta  (1): 7 registers set

[18:25:57.071]     INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs

[18:25:57.071]     INFO: 	ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:57.071]     INFO: 	ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:57.071]     INFO: 	ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:57.071]     INFO: 	ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:57.071]     INFO: 	ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:57.072]     INFO: 	ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:57.072]     INFO: 	ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:57.072]     INFO: 	ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:57.072]     INFO: 	ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:57.072]     INFO: 	ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:57.072]     INFO: 	ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:57.072]     INFO: 	ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:57.072]     INFO: 	ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:57.072]     INFO: 	ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:57.072]     INFO: 	ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:57.072]     INFO: 	ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:58.162]     INFO: Test took 1090ms.

[18:25:58.163]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256

[18:25:58.163]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 5, 62, 12 12

[18:25:58.163]     INFO: The DUT currently contains the following objects:

[18:25:58.163]     INFO:  2 TBM Cores tbm08c (2 ON)

[18:25:58.163]     INFO: 	TBM Core alpha (0): 7 registers set

[18:25:58.163]     INFO: 	TBM Core beta  (1): 7 registers set

[18:25:58.163]     INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs

[18:25:58.163]     INFO: 	ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:58.163]     INFO: 	ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:58.163]     INFO: 	ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:58.163]     INFO: 	ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:58.163]     INFO: 	ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:58.163]     INFO: 	ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:58.163]     INFO: 	ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:58.163]     INFO: 	ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:58.163]     INFO: 	ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:58.163]     INFO: 	ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:58.163]     INFO: 	ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:58.163]     INFO: 	ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:58.163]     INFO: 	ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:58.163]     INFO: 	ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:58.163]     INFO: 	ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:58.163]     INFO: 	ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:59.254]     INFO: Test took 1091ms.

[18:25:59.255]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256

[18:25:59.255]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 8, 42, 13 13

[18:25:59.255]     INFO: The DUT currently contains the following objects:

[18:25:59.255]     INFO:  2 TBM Cores tbm08c (2 ON)

[18:25:59.255]     INFO: 	TBM Core alpha (0): 7 registers set

[18:25:59.255]     INFO: 	TBM Core beta  (1): 7 registers set

[18:25:59.255]     INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs

[18:25:59.255]     INFO: 	ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:59.255]     INFO: 	ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:59.255]     INFO: 	ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:59.255]     INFO: 	ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:59.255]     INFO: 	ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:59.255]     INFO: 	ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:59.255]     INFO: 	ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:59.255]     INFO: 	ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:59.255]     INFO: 	ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:59.255]     INFO: 	ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:59.255]     INFO: 	ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:59.255]     INFO: 	ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:59.255]     INFO: 	ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:59.255]     INFO: 	ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:59.255]     INFO: 	ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:25:59.255]     INFO: 	ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:26:00.346]     INFO: Test took 1091ms.

[18:26:00.347]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256

[18:26:00.347]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 3, 12, 14 14

[18:26:00.347]     INFO: The DUT currently contains the following objects:

[18:26:00.347]     INFO:  2 TBM Cores tbm08c (2 ON)

[18:26:00.347]     INFO: 	TBM Core alpha (0): 7 registers set

[18:26:00.347]     INFO: 	TBM Core beta  (1): 7 registers set

[18:26:00.347]     INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs

[18:26:00.347]     INFO: 	ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:26:00.347]     INFO: 	ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:26:00.347]     INFO: 	ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:26:00.347]     INFO: 	ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:26:00.347]     INFO: 	ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:26:00.347]     INFO: 	ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:26:00.347]     INFO: 	ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:26:00.347]     INFO: 	ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:26:00.347]     INFO: 	ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:26:00.347]     INFO: 	ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:26:00.347]     INFO: 	ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:26:00.347]     INFO: 	ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:26:00.347]     INFO: 	ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:26:00.347]     INFO: 	ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:26:00.347]     INFO: 	ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:26:00.347]     INFO: 	ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:26:01.438]     INFO: Test took 1091ms.

[18:26:01.438]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256

[18:26:01.438]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L591> enabling pixels 8, 9, 15 15

[18:26:01.438]     INFO: The DUT currently contains the following objects:

[18:26:01.438]     INFO:  2 TBM Cores tbm08c (2 ON)

[18:26:01.438]     INFO: 	TBM Core alpha (0): 7 registers set

[18:26:01.438]     INFO: 	TBM Core beta  (1): 7 registers set

[18:26:01.438]     INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs

[18:26:01.438]     INFO: 	ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:26:01.438]     INFO: 	ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:26:01.438]     INFO: 	ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:26:01.438]     INFO: 	ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:26:01.438]     INFO: 	ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:26:01.438]     INFO: 	ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:26:01.438]     INFO: 	ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:26:01.439]     INFO: 	ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:26:01.439]     INFO: 	ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:26:01.439]     INFO: 	ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:26:01.439]     INFO: 	ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:26:01.439]     INFO: 	ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:26:01.439]     INFO: 	ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:26:01.439]     INFO: 	ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:26:01.439]     INFO: 	ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:26:01.439]     INFO: 	ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.

[18:26:02.529]     INFO: Test took 1090ms.

[18:26:02.529]    DEBUG: <PixTestPhOptimization.cc/GetMinPhPixel:L611> size of results 256

[18:26:02.529]    DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 32 on ROC0

[18:26:02.529]    DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 32 on ROC1

[18:26:02.530]    DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 31 on ROC2

[18:26:02.530]    DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 32 on ROC3

[18:26:02.530]    DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 31 on ROC4

[18:26:02.530]    DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 33 on ROC5

[18:26:02.530]    DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 33 on ROC6

[18:26:02.530]    DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 30 on ROC7

[18:26:02.530]    DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 28 on ROC8

[18:26:02.530]    DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 33 on ROC9

[18:26:02.530]    DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 31 on ROC10

[18:26:02.530]    DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 34 on ROC11

[18:26:02.530]    DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 33 on ROC12

[18:26:02.530]    DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 31 on ROC13

[18:26:02.530]    DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 31 on ROC14

[18:26:02.530]    DEBUG: <PixTestPhOptimization.cc/doTest:L132> vcal min 33 on ROC15

[18:26:02.534]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[18:28:52.448]     INFO: Test took 169914ms.

[18:28:53.948]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[18:31:43.283]     INFO: Test took 169335ms.

[18:31:44.894]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component

[18:31:44.894]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip0

[18:31:44.894]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component

[18:31:44.894]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip1

[18:31:44.894]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component

[18:31:44.895]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip2

[18:31:44.895]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component

[18:31:44.895]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip3

[18:31:44.895]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component

[18:31:44.895]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip4

[18:31:44.895]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component

[18:31:44.896]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip5

[18:31:44.896]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component

[18:31:44.896]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip6

[18:31:44.896]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component

[18:31:44.896]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip7

[18:31:44.897]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component

[18:31:44.897]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip8

[18:31:44.897]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component

[18:31:44.897]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip9

[18:31:44.897]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component

[18:31:44.898]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip10

[18:31:44.898]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component

[18:31:44.898]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip11

[18:31:44.898]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component

[18:31:44.898]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip12

[18:31:44.898]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component

[18:31:44.899]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip13

[18:31:44.899]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component

[18:31:44.899]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip14

[18:31:44.899]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L927> before assigning th2_sol to vector component

[18:31:44.899]    DEBUG: <PixTestPhOptimization.cc/optimiseOnMapsNew:L934> after assigning th2_sol to vector component, chip15

[18:31:44.899]     INFO: safety margin for low PH: adding 0, margin is now 20

[18:31:44.905]     INFO: safety margin for low PH: adding 0, margin is now 20

[18:31:44.910]     INFO: safety margin for low PH: adding 0, margin is now 20

[18:31:44.916]     INFO: safety margin for low PH: adding 1, margin is now 21

[18:31:44.922]     INFO: safety margin for low PH: adding 0, margin is now 20

[18:31:44.927]     INFO: safety margin for low PH: adding 0, margin is now 20

[18:31:44.933]     INFO: safety margin for low PH: adding 0, margin is now 20

[18:31:44.938]     INFO: safety margin for low PH: adding 0, margin is now 20

[18:31:44.944]     INFO: safety margin for low PH: adding 0, margin is now 20

[18:31:44.949]     INFO: safety margin for low PH: adding 0, margin is now 20

[18:31:44.955]     INFO: safety margin for low PH: adding 0, margin is now 20

[18:31:44.960]     INFO: safety margin for low PH: adding 0, margin is now 20

[18:31:44.966]     INFO: safety margin for low PH: adding 0, margin is now 20

[18:31:44.971]     INFO: safety margin for low PH: adding 0, margin is now 20

[18:31:44.977]     INFO: safety margin for low PH: adding 0, margin is now 20

[18:31:44.983]     INFO: safety margin for low PH: adding 0, margin is now 20

[18:31:44.988]     INFO: safety margin for low PH: adding 0, margin is now 20

[18:31:44.994]    DEBUG: <PixTestPhOptimization.cc/doTest:L172> optimisation done

[18:31:45.042]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//dacParameters35_C0.dat

[18:31:45.043]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//dacParameters35_C1.dat

[18:31:45.043]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//dacParameters35_C2.dat

[18:31:45.043]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//dacParameters35_C3.dat

[18:31:45.043]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//dacParameters35_C4.dat

[18:31:45.043]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//dacParameters35_C5.dat

[18:31:45.043]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//dacParameters35_C6.dat

[18:31:45.043]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//dacParameters35_C7.dat

[18:31:45.043]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//dacParameters35_C8.dat

[18:31:45.043]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//dacParameters35_C9.dat

[18:31:45.043]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//dacParameters35_C10.dat

[18:31:45.043]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//dacParameters35_C11.dat

[18:31:45.044]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//dacParameters35_C12.dat

[18:31:45.044]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//dacParameters35_C13.dat

[18:31:45.044]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//dacParameters35_C14.dat

[18:31:45.044]     INFO: write dac parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//dacParameters35_C15.dat

[18:31:48.739]     INFO: Test took 3691ms.

[18:31:52.682]     INFO: Test took 3665ms.

[18:31:56.646]     INFO: Test took 3686ms.

[18:31:56.931]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[18:31:57.833]     INFO: Test took 902ms.

[18:31:57.836]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[18:31:58.926]     INFO: Test took 1090ms.

[18:31:58.929]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[18:32:00.019]     INFO: Test took 1090ms.

[18:32:00.023]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[18:32:01.113]     INFO: Test took 1090ms.

[18:32:01.116]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[18:32:02.206]     INFO: Test took 1090ms.

[18:32:02.209]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[18:32:03.299]     INFO: Test took 1090ms.

[18:32:03.302]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[18:32:04.392]     INFO: Test took 1090ms.

[18:32:04.396]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[18:32:05.485]     INFO: Test took 1089ms.

[18:32:05.488]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[18:32:06.578]     INFO: Test took 1090ms.

[18:32:06.581]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[18:32:07.672]     INFO: Test took 1091ms.

[18:32:07.675]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[18:32:08.765]     INFO: Test took 1090ms.

[18:32:08.768]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[18:32:09.859]     INFO: Test took 1091ms.

[18:32:09.862]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[18:32:10.952]     INFO: Test took 1090ms.

[18:32:10.955]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[18:32:12.045]     INFO: Test took 1090ms.

[18:32:12.048]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[18:32:13.138]     INFO: Test took 1090ms.

[18:32:13.141]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[18:32:14.232]     INFO: Test took 1091ms.

[18:32:14.235]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[18:32:15.325]     INFO: Test took 1090ms.

[18:32:15.328]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[18:32:16.417]     INFO: Test took 1089ms.

[18:32:16.421]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[18:32:17.510]     INFO: Test took 1090ms.

[18:32:17.513]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[18:32:18.603]     INFO: Test took 1090ms.

[18:32:18.606]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[18:32:19.697]     INFO: Test took 1091ms.

[18:32:19.700]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[18:32:20.790]     INFO: Test took 1090ms.

[18:32:20.793]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[18:32:21.883]     INFO: Test took 1090ms.

[18:32:21.886]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[18:32:22.976]     INFO: Test took 1090ms.

[18:32:22.979]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[18:32:24.069]     INFO: Test took 1090ms.

[18:32:24.072]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[18:32:25.162]     INFO: Test took 1090ms.

[18:32:25.165]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[18:32:26.255]     INFO: Test took 1090ms.

[18:32:26.258]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[18:32:27.348]     INFO: Test took 1090ms.

[18:32:27.351]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[18:32:28.441]     INFO: Test took 1090ms.

[18:32:28.445]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[18:32:29.534]     INFO: Test took 1090ms.

[18:32:29.538]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[18:32:30.628]     INFO: Test took 1090ms.

[18:32:30.631]     INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.

[18:32:31.720]     INFO: Test took 1089ms.

[18:32:32.306]     INFO: PixTestPhOptimization::doTest() done, duration: 418 seconds

[18:32:32.306]     INFO: PH scale (per ROC):    64  62  64  65  76  68  75  73  66  62  71  77  74  75  64  66

[18:32:32.306]     INFO: PH offset (per ROC):  185 181 192 182 187 189 175 178 188 188 182 172 178 183 190 190

[18:32:32.449]     INFO: ######################################################################

[18:32:32.450]     INFO: PixTestGainPedestal::fullTest() ntrig = 10

[18:32:32.450]     INFO: ######################################################################

[18:32:32.450]    DEBUG: <PixTestGainPedestal.cc/measure:L188>  using FLAGS = 16

[18:32:32.461]     INFO: scanning low vcal = 50

[18:32:36.183]     INFO: Test took 3722ms.

[18:32:36.241]     INFO: scanning low vcal = 100

[18:32:39.979]     INFO: Test took 3738ms.

[18:32:40.037]     INFO: scanning low vcal = 150

[18:32:43.778]     INFO: Test took 3741ms.

[18:32:43.835]     INFO: scanning low vcal = 200

[18:32:47.570]     INFO: Test took 3735ms.

[18:32:47.628]     INFO: scanning low vcal = 250

[18:32:51.370]     INFO: Test took 3742ms.

[18:32:51.430]     INFO: scanning high vcal = 30 (= 210 in low range)

[18:32:55.168]     INFO: Test took 3738ms.

[18:32:55.226]     INFO: scanning high vcal = 50 (= 350 in low range)

[18:32:58.961]     INFO: Test took 3735ms.

[18:32:59.019]     INFO: scanning high vcal = 70 (= 490 in low range)

[18:33:02.760]     INFO: Test took 3741ms.

[18:33:02.818]     INFO: scanning high vcal = 90 (= 630 in low range)

[18:33:06.559]     INFO: Test took 3741ms.

[18:33:06.616]     INFO: scanning high vcal = 200 (= 1400 in low range)

[18:33:10.353]     INFO: Test took 3737ms.

[18:33:10.677]     INFO: PixTestGainPedestal::measure() done 

[18:33:10.678]    DEBUG: <PixTestGainPedestal.cc/fit:L377> Create hist gainPedestalP1_C0

[18:33:10.678]    DEBUG: <PixTestGainPedestal.cc/fit:L377> Create hist gainPedestalP1_C1

[18:33:10.678]    DEBUG: <PixTestGainPedestal.cc/fit:L377> Create hist gainPedestalP1_C2

[18:33:10.679]    DEBUG: <PixTestGainPedestal.cc/fit:L377> Create hist gainPedestalP1_C3

[18:33:10.679]    DEBUG: <PixTestGainPedestal.cc/fit:L377> Create hist gainPedestalP1_C4

[18:33:10.679]    DEBUG: <PixTestGainPedestal.cc/fit:L377> Create hist gainPedestalP1_C5

[18:33:10.679]    DEBUG: <PixTestGainPedestal.cc/fit:L377> Create hist gainPedestalP1_C6

[18:33:10.679]    DEBUG: <PixTestGainPedestal.cc/fit:L377> Create hist gainPedestalP1_C7

[18:33:10.679]    DEBUG: <PixTestGainPedestal.cc/fit:L377> Create hist gainPedestalP1_C8

[18:33:10.679]    DEBUG: <PixTestGainPedestal.cc/fit:L377> Create hist gainPedestalP1_C9

[18:33:10.680]    DEBUG: <PixTestGainPedestal.cc/fit:L377> Create hist gainPedestalP1_C10

[18:33:10.680]    DEBUG: <PixTestGainPedestal.cc/fit:L377> Create hist gainPedestalP1_C11

[18:33:10.680]    DEBUG: <PixTestGainPedestal.cc/fit:L377> Create hist gainPedestalP1_C12

[18:33:10.680]    DEBUG: <PixTestGainPedestal.cc/fit:L377> Create hist gainPedestalP1_C13

[18:33:10.680]    DEBUG: <PixTestGainPedestal.cc/fit:L377> Create hist gainPedestalP1_C14

[18:33:10.680]    DEBUG: <PixTestGainPedestal.cc/fit:L377> Create hist gainPedestalP1_C15

[18:33:32.707]     INFO: PixTestGainPedestal::fit() done

[18:33:32.707]     INFO: non-linearity mean:  0.956 0.956 0.966 0.959 0.958 0.962 0.962 0.956 0.955 0.957 0.958 0.961 0.951 0.965 0.951 0.950

[18:33:32.707]     INFO: non-linearity RMS:   0.008 0.007 0.006 0.007 0.008 0.007 0.006 0.007 0.007 0.007 0.006 0.005 0.007 0.006 0.008 0.009

[18:33:32.707]     INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//phCalibrationFitErr35_C0.dat

[18:33:32.724]     INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//phCalibrationFitErr35_C1.dat

[18:33:32.740]     INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//phCalibrationFitErr35_C2.dat

[18:33:32.756]     INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//phCalibrationFitErr35_C3.dat

[18:33:32.772]     INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//phCalibrationFitErr35_C4.dat

[18:33:32.789]     INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//phCalibrationFitErr35_C5.dat

[18:33:32.805]     INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//phCalibrationFitErr35_C6.dat

[18:33:32.821]     INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//phCalibrationFitErr35_C7.dat

[18:33:32.838]     INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//phCalibrationFitErr35_C8.dat

[18:33:32.854]     INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//phCalibrationFitErr35_C9.dat

[18:33:32.870]     INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//phCalibrationFitErr35_C10.dat

[18:33:32.887]     INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//phCalibrationFitErr35_C11.dat

[18:33:32.903]     INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//phCalibrationFitErr35_C12.dat

[18:33:32.919]     INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//phCalibrationFitErr35_C13.dat

[18:33:32.936]     INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//phCalibrationFitErr35_C14.dat

[18:33:32.952]     INFO: write gain/ped parameters into /home/pixel_dev/elcomandante/trunk/DATA/ThermalCycling/M3017_FullQualification_2015-06-26_09h57m_1435305433//007_Fulltest_p17//phCalibrationFitErr35_C15.dat

[18:33:32.968]     INFO: PixTestGainPedestal::doTest() done, duration: 60 seconds

[18:33:32.968]    DEBUG: <PixTestGainPedestal.cc/~PixTestGainPedestal:L121> PixTestGainPedestal dtor

[18:33:32.974]    DEBUG: <PixTestFullTest.cc/~PixTestFullTest:L78> PixTestFullTest dtor

[18:33:32.974]     INFO: enter test to run

[18:33:32.974]     INFO:   test: q no parameter change

[18:33:32.974]    DEBUG: <PixMonitor.cc/dumpSummaries:L34> PixMonitor::dumpSummaries

[18:33:33.086]    QUIET: Connection to board 105 closed.

[18:33:33.087]     INFO: pXar: this is the end, my friend

[18:33:33.088]    DEBUG: <PixSetup.cc/~PixSetup:L68> PixSetup free fPxarMemory
MoReWeb-v0.6.7-17-g62372b6 on branch psi46master