[10:17:47.767] INFO: *** Welcome to pxar ***
[10:17:47.767] INFO: *** Today: 2016/06/16
[10:17:47.790] INFO: *** Version: v1.9.0-814-g7497
[10:17:47.791] INFO: readRocDacs: data/mp202/dacParameters35_C0.dat .. data/mp202/dacParameters35_C15.dat
[10:17:47.792] INFO: readTbmDacs: data/mp202/tbmParameters_C0a.dat .. data/mp202/tbmParameters_C0b.dat
[10:17:47.792] INFO: readMaskFile: data/mp202/defaultMaskFile.dat
[10:17:47.792] INFO: MASKED Roc 14 col/row: 3 19
[10:17:47.792] INFO: MASKED Roc 14 col/row: 3 20
[10:17:47.792] INFO: MASKED Roc 14 col/row: 3 35
[10:17:47.792] INFO: MASKED Roc 14 col/row: 3 40
[10:17:47.792] INFO: MASKED Roc 14 col/row: 3 46
[10:17:47.792] INFO: MASKED Roc 14 col/row: 3 52
[10:17:47.792] INFO: MASKED Roc 14 col/row: 3 54
[10:17:47.792] INFO: MASKED Roc 14 col/row: 3 55
[10:17:47.792] INFO: MASKED Roc 14 col/row: 3 66
[10:17:47.792] INFO: MASKED Roc 14 col/row: 3 68
[10:17:47.792] INFO: MASKED Roc 14 col/row: 3 70
[10:17:47.792] INFO: readTrimFile: data/mp202/trimParameters35_C0.dat .. data/mp202/trimParameters35_C15.dat
[10:17:47.924] INFO: masking Roc 14 col/row: 3 19
[10:17:47.924] INFO: masking Roc 14 col/row: 3 20
[10:17:47.924] INFO: masking Roc 14 col/row: 3 35
[10:17:47.924] INFO: masking Roc 14 col/row: 3 40
[10:17:47.924] INFO: masking Roc 14 col/row: 3 46
[10:17:47.924] INFO: masking Roc 14 col/row: 3 52
[10:17:47.924] INFO: masking Roc 14 col/row: 3 54
[10:17:47.924] INFO: masking Roc 14 col/row: 3 55
[10:17:47.924] INFO: masking Roc 14 col/row: 3 66
[10:17:47.924] INFO: masking Roc 14 col/row: 3 68
[10:17:47.925] INFO: masking Roc 14 col/row: 3 70
[10:17:47.944] INFO: clk: 4
[10:17:47.944] INFO: ctr: 4
[10:17:47.944] INFO: sda: 19
[10:17:47.944] INFO: tin: 9
[10:17:47.944] INFO: level: 15
[10:17:47.944] INFO: triggerdelay: 0
[10:17:47.944] QUIET: Instanciating API for pxar v1.9.0+803~gf2ecfa7
[10:17:47.944] INFO: Log level: DEBUG
[10:17:47.955] QUIET: Connection to board DTB_WRMNMR opened.
[10:17:47.958] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 43
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WRMNMR
MAC address: 40D85511802B
Hostname: pixelDTB043
Comment: sent to Frank Meier (UNL)
------------------------------------------------------
[10:17:47.961] INFO: RPC call hashes of host and DTB match: 398089610
[10:17:49.564] INFO: DUT info:
[10:17:49.564] INFO: The DUT currently contains the following objects:
[10:17:49.564] INFO: 2 TBM Cores tbm08c (2 ON)
[10:17:49.564] INFO: TBM Core alpha (0): 7 registers set
[10:17:49.564] INFO: TBM Core beta (1): 7 registers set
[10:17:49.564] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[10:17:49.564] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[10:17:49.564] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[10:17:49.564] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[10:17:49.564] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[10:17:49.565] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[10:17:49.565] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[10:17:49.565] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[10:17:49.565] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[10:17:49.565] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[10:17:49.565] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[10:17:49.565] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[10:17:49.565] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[10:17:49.565] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[10:17:49.565] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[10:17:49.565] INFO: ROC 14: 19 DACs set, Pixels: 11 masked, 0 active.
[10:17:49.565] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[10:17:49.565] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->BB<-
[10:17:49.565] DEBUG: <PixTestParameters.cc/dump:L107> dumpall: checkbox(0)
[10:17:49.565] DEBUG: <PixTestParameters.cc/dump:L107> dumpproblematic: checkbox(0)
[10:17:49.565] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 5
[10:17:49.565] DEBUG: <PixTestParameters.cc/dump:L107> vcals: 250
[10:17:49.565] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->BB2<-
[10:17:49.565] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[10:17:49.565] DEBUG: <PixTestParameters.cc/dump:L107> vcals: 222
[10:17:49.565] DEBUG: <PixTestParameters.cc/dump:L107> plwidth: 35
[10:17:49.565] DEBUG: <PixTestParameters.cc/dump:L107> pix: 11,20
[10:17:49.565] DEBUG: <PixTestParameters.cc/dump:L107> targetia: 24
[10:17:49.565] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->BB3<-
[10:17:49.565] DEBUG: <PixTestParameters.cc/dump:L107> dumpall: checkbox(0)
[10:17:49.565] DEBUG: <PixTestParameters.cc/dump:L107> dumpproblematic: checkbox(0)
[10:17:49.566] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 5
[10:17:49.566] DEBUG: <PixTestParameters.cc/dump:L107> vcals: 250
[10:17:49.566] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->BB4<-
[10:17:49.566] DEBUG: <PixTestParameters.cc/dump:L107> savecaldelscan: checkbox(0)
[10:17:49.566] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 100
[10:17:49.566] DEBUG: <PixTestParameters.cc/dump:L107> cals: 1
[10:17:49.566] DEBUG: <PixTestParameters.cc/dump:L107> caldello: 80
[10:17:49.566] DEBUG: <PixTestParameters.cc/dump:L107> caldelhi: 200
[10:17:49.566] DEBUG: <PixTestParameters.cc/dump:L107> caldelstep: 10
[10:17:49.566] DEBUG: <PixTestParameters.cc/dump:L107> vthrcomplo: 70
[10:17:49.566] DEBUG: <PixTestParameters.cc/dump:L107> vthrcomphi: 130
[10:17:49.566] DEBUG: <PixTestParameters.cc/dump:L107> vthrcompstep: 5
[10:17:49.566] DEBUG: <PixTestParameters.cc/dump:L107> noisypixels: 10
[10:17:49.566] DEBUG: <PixTestParameters.cc/dump:L107> vcal: 255
[10:17:49.566] DEBUG: <PixTestParameters.cc/dump:L107> cut: 0.5
[10:17:49.566] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Cmd<-
[10:17:49.566] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->DAQ<-
[10:17:49.566] DEBUG: <PixTestParameters.cc/dump:L107> delaytbm: checkbox
[10:17:49.566] DEBUG: <PixTestParameters.cc/dump:L107> filltree: checkbox
[10:17:49.566] DEBUG: <PixTestParameters.cc/dump:L107> trgfrequency(khz): 100
[10:17:49.566] DEBUG: <PixTestParameters.cc/dump:L107> maskhotpixels: button
[10:17:49.566] DEBUG: <PixTestParameters.cc/dump:L107> trgnumber: 5
[10:17:49.566] DEBUG: <PixTestParameters.cc/dump:L107> iterations: 10
[10:17:49.566] DEBUG: <PixTestParameters.cc/dump:L107> rundaqtrg: button
[10:17:49.566] DEBUG: <PixTestParameters.cc/dump:L107> daqseconds: 5
[10:17:49.566] DEBUG: <PixTestParameters.cc/dump:L107> rundaqseconds: button
[10:17:49.566] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->DacDacScan<-
[10:17:49.566] DEBUG: <PixTestParameters.cc/dump:L107> phmap: checkbox
[10:17:49.566] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[10:17:49.566] DEBUG: <PixTestParameters.cc/dump:L107> dac1: caldel
[10:17:49.566] DEBUG: <PixTestParameters.cc/dump:L107> dac1lo: 0
[10:17:49.566] DEBUG: <PixTestParameters.cc/dump:L107> dac1hi: 255
[10:17:49.566] DEBUG: <PixTestParameters.cc/dump:L107> dac2: vthrcomp
[10:17:49.566] DEBUG: <PixTestParameters.cc/dump:L107> dac2lo: 0
[10:17:49.566] DEBUG: <PixTestParameters.cc/dump:L107> dac2hi: 255
[10:17:49.566] DEBUG: <PixTestParameters.cc/dump:L107> pix: 11,20
[10:17:49.566] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->DacScan<-
[10:17:49.566] DEBUG: <PixTestParameters.cc/dump:L107> phmap: checkbox(1)
[10:17:49.566] DEBUG: <PixTestParameters.cc/dump:L107> allpixels: checkbox(0)
[10:17:49.566] DEBUG: <PixTestParameters.cc/dump:L107> unmasked: checkbox(0)
[10:17:49.566] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[10:17:49.566] DEBUG: <PixTestParameters.cc/dump:L107> dac: vcal
[10:17:49.566] DEBUG: <PixTestParameters.cc/dump:L107> daclo: 0
[10:17:49.566] DEBUG: <PixTestParameters.cc/dump:L107> dachi: 255
[10:17:49.566] DEBUG: <PixTestParameters.cc/dump:L107> pix: 11,20
[10:17:49.566] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->GainPedestal<-
[10:17:49.566] DEBUG: <PixTestParameters.cc/dump:L107> showfits: checkbox(0)
[10:17:49.566] DEBUG: <PixTestParameters.cc/dump:L107> extended: checkbox(0)
[10:17:49.566] DEBUG: <PixTestParameters.cc/dump:L107> dumphists: checkbox(0)
[10:17:49.566] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[10:17:49.566] DEBUG: <PixTestParameters.cc/dump:L107> vcalstep: 10
[10:17:49.566] DEBUG: <PixTestParameters.cc/dump:L107> measure: button
[10:17:49.566] DEBUG: <PixTestParameters.cc/dump:L107> fit: button
[10:17:49.566] DEBUG: <PixTestParameters.cc/dump:L107> save: button
[10:17:49.566] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->HighRate<-
[10:17:49.566] DEBUG: <PixTestParameters.cc/dump:L107> pix: 11,20
[10:17:49.566] DEBUG: <PixTestParameters.cc/dump:L107> trimhotpixels: button
[10:17:49.566] DEBUG: <PixTestParameters.cc/dump:L107> trimhotpixelthr: 200
[10:17:49.567] DEBUG: <PixTestParameters.cc/dump:L107> runsecondshotpixels: 10
[10:17:49.567] DEBUG: <PixTestParameters.cc/dump:L107> savetrimbits: checkbox(1)
[10:17:49.567] DEBUG: <PixTestParameters.cc/dump:L107> maskuntrimmable: checkbox(1)
[10:17:49.567] DEBUG: <PixTestParameters.cc/dump:L107> maskhotpixels: button
[10:17:49.567] DEBUG: <PixTestParameters.cc/dump:L107> savemaskfile: checkbox(0)
[10:17:49.567] DEBUG: <PixTestParameters.cc/dump:L107> maskfilename: default
[10:17:49.567] DEBUG: <PixTestParameters.cc/dump:L107> caldelscan: button
[10:17:49.567] DEBUG: <PixTestParameters.cc/dump:L107> xpixelalive: button
[10:17:49.567] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 50
[10:17:49.567] DEBUG: <PixTestParameters.cc/dump:L107> vcal: 200
[10:17:49.567] DEBUG: <PixTestParameters.cc/dump:L107> xnoisemaps: button
[10:17:49.567] DEBUG: <PixTestParameters.cc/dump:L107> daclo: 0
[10:17:49.567] DEBUG: <PixTestParameters.cc/dump:L107> dachi: 100
[10:17:49.567] DEBUG: <PixTestParameters.cc/dump:L107> dacs/step: 20
[10:17:49.567] DEBUG: <PixTestParameters.cc/dump:L107> rundaq: button
[10:17:49.567] DEBUG: <PixTestParameters.cc/dump:L107> trgfrequency(khz): 20
[10:17:49.567] DEBUG: <PixTestParameters.cc/dump:L107> runseconds: 2
[10:17:49.567] DEBUG: <PixTestParameters.cc/dump:L107> triggerdelay: 20
[10:17:49.567] DEBUG: <PixTestParameters.cc/dump:L107> delaytbm: checkbox
[10:17:49.567] DEBUG: <PixTestParameters.cc/dump:L107> filltree: checkbox
[10:17:49.567] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->IV<-
[10:17:49.567] DEBUG: <PixTestParameters.cc/dump:L107> port: /dev/FIXME
[10:17:49.567] DEBUG: <PixTestParameters.cc/dump:L107> voltagestart: 0
[10:17:49.567] DEBUG: <PixTestParameters.cc/dump:L107> voltagestop: 600
[10:17:49.567] DEBUG: <PixTestParameters.cc/dump:L107> voltagestep: 5
[10:17:49.567] DEBUG: <PixTestParameters.cc/dump:L107> delay: 1
[10:17:49.567] DEBUG: <PixTestParameters.cc/dump:L107> compliance(ua): 100
[10:17:49.567] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->PhOptimization<-
[10:17:49.567] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[10:17:49.567] DEBUG: <PixTestParameters.cc/dump:L107> safetymarginlow: 20
[10:17:49.567] DEBUG: <PixTestParameters.cc/dump:L107> saturationvcal: 100
[10:17:49.567] DEBUG: <PixTestParameters.cc/dump:L107> quantilesaturation: 0.98
[10:17:49.567] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->PixelAlive<-
[10:17:49.567] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[10:17:49.567] DEBUG: <PixTestParameters.cc/dump:L107> vcal: 200
[10:17:49.567] DEBUG: <PixTestParameters.cc/dump:L107> alivetest: button
[10:17:49.567] DEBUG: <PixTestParameters.cc/dump:L107> masktest: button
[10:17:49.567] DEBUG: <PixTestParameters.cc/dump:L107> addressdecodingtest: button
[10:17:49.567] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Pretest<-
[10:17:49.567] DEBUG: <PixTestParameters.cc/dump:L107> programroc: button
[10:17:49.567] DEBUG: <PixTestParameters.cc/dump:L107> targetia: 24
[10:17:49.567] DEBUG: <PixTestParameters.cc/dump:L107> setvana: button
[10:17:49.567] DEBUG: <PixTestParameters.cc/dump:L107> iterations: 100
[10:17:49.567] DEBUG: <PixTestParameters.cc/dump:L107> settimings: button
[10:17:49.567] DEBUG: <PixTestParameters.cc/dump:L107> findtiming: button
[10:17:49.567] DEBUG: <PixTestParameters.cc/dump:L107> findworkingpixel: button
[10:17:49.567] DEBUG: <PixTestParameters.cc/dump:L107> setvthrcompcaldel: button
[10:17:49.567] DEBUG: <PixTestParameters.cc/dump:L107> pix: 11,20
[10:17:49.567] DEBUG: <PixTestParameters.cc/dump:L107> vcal: 250
[10:17:49.567] DEBUG: <PixTestParameters.cc/dump:L107> deltavthrcomp: 50
[10:17:49.567] DEBUG: <PixTestParameters.cc/dump:L107> fraccaldel: 0.5
[10:17:49.567] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 5
[10:17:49.567] DEBUG: <PixTestParameters.cc/dump:L107> savedacs: button
[10:17:49.567] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Readback<-
[10:17:49.567] DEBUG: <PixTestParameters.cc/dump:L107> calibratevd: button
[10:17:49.567] DEBUG: <PixTestParameters.cc/dump:L107> calibrateva: button
[10:17:49.567] DEBUG: <PixTestParameters.cc/dump:L107> calibrateia: button
[10:17:49.567] DEBUG: <PixTestParameters.cc/dump:L107> readbackvbg: button
[10:17:49.568] DEBUG: <PixTestParameters.cc/dump:L107> getcalibratedvbg: button
[10:17:49.568] DEBUG: <PixTestParameters.cc/dump:L107> usecalvd: checkbox(1)
[10:17:49.568] DEBUG: <PixTestParameters.cc/dump:L107> usecalva: checkbox(0)
[10:17:49.568] DEBUG: <PixTestParameters.cc/dump:L107> setvana: button
[10:17:49.568] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Scurves<-
[10:17:49.568] DEBUG: <PixTestParameters.cc/dump:L107> adjustvcal: checkbox(0)
[10:17:49.568] DEBUG: <PixTestParameters.cc/dump:L107> dumpall: checkbox(0)
[10:17:49.568] DEBUG: <PixTestParameters.cc/dump:L107> dumpproblematic: checkbox(0)
[10:17:49.568] DEBUG: <PixTestParameters.cc/dump:L107> dumpoutputfile: checkbox(0)
[10:17:49.568] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 50
[10:17:49.568] DEBUG: <PixTestParameters.cc/dump:L107> dac: Vcal
[10:17:49.568] DEBUG: <PixTestParameters.cc/dump:L107> daclo: 0
[10:17:49.568] DEBUG: <PixTestParameters.cc/dump:L107> dachi: 200
[10:17:49.568] DEBUG: <PixTestParameters.cc/dump:L107> dacs/step: -1
[10:17:49.568] DEBUG: <PixTestParameters.cc/dump:L107> ntrig/step: -1
[10:17:49.568] DEBUG: <PixTestParameters.cc/dump:L107> scurves: button
[10:17:49.568] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Timing<-
[10:17:49.568] DEBUG: <PixTestParameters.cc/dump:L107> targetclk: 4
[10:17:49.568] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[10:17:49.568] DEBUG: <PixTestParameters.cc/dump:L107> clocksdascan: button
[10:17:49.568] DEBUG: <PixTestParameters.cc/dump:L107> notokenpass: checkbox(0)
[10:17:49.568] DEBUG: <PixTestParameters.cc/dump:L107> phasescan: button
[10:17:49.568] DEBUG: <PixTestParameters.cc/dump:L107> levelscan: button
[10:17:49.568] DEBUG: <PixTestParameters.cc/dump:L107> tbmphasescan: button
[10:17:49.568] DEBUG: <PixTestParameters.cc/dump:L107> rocdelayscan: button
[10:17:49.568] DEBUG: <PixTestParameters.cc/dump:L107> timingtest: button
[10:17:49.568] DEBUG: <PixTestParameters.cc/dump:L107> saveparameters: button
[10:17:49.568] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Trim<-
[10:17:49.568] DEBUG: <PixTestParameters.cc/dump:L107> trim: button
[10:17:49.568] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 8
[10:17:49.568] DEBUG: <PixTestParameters.cc/dump:L107> vcal: 35
[10:17:49.568] DEBUG: <PixTestParameters.cc/dump:L107> trimbits: button
[10:17:49.568] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Xray<-
[10:17:49.568] DEBUG: <PixTestParameters.cc/dump:L107> maskhotpixels: button
[10:17:49.568] DEBUG: <PixTestParameters.cc/dump:L107> savemaskfile: checkbox(0)
[10:17:49.568] DEBUG: <PixTestParameters.cc/dump:L107> maskfilename: default
[10:17:49.568] DEBUG: <PixTestParameters.cc/dump:L107> source: Ag
[10:17:49.568] DEBUG: <PixTestParameters.cc/dump:L107> phrun: button
[10:17:49.568] DEBUG: <PixTestParameters.cc/dump:L107> runseconds: 100
[10:17:49.568] DEBUG: <PixTestParameters.cc/dump:L107> trgfrequency(khz): 100
[10:17:49.568] DEBUG: <PixTestParameters.cc/dump:L107> ratescan: button
[10:17:49.568] DEBUG: <PixTestParameters.cc/dump:L107> vthrcompmin: 10
[10:17:49.568] DEBUG: <PixTestParameters.cc/dump:L107> vthrcompmax: 80
[10:17:49.568] DEBUG: <PixTestParameters.cc/dump:L107> stepseconds: 5
[10:17:49.568] DEBUG: <PixTestParameters.cc/dump:L107> delaytbm: checkbox
[10:17:49.568] DEBUG: <PixTestParameters.cc/dump:L107> filltree: checkbox
[10:17:49.570] DEBUG: <PixSetup.cc/init:L81> PixSetup init start; getCurrentRSS() = 32763904
[10:17:49.570] DEBUG: <PixSetup.cc/init:L87> fPixTestParameters = 0x164ce60
[10:17:49.571] DEBUG: <PixSetup.cc/init:L88> fConfigParameters = 0x15dae60
[10:17:49.571] DEBUG: <PixSetup.cc/init:L89> fPxarMemory = 0x7f7a39d94010
[10:17:49.571] DEBUG: <PixSetup.cc/init:L90> fPxarMemHi = 0x7f7a3ffff510
[10:17:49.571] DEBUG: <PixSetup.cc/init:L106> PixSetup init done; getCurrentRSS() = 32772096 fPxarMemory = 0x7f7a39d94010
[10:17:49.572] DEBUG: <pXar.cc/main:L223> Initial Analog Current: 379.4mA
[10:17:49.573] DEBUG: <pXar.cc/main:L224> Initial Digital Current: 461.4mA
[10:17:49.573] DEBUG: <pXar.cc/main:L225> Initial Module Temperature: -0.4 C
[10:17:50.074] DEBUG: <PixGui.cc/hvOn:L460> HV set On: 0x1c23930
[10:17:50.134] DEBUG: <PixTestFactory.cc/PixTestFactory:L53> PixTestFactory::PixTestFactory()
[10:17:50.135] DEBUG: <PixTestBBMap.cc/init:L79> PixTestBBMap::init()
[10:17:50.135] DEBUG: <PixTestBBMap.cc/PixTestBBMap:L27> PixTestBBMap ctor(PixSetup &a, string, TGTab *)
[10:17:50.140] DEBUG: <PixTestBB2Map.cc/setParameter:L58> setting fTargetIa = 24 mA/ROC
[10:17:50.140] DEBUG: <PixTestBB2Map.cc/init:L97> PixTestBB2Map::init()
[10:17:50.141] DEBUG: <PixTestBB2Map.cc/PixTestBB2Map:L29> PixTestBB2Map ctor(PixSetup &a, string, TGTab *)
[10:17:50.151] DEBUG: <PixTestBB3Map.cc/init:L81> PixTestBB3Map::init()
[10:17:50.151] DEBUG: <PixTestBB3Map.cc/PixTestBB3Map:L29> PixTestBB3Map ctor(PixSetup &a, string, TGTab *)
[10:17:50.163] DEBUG: <PixTestBB4Map.cc/init:L93> PixTestBB4Map::init()
[10:17:50.163] DEBUG: <PixTestBB4Map.cc/PixTestBB4Map:L26> PixTestMapeff ctor(PixSetup &a, string, TGTab *)
[10:17:50.179] INFO: PixTestCmd::init()
[10:17:50.196] DEBUG: <PixTestDaq.cc/init:L44> PixTestDaq::init()
[10:17:50.196] DEBUG: <PixTestDaq.cc/PixTestDaq:L22> PixTestDaq ctor(PixSetup &a, string, TGTab *)
[10:17:50.196] INFO: readGainPedestalParameters data/mp202/phCalibrationFitErr35_C0.dat .. data/mp202/phCalibrationFitErr35_C15.dat
[10:17:50.448] DEBUG: <PixTestDacDacScan.cc/init:L103> PixTestDacDacScan::init()
[10:17:50.449] DEBUG: <PixTestDacDacScan.cc/PixTestDacDacScan:L22> PixTestDacDacScan ctor(PixSetup &a, string, TGTab *)
[10:17:50.463] DEBUG: <PixTestGainPedestal.cc/setParameter:L83> PixTestGainPedestal::PixTest() fVcalStep = 10
[10:17:50.469] DEBUG: <PixTestHighRate.cc/setParameter:L68> setting fParTriggerFrequency -> 20
[10:17:50.469] DEBUG: <PixTestHighRate.cc/init:L211> PixTestHighRate::init()
[10:17:50.469] DEBUG: <PixTestHighRate.cc/PixTestHighRate:L31> PixTestHighRate ctor(PixSetup &a, string, TGTab *)
[10:17:50.493] DEBUG: <PixTest.cc/setTestParameter:L637> setting ntrig to new value 10
[10:17:50.493] DEBUG: <PixTestPhOptimization.cc/setParameter:L37> setting fParNtrig ->10<- from sval = 10
[10:17:50.493] DEBUG: <PixTestPhOptimization.cc/setParameter:L42> setting fSafetyMarginLow ->20<- from sval = 20
[10:17:50.493] DEBUG: <PixTestPhOptimization.cc/setParameter:L48> setting fVcalMax ->100<- from sval = 100
[10:17:50.493] DEBUG: <PixTestPhOptimization.cc/setParameter:L53> setting fQuantMax ->0.98<- from sval = 0.98
[10:17:50.500] DEBUG: <PixTestAlive.cc/init:L83> PixTestAlive::init()
[10:17:50.500] DEBUG: <PixTestAlive.cc/PixTestAlive:L21> PixTestAlive ctor(PixSetup &a, string, TGTab *)
[10:17:50.522] DEBUG: <PixTestReadback.cc/setParameter:L172> fCalwVd set to 1
[10:17:50.522] DEBUG: <PixTestReadback.cc/init:L95> PixTestReadback::init()
[10:17:50.522] DEBUG: <PixTestReadback.cc/PixTestReadback:L22> PixTestReadback ctor(PixSetup &a, string, TGTab *)
[10:17:50.522] INFO: readReadbackCal: data/mp202/readbackCal_C0.dat .. data/mp202/readbackCal_C15.dat
[10:17:50.532] DEBUG: <PixTestScurves.cc/setParameter:L93> set fOutputFilename =
[10:17:50.540] DEBUG: <PixTestTiming.cc/setParameter:L61> PixTestTiming::PixTest() targetclk = 4
[10:17:50.540] DEBUG: <PixTestTiming.cc/setParameter:L65> PixTestTiming::PixTest() ntrig = 10
[10:17:50.540] DEBUG: <PixTestTiming.cc/setParameter:L49> fNoTokenPass: 0
[10:17:50.540] DEBUG: <PixTestTiming.cc/init:L75> PixTestTiming::init()
[10:17:50.560] DEBUG: <PixTestXray.cc/init:L135> PixTestXray::init()
[10:17:50.560] DEBUG: <PixTestXray.cc/PixTestXray:L28> PixTestXray ctor(PixSetup &a, string, TGTab *)
[10:17:54.355] INFO: ######################################################################
[10:17:54.355] INFO: PixTestAlive::doTest()
[10:17:54.355] INFO: ######################################################################
[10:17:54.359] INFO: ----------------------------------------------------------------------
[10:17:54.359] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[10:17:54.359] INFO: ----------------------------------------------------------------------
[10:17:54.361] INFO: ROC 14 masking pixel 3/19
[10:17:54.361] INFO: ROC 14 masking pixel 3/20
[10:17:54.361] INFO: ROC 14 masking pixel 3/35
[10:17:54.361] INFO: ROC 14 masking pixel 3/40
[10:17:54.361] INFO: ROC 14 masking pixel 3/46
[10:17:54.361] INFO: ROC 14 masking pixel 3/52
[10:17:54.361] INFO: ROC 14 masking pixel 3/54
[10:17:54.361] INFO: ROC 14 masking pixel 3/55
[10:17:54.361] INFO: ROC 14 masking pixel 3/66
[10:17:54.361] INFO: ROC 14 masking pixel 3/68
[10:17:54.361] INFO: ROC 14 masking pixel 3/70
[10:17:54.361] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[10:17:54.741] INFO: Expecting 41600 events.
[10:17:58.911] INFO: 41600 events read in total (3452ms).
[10:17:59.059] INFO: Test took 4698ms.
[10:17:59.070] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:17:59.070] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 66545
[10:17:59.070] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists PixelAlive_C0 .. PixelAlive_C15
[10:17:59.349] INFO: PixTestAlive::aliveTest() done
[10:17:59.349] INFO: number of dead pixels (per ROC): 0 0 0 0 1 0 0 0 0 0 0 0 0 0 13 1
[10:17:59.349] DEBUG: <PixTestAlive.cc/aliveTest:L199> number of red-efficiency pixels: 51 26 46 84 90 78 90 64 74 88 64 67 65 40 51 39
[10:17:59.349] INFO: ROC 14 masking pixel 3/19
[10:17:59.349] INFO: ROC 14 masking pixel 3/20
[10:17:59.349] INFO: ROC 14 masking pixel 3/35
[10:17:59.349] INFO: ROC 14 masking pixel 3/40
[10:17:59.349] INFO: ROC 14 masking pixel 3/46
[10:17:59.349] INFO: ROC 14 masking pixel 3/52
[10:17:59.350] INFO: ROC 14 masking pixel 3/54
[10:17:59.350] INFO: ROC 14 masking pixel 3/55
[10:17:59.350] INFO: ROC 14 masking pixel 3/66
[10:17:59.350] INFO: ROC 14 masking pixel 3/68
[10:17:59.350] INFO: ROC 14 masking pixel 3/70
[10:17:59.373] INFO: ----------------------------------------------------------------------
[10:17:59.373] INFO: PixTestAlive::maskTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[10:17:59.373] INFO: ----------------------------------------------------------------------
[10:17:59.375] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[10:17:59.752] INFO: Expecting 41600 events.
[10:18:02.690] INFO: 41600 events read in total (2222ms).
[10:18:02.691] INFO: Test took 3316ms.
[10:18:02.691] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:18:02.691] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 0
[10:18:02.691] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists MaskTest_C0 .. MaskTest_C15
[10:18:02.691] INFO: ROC 14 masking pixel 3/19
[10:18:02.691] INFO: ROC 14 masking pixel 3/20
[10:18:02.691] INFO: ROC 14 masking pixel 3/35
[10:18:02.691] INFO: ROC 14 masking pixel 3/40
[10:18:02.691] INFO: ROC 14 masking pixel 3/46
[10:18:02.691] INFO: ROC 14 masking pixel 3/52
[10:18:02.691] INFO: ROC 14 masking pixel 3/54
[10:18:02.691] INFO: ROC 14 masking pixel 3/55
[10:18:02.691] INFO: ROC 14 masking pixel 3/66
[10:18:02.691] INFO: ROC 14 masking pixel 3/68
[10:18:02.691] INFO: ROC 14 masking pixel 3/70
[10:18:02.691] INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[10:18:03.113] INFO: PixTestAlive::maskTest() done
[10:18:03.113] INFO: number of mask-defect pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[10:18:03.113] INFO: ROC 14 masking pixel 3/19
[10:18:03.113] INFO: ROC 14 masking pixel 3/20
[10:18:03.113] INFO: ROC 14 masking pixel 3/35
[10:18:03.113] INFO: ROC 14 masking pixel 3/40
[10:18:03.114] INFO: ROC 14 masking pixel 3/46
[10:18:03.114] INFO: ROC 14 masking pixel 3/52
[10:18:03.114] INFO: ROC 14 masking pixel 3/54
[10:18:03.114] INFO: ROC 14 masking pixel 3/55
[10:18:03.114] INFO: ROC 14 masking pixel 3/66
[10:18:03.114] INFO: ROC 14 masking pixel 3/68
[10:18:03.114] INFO: ROC 14 masking pixel 3/70
[10:18:03.136] INFO: ----------------------------------------------------------------------
[10:18:03.136] INFO: PixTestAlive::addressDecodingTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[10:18:03.136] INFO: ----------------------------------------------------------------------
[10:18:03.138] INFO: ROC 14 masking pixel 3/19
[10:18:03.138] INFO: ROC 14 masking pixel 3/20
[10:18:03.138] INFO: ROC 14 masking pixel 3/35
[10:18:03.138] INFO: ROC 14 masking pixel 3/40
[10:18:03.138] INFO: ROC 14 masking pixel 3/46
[10:18:03.138] INFO: ROC 14 masking pixel 3/52
[10:18:03.138] INFO: ROC 14 masking pixel 3/54
[10:18:03.138] INFO: ROC 14 masking pixel 3/55
[10:18:03.138] INFO: ROC 14 masking pixel 3/66
[10:18:03.138] INFO: ROC 14 masking pixel 3/68
[10:18:03.138] INFO: ROC 14 masking pixel 3/70
[10:18:03.138] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[10:18:03.515] INFO: Expecting 41600 events.
[10:18:07.715] INFO: 41600 events read in total (3485ms).
[10:18:07.717] INFO: Test took 4579ms.
[10:18:07.728] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:18:07.728] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 66545
[10:18:07.728] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists AddressDecodingTest_C0 .. AddressDecodingTest_C15
[10:18:08.097] INFO: PixTestAlive::addressDecodingTest() done
[10:18:08.098] INFO: number of address-decoding pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[10:18:08.098] INFO: ROC 14 masking pixel 3/19
[10:18:08.098] INFO: ROC 14 masking pixel 3/20
[10:18:08.098] INFO: ROC 14 masking pixel 3/35
[10:18:08.098] INFO: ROC 14 masking pixel 3/40
[10:18:08.098] INFO: ROC 14 masking pixel 3/46
[10:18:08.098] INFO: ROC 14 masking pixel 3/52
[10:18:08.098] INFO: ROC 14 masking pixel 3/54
[10:18:08.098] INFO: ROC 14 masking pixel 3/55
[10:18:08.098] INFO: ROC 14 masking pixel 3/66
[10:18:08.098] INFO: ROC 14 masking pixel 3/68
[10:18:08.098] INFO: ROC 14 masking pixel 3/70
[10:18:08.098] INFO: PixTestAlive::doTest() done, duration: 13 seconds
[10:18:19.080] DEBUG: <PixTab.cc/buttonClicked:L308> xxxPressed(): caldelscan
[10:18:19.080] DEBUG: <PixTestHighRate.cc/runCommand:L165> running command: caldelscan
[10:18:19.080] INFO: ----------------------------------------------------------------------
[10:18:19.080] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[10:18:19.080] INFO: ----------------------------------------------------------------------
[10:18:19.219] INFO: Expecting 768 events.
[10:18:20.346] INFO: 768 events read in total (412ms).
[10:18:20.347] INFO: Test took 1261ms.
[10:18:20.350] INFO: ROC 14 masking pixel 3/19
[10:18:20.350] INFO: ROC 14 masking pixel 3/20
[10:18:20.350] INFO: ROC 14 masking pixel 3/35
[10:18:20.350] INFO: ROC 14 masking pixel 3/40
[10:18:20.350] INFO: ROC 14 masking pixel 3/46
[10:18:20.350] INFO: ROC 14 masking pixel 3/52
[10:18:20.350] INFO: ROC 14 masking pixel 3/54
[10:18:20.350] INFO: ROC 14 masking pixel 3/55
[10:18:20.350] INFO: ROC 14 masking pixel 3/66
[10:18:20.350] INFO: ROC 14 masking pixel 3/68
[10:18:20.350] INFO: ROC 14 masking pixel 3/70
[10:18:20.353] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[10:18:21.150] INFO: Expecting 41600 events.
[10:18:24.854] INFO: 41600 events read in total (3178ms).
[10:18:24.859] INFO: Test took 4506ms.
[10:18:25.013] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:18:25.013] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 876116
[10:18:25.013] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step0_C0 .. HR_xeff_CalDelScan_step0_C15
[10:18:25.014] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[10:18:25.077] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[10:18:25.742] INFO: Expecting 41600 events.
[10:18:29.516] INFO: 41600 events read in total (3247ms).
[10:18:29.521] INFO: Test took 4444ms.
[10:18:29.665] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:18:29.665] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 884690
[10:18:29.665] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step1_C0 .. HR_xeff_CalDelScan_step1_C15
[10:18:29.666] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[10:18:29.734] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[10:18:30.401] INFO: Expecting 41600 events.
[10:18:34.203] INFO: 41600 events read in total (3276ms).
[10:18:34.209] INFO: Test took 4474ms.
[10:18:34.353] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:18:34.353] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 884661
[10:18:34.353] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step2_C0 .. HR_xeff_CalDelScan_step2_C15
[10:18:34.354] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[10:18:34.421] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[10:18:35.088] INFO: Expecting 41600 events.
[10:18:38.905] INFO: 41600 events read in total (3290ms).
[10:18:38.910] INFO: Test took 4488ms.
[10:18:39.058] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:18:39.058] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 885412
[10:18:39.058] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step3_C0 .. HR_xeff_CalDelScan_step3_C15
[10:18:39.059] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[10:18:39.126] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[10:18:39.791] INFO: Expecting 41600 events.
[10:18:43.612] INFO: 41600 events read in total (3295ms).
[10:18:43.618] INFO: Test took 4492ms.
[10:18:43.763] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:18:43.763] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 886042
[10:18:43.763] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step4_C0 .. HR_xeff_CalDelScan_step4_C15
[10:18:43.764] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[10:18:43.831] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[10:18:44.496] INFO: Expecting 41600 events.
[10:18:48.327] INFO: 41600 events read in total (3304ms).
[10:18:48.333] INFO: Test took 4502ms.
[10:18:48.477] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:18:48.477] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 887340
[10:18:48.477] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step5_C0 .. HR_xeff_CalDelScan_step5_C15
[10:18:48.478] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[10:18:48.544] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[10:18:49.209] INFO: Expecting 41600 events.
[10:18:53.040] INFO: 41600 events read in total (3304ms).
[10:18:53.045] INFO: Test took 4501ms.
[10:18:53.189] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:18:53.189] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 888653
[10:18:53.189] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step6_C0 .. HR_xeff_CalDelScan_step6_C15
[10:18:53.189] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[10:18:53.257] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[10:18:53.922] INFO: Expecting 41600 events.
[10:18:57.733] INFO: 41600 events read in total (3285ms).
[10:18:57.738] INFO: Test took 4481ms.
[10:18:57.882] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:18:57.882] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 884707
[10:18:57.882] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step7_C0 .. HR_xeff_CalDelScan_step7_C15
[10:18:57.882] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[10:18:57.949] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[10:18:58.616] INFO: Expecting 41600 events.
[10:19:02.468] INFO: 41600 events read in total (3326ms).
[10:19:02.473] INFO: Test took 4524ms.
[10:19:02.616] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:19:02.616] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 883438
[10:19:02.616] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step8_C0 .. HR_xeff_CalDelScan_step8_C15
[10:19:02.616] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[10:19:02.683] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[10:19:03.348] INFO: Expecting 41600 events.
[10:19:07.198] INFO: 41600 events read in total (3323ms).
[10:19:07.203] INFO: Test took 4521ms.
[10:19:07.348] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:19:07.348] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 885953
[10:19:07.348] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step9_C0 .. HR_xeff_CalDelScan_step9_C15
[10:19:07.348] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[10:19:07.415] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[10:19:08.080] INFO: Expecting 41600 events.
[10:19:11.933] INFO: 41600 events read in total (3326ms).
[10:19:11.938] INFO: Test took 4523ms.
[10:19:12.083] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:19:12.083] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 886926
[10:19:12.083] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step10_C0 .. HR_xeff_CalDelScan_step10_C15
[10:19:12.084] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[10:19:12.151] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[10:19:12.817] INFO: Expecting 41600 events.
[10:19:16.673] INFO: 41600 events read in total (3330ms).
[10:19:16.678] INFO: Test took 4527ms.
[10:19:16.821] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:19:16.821] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 884134
[10:19:16.821] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step11_C0 .. HR_xeff_CalDelScan_step11_C15
[10:19:16.822] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[10:19:16.888] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[10:19:17.553] INFO: Expecting 41600 events.
[10:19:21.406] INFO: 41600 events read in total (3326ms).
[10:19:21.411] INFO: Test took 4522ms.
[10:19:21.555] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:19:21.555] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 883968
[10:19:21.555] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step12_C0 .. HR_xeff_CalDelScan_step12_C15
[10:19:21.555] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[10:19:21.623] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[10:19:22.288] INFO: Expecting 41600 events.
[10:19:26.137] INFO: 41600 events read in total (3323ms).
[10:19:26.142] INFO: Test took 4519ms.
[10:19:26.289] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:19:26.289] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 885783
[10:19:26.289] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step13_C0 .. HR_xeff_CalDelScan_step13_C15
[10:19:26.289] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[10:19:26.356] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[10:19:27.021] INFO: Expecting 41600 events.
[10:19:30.873] INFO: 41600 events read in total (3325ms).
[10:19:30.879] INFO: Test took 4523ms.
[10:19:31.021] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:19:31.021] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 884111
[10:19:31.021] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step14_C0 .. HR_xeff_CalDelScan_step14_C15
[10:19:31.022] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[10:19:31.088] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[10:19:31.753] INFO: Expecting 41600 events.
[10:19:35.601] INFO: 41600 events read in total (3321ms).
[10:19:35.606] INFO: Test took 4517ms.
[10:19:35.749] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:19:35.749] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 883180
[10:19:35.749] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step15_C0 .. HR_xeff_CalDelScan_step15_C15
[10:19:35.749] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[10:19:35.817] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[10:19:36.482] INFO: Expecting 41600 events.
[10:19:40.339] INFO: 41600 events read in total (3331ms).
[10:19:40.344] INFO: Test took 4527ms.
[10:19:40.488] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:19:40.488] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 883765
[10:19:40.488] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step16_C0 .. HR_xeff_CalDelScan_step16_C15
[10:19:40.488] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[10:19:40.555] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[10:19:41.220] INFO: Expecting 41600 events.
[10:19:45.062] INFO: 41600 events read in total (3316ms).
[10:19:45.068] INFO: Test took 4513ms.
[10:19:45.210] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:19:45.210] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 884743
[10:19:45.210] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step17_C0 .. HR_xeff_CalDelScan_step17_C15
[10:19:45.211] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[10:19:45.278] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[10:19:45.943] INFO: Expecting 41600 events.
[10:19:49.749] INFO: 41600 events read in total (3279ms).
[10:19:49.754] INFO: Test took 4476ms.
[10:19:49.898] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:19:49.898] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 882721
[10:19:49.898] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step18_C0 .. HR_xeff_CalDelScan_step18_C15
[10:19:49.898] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[10:19:49.966] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[10:19:50.631] INFO: Expecting 41600 events.
[10:19:54.230] INFO: 41600 events read in total (3072ms).
[10:19:54.235] INFO: Test took 4269ms.
[10:19:54.378] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:19:54.378] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 872083
[10:19:54.378] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step19_C0 .. HR_xeff_CalDelScan_step19_C15
[10:19:54.378] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[10:19:54.667] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 0: caldel = 160 eff = 0.99875
[10:19:54.667] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 1: caldel = 157 eff = 0.999495
[10:19:54.667] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 2: caldel = 153 eff = 0.997716
[10:19:54.667] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 3: caldel = 172 eff = 0.996178
[10:19:54.668] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 4: caldel = 159 eff = 0.995625
[10:19:54.668] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 5: caldel = 198 eff = 0.995913
[10:19:54.668] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 6: caldel = 169 eff = 0.99601
[10:19:54.668] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 7: caldel = 158 eff = 0.996418
[10:19:54.668] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 8: caldel = 155 eff = 0.995962
[10:19:54.668] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 9: caldel = 144 eff = 0.995096
[10:19:54.668] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 10: caldel = 164 eff = 0.995793
[10:19:54.669] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 11: caldel = 174 eff = 0.996707
[10:19:54.669] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 12: caldel = 149 eff = 0.996154
[10:19:54.669] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 13: caldel = 157 eff = 0.998221
[10:19:54.669] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 14: caldel = 143 eff = 0.995817
[10:19:54.669] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 15: caldel = 144 eff = 0.998726
[10:20:04.848] DEBUG: <PixTab.cc/buttonClicked:L308> xxxPressed(): xpixelalive
[10:20:04.848] DEBUG: <PixTestHighRate.cc/runCommand:L165> running command: xpixelalive
[10:20:04.848] INFO: ----------------------------------------------------------------------
[10:20:04.848] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:20:04.848] INFO: ----------------------------------------------------------------------
[10:20:04.849] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: clk: 4
[10:20:04.849] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: ctr: 4
[10:20:04.849] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: sda: 19
[10:20:04.849] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: tin: 9
[10:20:04.849] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: level: 15
[10:20:04.849] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: triggerdelay: 0
[10:20:04.849] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: clk: 4
[10:20:04.849] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: ctr: 4
[10:20:04.849] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: sda: 19
[10:20:04.849] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: tin: 9
[10:20:04.849] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: level: 15
[10:20:04.849] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: triggerdelay: 20
[10:20:04.866] INFO: ROC 14 masking pixel 3/19
[10:20:04.866] INFO: ROC 14 masking pixel 3/20
[10:20:04.866] INFO: ROC 14 masking pixel 3/35
[10:20:04.866] INFO: ROC 14 masking pixel 3/40
[10:20:04.866] INFO: ROC 14 masking pixel 3/46
[10:20:04.866] INFO: ROC 14 masking pixel 3/52
[10:20:04.866] INFO: ROC 14 masking pixel 3/54
[10:20:04.866] INFO: ROC 14 masking pixel 3/55
[10:20:04.866] INFO: ROC 14 masking pixel 3/66
[10:20:04.866] INFO: ROC 14 masking pixel 3/68
[10:20:04.866] INFO: ROC 14 masking pixel 3/70
[10:20:04.866] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[10:20:05.532] INFO: Expecting 208000 events.
[10:20:18.786] ERROR: <datapipe.cc/CheckEventValidity:L491> Channel 1 Number of ROCs (5) != Token Chain Length (8)
[10:20:18.787] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[10:20:18.787] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1b1 80c0 4788 4d 2a48 208 2a4a 6c5 2847 752 20a7 4788 752 2088 4788 752 20a3 4789 752 2089 4789 35d 248f 35b 2668 550 2462 6cc 2a45 752 2088 4788 44d 2865 752 2089 4789 752 208b 4789 64b 2249 752 206f e002 c000
[10:20:18.787] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1ab 8040 4788 e2 2a4e 261 2284 752 24a0 4788 48d 262f 48d 2a43 752 248d 4788 215 2a62 752 248c 4789 208 2829 752 248d 4788 13 2649 60d 2066 752 248d 4789 611 244b 752 248f 4789 354 242c 354 262d 752 248f 4789 762 2467 752 246f e002 c000
[10:20:18.787] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1ac 80b1 4789 49b 226e 752 24a4 4789 15a 242d 752 2489 752 2649 4789 35a 204f 519 206a 681 2049 752 24a4 4788 752 246f 4789 11d 284a 295 286d 752 2485 4789 752 248b 4788 418 2265 752 248c 4788 e0 204b 752 2481 e002 c000
[10:20:18.787] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1ad 80c0 4788 752 20a6 4788 254 2680 353 2a2f 752 206f 4788 4 284a 9a 2040 4dc 2a47 752 20a2 4788 102 242a 218 2047 752 2089 751 2a42 4788 11 2447 11 2044 10 2a45 1c 2a4d 252 2081 752 2085 4788 752 2087 818 2849 4788 752 20ab 4788 495 2a4f 752 2082 e002 c000
[10:20:18.787] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1ae 8000 4788 451 2265 752 20a3 4788 15 246f 752 2081 84d 2645 84d 2a29 4788 4d 2449 4b 266c 481 2a40 752 2087 478a 752 206f 4788 e031 c024
[10:20:18.787] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1af 8040 478a 752 20a1 478a 752 20a5 478a 10a 264f 2da 2449 651 2447 752 208f 4789 752 208d 478a 752 20a2 4788 752 2080 4789 752 208d 4789 6dc 2844 752 2087 e002 c000
[10:20:18.787] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1b0 80b1 4789 451 2644 491 2448 6a1 2265 752 20a0 4789 605 204c 752 208f 4789 441 204f 752 2084 80d 2463 4788 752 20a1 4789 752 2086 4788 29b 2245 695 2081 752 2085 4789 518 2624 752 208e 4789 752 2088 e002 c000
[10:20:22.233] INFO: 208000 events read in total (16174ms).
[10:20:22.254] INFO: Test took 17389ms.
[10:20:23.015] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:20:23.015] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 4108459
[10:20:23.015] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists highRate_C0 .. highRate_C15
[10:20:23.016] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[10:20:23.521] INFO: number of dead pixels (per ROC): 0 0 0 0 1 0 0 0 0 0 0 0 0 0 13 1
[10:20:23.521] INFO: number of red-efficiency pixels: 254 172 442 690 834 745 820 632 767 802 751 640 762 401 195 263
[10:20:23.521] INFO: number of X-ray hits detected: 173047 120238 198245 298060 320933 320524 314445 287645 311766 319628 318953 289208 306781 199763 119953 142725
[10:20:23.521] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:20:23.521] INFO: number of Vcal hits detected: 207730 207814 207504 207218 206969 207140 207048 207289 207121 207058 207116 207264 207130 207550 207149 207675
[10:20:23.521] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.8 99.7 99.6 99.6 99.6 99.7 99.6 99.6 99.6 99.7 99.6 99.8 99.9 99.9
[10:20:23.521] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.6 99.5 99.6 99.5 99.7 99.6 99.5 99.6 99.6 99.6 99.8 99.6 99.8
[10:20:23.521] INFO: X-ray hit rate [MHz/cm2]: 50.7 35.2 58.1 87.4 94.1 93.9 92.2 84.3 91.4 93.7 93.5 84.8 89.9 58.6 35.2 41.8
[10:20:23.521] INFO: PixTestHighRate::doXPixelAlive() done
[10:20:23.568] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: clk: 4
[10:20:23.568] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: ctr: 4
[10:20:23.568] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: sda: 19
[10:20:23.568] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: tin: 9
[10:20:23.568] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: level: 15
[10:20:23.569] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: triggerdelay: 0
[10:20:23.569] INFO: PixTest:: pg_setup set to default.
[10:20:27.744] DEBUG: <PixTest.cc/moduleMap:L1029> moduleMap histname: what
[10:20:27.744] DEBUG: <PixTest.cc/moduleMap:L1039> h1->GetName() = highRate_xraymap_C11_V0 -> highRate_xraymap_mod
[10:20:28.992] DEBUG: <PixGui.cc/handleButtons:L396> PixGui::exit called
[10:20:28.993] DEBUG: <PixGui.cc/CloseWindow:L335> Final Analog Current: 382.7mA
[10:20:28.994] DEBUG: <PixGui.cc/CloseWindow:L336> Final Digital Current: 462.3mA
[10:20:28.994] DEBUG: <PixGui.cc/CloseWindow:L337> Final Module Temperature: -0.4 C
[10:20:28.994] DEBUG: <PixTestBBMap.cc/~PixTestBBMap:L97> PixTestBBMap dtor
[10:20:28.994] DEBUG: <PixTestBB2Map.cc/~PixTestBB2Map:L115> PixTestBB2Map dtor
[10:20:28.994] DEBUG: <PixTestBB3Map.cc/~PixTestBB3Map:L99> PixTestBB3Map dtor
[10:20:28.994] DEBUG: <PixTestBB4Map.cc/~PixTestBB4Map:L118> PixTestBB4Map dtor
[10:20:28.994] DEBUG: <PixTestCmd.cc/~PixTestCmd:L78> PixTestCmd dtor
[10:20:28.994] DEBUG: <PixTestDaq.cc/~PixTestDaq:L37> PixTestDaq dtor
[10:20:28.994] DEBUG: <PixTestDacDacScan.cc/~PixTestDacDacScan:L136> PixTestDacDacScan dtor
[10:20:28.994] DEBUG: <PixTestDacScan.cc/~PixTestDacScan:L129> PixTestDacScan dtor
[10:20:28.994] DEBUG: <PixTestGainPedestal.cc/~PixTestGainPedestal:L125> PixTestGainPedestal dtor
[10:20:28.994] DEBUG: <PixTestHighRate.cc/~PixTestHighRate:L258> PixTestHighRate dtor
[10:20:29.088] DEBUG: <PixTestIV.cc/~PixTestIV:L96> PixTestIV dtor
[10:20:29.088] DEBUG: <PixTestAlive.cc/~PixTestAlive:L115> PixTestAlive dtor
[10:20:29.097] DEBUG: <PixTestPretest.cc/~PixTestPretest:L136> PixTestPretest dtor
[10:20:29.098] DEBUG: <PixTestReadback.cc/~PixTestReadback:L89> PixTestReadback dtor, saving tree ...
[10:20:29.098] DEBUG: <PixTestScurves.cc/~PixTestScurves:L142> PixTestScurves dtor
[10:20:29.098] DEBUG: <PixTestTiming.cc/~PixTestTiming:L98> PixTestTiming dtor
[10:20:29.098] DEBUG: <PixTestTrim.cc/~PixTestTrim:L103> PixTestTrim dtor
[10:20:29.098] DEBUG: <PixTestXray.cc/~PixTestXray:L218> PixTestXray dtor
[10:20:29.100] QUIET: Connection to board 43 closed.
[10:20:29.179] DEBUG: <PixMonitor.cc/dumpSummaries:L39> PixMonitor::dumpSummaries