[15:51:30.786] INFO: *** Welcome to pxar ***
[15:51:30.786] INFO: *** Today: 2017/02/02
[15:51:31.503] INFO: *** Version: v1.9.0-825-g6bc29
[15:51:31.503] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-2-27_FPIXTest-17C-FNAL-170201-1320-150V_2017-02-01_13h28m_1485977315/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-2-27_FPIXTest-17C-FNAL-170201-1320-150V_2017-02-01_13h28m_1485977315/000_FPIXTest_p17//dacParameters35_C15.dat
[15:51:31.537] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-2-27_FPIXTest-17C-FNAL-170201-1320-150V_2017-02-01_13h28m_1485977315/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-2-27_FPIXTest-17C-FNAL-170201-1320-150V_2017-02-01_13h28m_1485977315/000_FPIXTest_p17//tbmParameters_C0b.dat
[15:51:31.551] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-2-27_FPIXTest-17C-FNAL-170201-1320-150V_2017-02-01_13h28m_1485977315/000_FPIXTest_p17//defaultMaskFile.dat
[15:51:31.551] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-2-27_FPIXTest-17C-FNAL-170201-1320-150V_2017-02-01_13h28m_1485977315/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-2-27_FPIXTest-17C-FNAL-170201-1320-150V_2017-02-01_13h28m_1485977315/000_FPIXTest_p17//trimParameters35_C15.dat
[15:51:31.666] INFO: clk: 4
[15:51:31.666] INFO: ctr: 4
[15:51:31.666] INFO: sda: 19
[15:51:31.666] INFO: tin: 9
[15:51:31.666] INFO: level: 15
[15:51:31.666] INFO: triggerdelay: 0
[15:51:31.666] QUIET: Instanciating API for pxar v1.9.0+825~g6bc290c
[15:51:31.667] INFO: Log level: DEBUG
[15:51:31.682] QUIET: Connection to board DTB_WREKRL opened.
[15:51:31.685] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 33
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREKRL
MAC address: 40D855118021
Hostname: pixelDTB033
Comment:
------------------------------------------------------
[15:51:31.688] INFO: RPC call hashes of host and DTB match: 398089610
[15:51:33.220] INFO: DUT info:
[15:51:33.220] INFO: The DUT currently contains the following objects:
[15:51:33.220] INFO: 2 TBM Cores tbm08c (2 ON)
[15:51:33.220] INFO: TBM Core alpha (0): 7 registers set
[15:51:33.220] INFO: TBM Core beta (1): 7 registers set
[15:51:33.220] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[15:51:33.220] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[15:51:33.220] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[15:51:33.220] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[15:51:33.220] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[15:51:33.220] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[15:51:33.220] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[15:51:33.220] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[15:51:33.220] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[15:51:33.220] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[15:51:33.220] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[15:51:33.220] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[15:51:33.220] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[15:51:33.220] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[15:51:33.220] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[15:51:33.220] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[15:51:33.220] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[15:51:33.228] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->BB<-
[15:51:33.228] DEBUG: <PixTestParameters.cc/dump:L107> dumpall: checkbox(0)
[15:51:33.228] DEBUG: <PixTestParameters.cc/dump:L107> dumpproblematic: checkbox(0)
[15:51:33.228] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 5
[15:51:33.228] DEBUG: <PixTestParameters.cc/dump:L107> vcals: 250
[15:51:33.228] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->BB2<-
[15:51:33.228] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[15:51:33.228] DEBUG: <PixTestParameters.cc/dump:L107> vcals: 222
[15:51:33.228] DEBUG: <PixTestParameters.cc/dump:L107> plwidth: 35
[15:51:33.228] DEBUG: <PixTestParameters.cc/dump:L107> pix: 11,20
[15:51:33.228] DEBUG: <PixTestParameters.cc/dump:L107> targetia: 24
[15:51:33.228] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->BB3<-
[15:51:33.228] DEBUG: <PixTestParameters.cc/dump:L107> dumpall: checkbox(0)
[15:51:33.228] DEBUG: <PixTestParameters.cc/dump:L107> dumpproblematic: checkbox(0)
[15:51:33.228] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 5
[15:51:33.228] DEBUG: <PixTestParameters.cc/dump:L107> vcals: 250
[15:51:33.228] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->BB4<-
[15:51:33.228] DEBUG: <PixTestParameters.cc/dump:L107> savecaldelscan: checkbox(0)
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 100
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> cals: 1
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> caldello: 80
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> caldelhi: 200
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> caldelstep: 10
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> vthrcomplo: 70
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> vthrcomphi: 130
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> vthrcompstep: 5
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> noisypixels: 10
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> vcal: 255
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> cut: 0.5
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Cmd<-
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->DacDacScan<-
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> phmap: checkbox
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> dac1: caldel
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> dac1lo: 0
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> dac1hi: 255
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> dac2: vthrcomp
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> dac2lo: 0
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> dac2hi: 255
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> pix: 11,20
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->DacScan<-
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> phmap: checkbox(1)
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> allpixels: checkbox(0)
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> unmasked: checkbox(0)
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> dac: vcal
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> daclo: 0
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> dachi: 255
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> pix: 11,20
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->GainPedestal<-
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> showfits: checkbox(0)
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> extended: checkbox(0)
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> dumphists: checkbox(0)
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> vcalstep: 10
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> measure: button
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> fit: button
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> save: button
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->HighRate<-
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> pix: 11,20
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> trimhotpixels: button
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> trimhotpixelthr: 200
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> runsecondshotpixels: 10
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> savetrimbits: checkbox(1)
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> maskuntrimmable: checkbox(1)
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> maskhotpixels: button
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> savemaskfile: checkbox(0)
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> maskfilename: default
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> caldelscan: button
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> xpixelalive: button
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 50
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> vcal: 200
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> xnoisemaps: button
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> daclo: 0
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> dachi: 100
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> dacs/step: 20
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> rundaq: button
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> trgfrequency(khz): 20
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> runseconds: 2
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> triggerdelay: 20
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> delaytbm: checkbox
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> filltree: checkbox
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->IV<-
[15:51:33.229] DEBUG: <PixTestParameters.cc/dump:L107> port: /dev/FIXME
[15:51:33.230] DEBUG: <PixTestParameters.cc/dump:L107> voltagestart: 0
[15:51:33.230] DEBUG: <PixTestParameters.cc/dump:L107> voltagestop: 600
[15:51:33.230] DEBUG: <PixTestParameters.cc/dump:L107> voltagestep: 5
[15:51:33.230] DEBUG: <PixTestParameters.cc/dump:L107> delay: 1
[15:51:33.230] DEBUG: <PixTestParameters.cc/dump:L107> compliance(ua): 100
[15:51:33.230] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->PhOptimization<-
[15:51:33.230] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[15:51:33.230] DEBUG: <PixTestParameters.cc/dump:L107> safetymarginlow: 20
[15:51:33.230] DEBUG: <PixTestParameters.cc/dump:L107> saturationvcal: 100
[15:51:33.230] DEBUG: <PixTestParameters.cc/dump:L107> quantilesaturation: 0.98
[15:51:33.230] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->PixelAlive<-
[15:51:33.230] DEBUG: <PixTestParameters.cc/dump:L107> phmap: checkbox(0)
[15:51:33.230] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[15:51:33.230] DEBUG: <PixTestParameters.cc/dump:L107> vcal: 200
[15:51:33.230] DEBUG: <PixTestParameters.cc/dump:L107> alivetest: button
[15:51:33.230] DEBUG: <PixTestParameters.cc/dump:L107> masktest: button
[15:51:33.230] DEBUG: <PixTestParameters.cc/dump:L107> addressdecodingtest: button
[15:51:33.230] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Pretest<-
[15:51:33.230] DEBUG: <PixTestParameters.cc/dump:L107> programroc: button
[15:51:33.230] DEBUG: <PixTestParameters.cc/dump:L107> checkidig: button
[15:51:33.230] DEBUG: <PixTestParameters.cc/dump:L107> targetia: 24
[15:51:33.230] DEBUG: <PixTestParameters.cc/dump:L107> setvana: button
[15:51:33.230] DEBUG: <PixTestParameters.cc/dump:L107> iterations: 100
[15:51:33.230] DEBUG: <PixTestParameters.cc/dump:L107> settimings: button
[15:51:33.230] DEBUG: <PixTestParameters.cc/dump:L107> findtiming: button
[15:51:33.230] DEBUG: <PixTestParameters.cc/dump:L107> findworkingpixel: button
[15:51:33.230] DEBUG: <PixTestParameters.cc/dump:L107> setvthrcompcaldel: button
[15:51:33.230] DEBUG: <PixTestParameters.cc/dump:L107> pix: 11,20
[15:51:33.230] DEBUG: <PixTestParameters.cc/dump:L107> vcal: 250
[15:51:33.230] DEBUG: <PixTestParameters.cc/dump:L107> deltavthrcomp: 50
[15:51:33.230] DEBUG: <PixTestParameters.cc/dump:L107> fraccaldel: 0.5
[15:51:33.230] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 5
[15:51:33.230] DEBUG: <PixTestParameters.cc/dump:L107> savedacs: button
[15:51:33.230] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Readback<-
[15:51:33.230] DEBUG: <PixTestParameters.cc/dump:L107> calibratevd: button
[15:51:33.230] DEBUG: <PixTestParameters.cc/dump:L107> calibrateva: button
[15:51:33.230] DEBUG: <PixTestParameters.cc/dump:L107> calibrateia: button
[15:51:33.230] DEBUG: <PixTestParameters.cc/dump:L107> readbackvbg: button
[15:51:33.230] DEBUG: <PixTestParameters.cc/dump:L107> getcalibratedvbg: button
[15:51:33.230] DEBUG: <PixTestParameters.cc/dump:L107> usecalvd: checkbox(1)
[15:51:33.230] DEBUG: <PixTestParameters.cc/dump:L107> usecalva: checkbox(0)
[15:51:33.230] DEBUG: <PixTestParameters.cc/dump:L107> setvana: button
[15:51:33.230] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Scurves<-
[15:51:33.230] DEBUG: <PixTestParameters.cc/dump:L107> adjustvcal: checkbox(0)
[15:51:33.230] DEBUG: <PixTestParameters.cc/dump:L107> dumpall: checkbox(0)
[15:51:33.230] DEBUG: <PixTestParameters.cc/dump:L107> dumpproblematic: checkbox(0)
[15:51:33.230] DEBUG: <PixTestParameters.cc/dump:L107> dumpoutputfile: checkbox(0)
[15:51:33.230] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 50
[15:51:33.230] DEBUG: <PixTestParameters.cc/dump:L107> dac: Vcal
[15:51:33.230] DEBUG: <PixTestParameters.cc/dump:L107> daclo: 0
[15:51:33.230] DEBUG: <PixTestParameters.cc/dump:L107> dachi: 200
[15:51:33.230] DEBUG: <PixTestParameters.cc/dump:L107> dacs/step: -1
[15:51:33.230] DEBUG: <PixTestParameters.cc/dump:L107> ntrig/step: -1
[15:51:33.230] DEBUG: <PixTestParameters.cc/dump:L107> scurves: button
[15:51:33.230] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Timing<-
[15:51:33.230] DEBUG: <PixTestParameters.cc/dump:L107> targetclk: 4
[15:51:33.234] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10000
[15:51:33.234] DEBUG: <PixTestParameters.cc/dump:L107> clocksdascan: button
[15:51:33.234] DEBUG: <PixTestParameters.cc/dump:L107> notokenpass: checkbox(0)
[15:51:33.234] DEBUG: <PixTestParameters.cc/dump:L107> ignorereadback: checkbox(0)
[15:51:33.234] DEBUG: <PixTestParameters.cc/dump:L107> phasescan: button
[15:51:33.234] DEBUG: <PixTestParameters.cc/dump:L107> levelscan: button
[15:51:33.234] DEBUG: <PixTestParameters.cc/dump:L107> tbmphasescan: button
[15:51:33.234] DEBUG: <PixTestParameters.cc/dump:L107> rocdelayscan: button
[15:51:33.234] DEBUG: <PixTestParameters.cc/dump:L107> timingtest: button
[15:51:33.234] DEBUG: <PixTestParameters.cc/dump:L107> saveparameters: button
[15:51:33.234] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Trim<-
[15:51:33.234] DEBUG: <PixTestParameters.cc/dump:L107> trim: button
[15:51:33.234] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 8
[15:51:33.234] DEBUG: <PixTestParameters.cc/dump:L107> vcal: 35
[15:51:33.234] DEBUG: <PixTestParameters.cc/dump:L107> trimbits: button
[15:51:33.234] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Xray<-
[15:51:33.234] DEBUG: <PixTestParameters.cc/dump:L107> maskhotpixels: button
[15:51:33.234] DEBUG: <PixTestParameters.cc/dump:L107> savemaskfile: checkbox(0)
[15:51:33.234] DEBUG: <PixTestParameters.cc/dump:L107> maskfilename: default
[15:51:33.234] DEBUG: <PixTestParameters.cc/dump:L107> source: Ag
[15:51:33.234] DEBUG: <PixTestParameters.cc/dump:L107> phrun: button
[15:51:33.234] DEBUG: <PixTestParameters.cc/dump:L107> runseconds: 100
[15:51:33.234] DEBUG: <PixTestParameters.cc/dump:L107> trgfrequency(khz): 100
[15:51:33.234] DEBUG: <PixTestParameters.cc/dump:L107> ratescan: button
[15:51:33.234] DEBUG: <PixTestParameters.cc/dump:L107> vthrcompmin: 10
[15:51:33.234] DEBUG: <PixTestParameters.cc/dump:L107> vthrcompmax: 80
[15:51:33.234] DEBUG: <PixTestParameters.cc/dump:L107> stepseconds: 5
[15:51:33.234] DEBUG: <PixTestParameters.cc/dump:L107> delaytbm: checkbox
[15:51:33.234] DEBUG: <PixTestParameters.cc/dump:L107> filltree: checkbox
[15:51:33.237] DEBUG: <PixSetup.cc/init:L81> PixSetup init start; getCurrentRSS() = 29057024
[15:51:33.237] DEBUG: <PixSetup.cc/init:L87> fPixTestParameters = 0x1daa220
[15:51:33.237] DEBUG: <PixSetup.cc/init:L88> fConfigParameters = 0x1cd0310
[15:51:33.237] DEBUG: <PixSetup.cc/init:L89> fPxarMemory = 0x7f8e31d94010
[15:51:33.237] DEBUG: <PixSetup.cc/init:L90> fPxarMemHi = 0x7f8e37fff510
[15:51:33.237] DEBUG: <PixSetup.cc/init:L106> PixSetup init done; getCurrentRSS() = 29122560 fPxarMemory = 0x7f8e31d94010
[15:51:33.238] DEBUG: <pXar.cc/main:L223> Initial Analog Current: 381.9mA
[15:51:33.239] DEBUG: <pXar.cc/main:L224> Initial Digital Current: 466.3mA
[15:51:33.239] DEBUG: <pXar.cc/main:L225> Initial Module Temperature: 11.4 C
[15:51:33.239] DEBUG: <PixTestFactory.cc/PixTestFactory:L53> PixTestFactory::PixTestFactory()
[15:51:33.640] INFO: enter 'restricted' command line mode
[15:51:33.640] INFO: enter test to run
[15:51:45.534] INFO: test: PixelAlive no parameter change
[15:51:45.534] INFO: running: pixelalive
[15:51:45.534] DEBUG: <PixTestAlive.cc/init:L83> PixTestAlive::init()
[15:51:45.539] DEBUG: <PixTestAlive.cc/PixTestAlive:L21> PixTestAlive ctor(PixSetup &a, string, TGTab *)
[15:51:45.539] DEBUG: <PixTestAlive.cc/runCommand:L62> running command: alivetest
[15:51:45.543] INFO: ----------------------------------------------------------------------
[15:51:45.543] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[15:51:45.543] INFO: ----------------------------------------------------------------------
[15:51:45.545] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[15:51:45.868] INFO: Expecting 41600 events.
[15:51:50.244] INFO: 41600 events read in total (3657ms).
[15:51:50.412] INFO: Test took 4867ms.
[15:51:50.426] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:51:50.426] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 66560
[15:51:50.426] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists PixelAlive_C0 .. PixelAlive_C15
[15:51:50.693] INFO: PixTestAlive::aliveTest() done
[15:51:50.693] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:51:50.693] DEBUG: <PixTestAlive.cc/aliveTest:L199> number of red-efficiency pixels: 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:51:50.694] DEBUG: <PixTestAlive.cc/~PixTestAlive:L115> PixTestAlive dtor
[15:51:50.722] INFO: enter test to run
[15:52:36.294] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[15:52:36.294] DEBUG: <PixTestParameters.cc/setTestParameter:L119> PixTestParameters: ->Xray<-
[15:52:36.294] DEBUG: <PixTestParameters.cc/setTestParameter:L124> setting source to new value DCLowRate
[15:52:36.294] INFO: running: xray
[15:52:36.294] DEBUG: <PixTestXray.cc/init:L135> PixTestXray::init()
[15:52:36.294] DEBUG: <PixTestXray.cc/PixTestXray:L28> PixTestXray ctor(PixSetup &a, string, TGTab *)
[15:52:36.294] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-2-27_FPIXTest-17C-FNAL-170201-1320-150V_2017-02-01_13h28m_1485977315/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-2-27_FPIXTest-17C-FNAL-170201-1320-150V_2017-02-01_13h28m_1485977315/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[15:52:36.532] DEBUG: <PixTestXray.cc/runCommand:L109> running command: phrun
[15:52:36.532] INFO: ----------------------------------------------------------------------
[15:52:36.532] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:52:36.532] INFO: ----------------------------------------------------------------------
[15:52:37.497] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:52:48.975] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[15:52:48.978] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[15:53:14.723] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 1130876 events.
[15:53:18.799] DEBUG: <PixTestXray.cc/processData:L823> # events read: 1130876, pixels seen in all events: 6681036
[15:53:18.887] INFO: Resuming triggers.
[15:53:30.357] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[15:53:30.361] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[15:53:56.166] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 1130029 events.
[15:54:00.340] DEBUG: <PixTestXray.cc/processData:L823> # events read: 1130029, pixels seen in all events: 6691049
[15:54:00.373] INFO: Resuming triggers.
[15:54:11.834] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[15:54:11.838] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[15:54:37.991] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 1129049 events.
[15:54:42.178] DEBUG: <PixTestXray.cc/processData:L823> # events read: 1129049, pixels seen in all events: 6702989
[15:54:42.256] INFO: Resuming triggers.
[15:54:53.713] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[15:54:53.716] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[15:55:20.347] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 1128689 events.
[15:55:24.362] DEBUG: <PixTestXray.cc/processData:L823> # events read: 1128689, pixels seen in all events: 6707358
[15:55:24.487] INFO: Resuming triggers.
[15:55:35.935] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[15:55:35.943] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[15:56:02.363] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 1127772 events.
[15:56:06.420] DEBUG: <PixTestXray.cc/processData:L823> # events read: 1127772, pixels seen in all events: 6717710
[15:56:06.516] INFO: Resuming triggers.
[15:56:17.960] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[15:56:17.963] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[15:56:43.774] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 1127382 events.
[15:56:47.585] DEBUG: <PixTestXray.cc/processData:L823> # events read: 1127382, pixels seen in all events: 6722949
[15:56:47.715] INFO: Resuming triggers.
[15:56:59.158] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[15:56:59.167] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[15:57:24.620] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 1127256 events.
[15:57:28.222] DEBUG: <PixTestXray.cc/processData:L823> # events read: 1127256, pixels seen in all events: 6724611
[15:57:28.308] INFO: Resuming triggers.
[15:57:39.749] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[15:57:39.753] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[15:58:05.527] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 1127173 events.
[15:58:09.162] DEBUG: <PixTestXray.cc/processData:L823> # events read: 1127173, pixels seen in all events: 6725217
[15:58:09.192] INFO: Resuming triggers.
[15:58:17.933] INFO: data taking finished, elapsed time: 100 seconds.
[15:58:18.129] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[15:58:37.885] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 861067 events.
[15:58:40.666] DEBUG: <PixTestXray.cc/processData:L823> # events read: 861067, pixels seen in all events: 5140481
[15:58:40.691] INFO: PixTest:: pg_setup set to default.
[15:58:40.694] INFO: PixTestXray::doPhRun() done
[15:58:40.694] DEBUG: <PixTestXray.cc/~PixTestXray:L218> PixTestXray dtor
[15:58:40.874] INFO: enter test to run
[15:59:15.939] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[15:59:15.939] DEBUG: <PixTestParameters.cc/setTestParameter:L119> PixTestParameters: ->Xray<-
[15:59:15.939] DEBUG: <PixTestParameters.cc/setTestParameter:L124> setting source to new value DCHighRate
[15:59:15.939] INFO: running: xray
[15:59:15.939] DEBUG: <PixTestXray.cc/init:L135> PixTestXray::init()
[15:59:15.939] DEBUG: <PixTestXray.cc/PixTestXray:L28> PixTestXray ctor(PixSetup &a, string, TGTab *)
[15:59:15.940] DEBUG: <PixTestXray.cc/runCommand:L109> running command: phrun
[15:59:15.940] INFO: ----------------------------------------------------------------------
[15:59:15.940] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:59:15.940] INFO: ----------------------------------------------------------------------
[15:59:16.904] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:59:23.639] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[15:59:23.642] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[15:59:47.474] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 663510 events.
[15:59:53.872] DEBUG: <PixTestXray.cc/processData:L823> # events read: 663510, pixels seen in all events: 12290013
[15:59:53.939] INFO: Resuming triggers.
[16:00:00.676] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[16:00:00.679] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[16:00:24.538] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 663662 events.
[16:00:31.162] DEBUG: <PixTestXray.cc/processData:L823> # events read: 663662, pixels seen in all events: 12287751
[16:00:31.231] INFO: Resuming triggers.
[16:00:37.965] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[16:00:37.968] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[16:01:01.785] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 663370 events.
[16:01:08.503] DEBUG: <PixTestXray.cc/processData:L823> # events read: 663370, pixels seen in all events: 12291631
[16:01:08.570] INFO: Resuming triggers.
[16:01:15.300] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[16:01:15.304] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[16:01:39.118] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 663026 events.
[16:01:45.588] DEBUG: <PixTestXray.cc/processData:L823> # events read: 663026, pixels seen in all events: 12296392
[16:01:45.657] INFO: Resuming triggers.
[16:01:52.392] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[16:01:52.395] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[16:02:16.190] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 663438 events.
[16:02:22.888] DEBUG: <PixTestXray.cc/processData:L823> # events read: 663438, pixels seen in all events: 12291306
[16:02:22.955] INFO: Resuming triggers.
[16:02:29.685] INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[16:02:29.688] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[16:02:53.508] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 663025 events.
[16:02:59.867] DEBUG: <PixTestXray.cc/processData:L823> # events read: 663025, pixels seen in all events: 12295346
[16:02:59.935] INFO: Resuming triggers.
[16:03:06.665] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[16:03:06.669] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[16:03:30.514] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 662991 events.
[16:03:37.288] DEBUG: <PixTestXray.cc/processData:L823> # events read: 662991, pixels seen in all events: 12297250
[16:03:37.357] INFO: Resuming triggers.
[16:03:44.089] INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[16:03:44.092] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[16:04:07.883] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 663209 events.
[16:04:14.443] DEBUG: <PixTestXray.cc/processData:L823> # events read: 663209, pixels seen in all events: 12293684
[16:04:14.512] INFO: Resuming triggers.
[16:04:21.245] INFO: run duration 60 seconds, buffer almost full (81%), pausing triggers.
[16:04:21.248] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[16:04:45.374] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 663255 events.
[16:04:52.628] DEBUG: <PixTestXray.cc/processData:L823> # events read: 663255, pixels seen in all events: 12293301
[16:04:52.699] INFO: Resuming triggers.
[16:04:59.433] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[16:04:59.437] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[16:05:22.668] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 663405 events.
[16:05:30.066] DEBUG: <PixTestXray.cc/processData:L823> # events read: 663405, pixels seen in all events: 12291528
[16:05:30.134] INFO: Resuming triggers.
[16:05:36.868] INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[16:05:36.871] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[16:06:00.743] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 663372 events.
[16:06:07.873] DEBUG: <PixTestXray.cc/processData:L823> # events read: 663372, pixels seen in all events: 12291238
[16:06:07.942] INFO: Resuming triggers.
[16:06:14.676] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[16:06:14.679] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[16:06:38.668] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 663369 events.
[16:06:45.004] DEBUG: <PixTestXray.cc/processData:L823> # events read: 663369, pixels seen in all events: 12291105
[16:06:46.075] INFO: Resuming triggers.
[16:06:52.810] INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[16:06:52.814] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[16:07:16.792] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 663482 events.
[16:07:24.097] DEBUG: <PixTestXray.cc/processData:L823> # events read: 663482, pixels seen in all events: 12291041
[16:07:24.163] INFO: Resuming triggers.
[16:07:30.900] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[16:07:30.904] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[16:07:55.379] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 663655 events.
[16:08:02.331] DEBUG: <PixTestXray.cc/processData:L823> # events read: 663655, pixels seen in all events: 12289091
[16:08:02.397] INFO: Resuming triggers.
[16:08:08.497] INFO: data taking finished, elapsed time: 100 seconds.
[16:08:08.693] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[16:08:31.084] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 600888 events.
[16:08:37.524] DEBUG: <PixTestXray.cc/processData:L823> # events read: 600888, pixels seen in all events: 11120640
[16:08:37.583] INFO: PixTest:: pg_setup set to default.
[16:08:37.586] INFO: PixTestXray::doPhRun() done
[16:08:37.586] DEBUG: <PixTestXray.cc/~PixTestXray:L218> PixTestXray dtor
[16:08:37.741] INFO: enter test to run
[16:08:55.127] INFO: test: HighRate no parameter change
[16:08:55.127] INFO: running: highrate
[16:08:55.139] DEBUG: <PixTestHighRate.cc/setParameter:L68> setting fParTriggerFrequency -> 20
[16:08:55.139] DEBUG: <PixTestHighRate.cc/init:L211> PixTestHighRate::init()
[16:08:55.139] DEBUG: <PixTestHighRate.cc/PixTestHighRate:L31> PixTestHighRate ctor(PixSetup &a, string, TGTab *)
[16:08:55.140] DEBUG: <PixTestHighRate.cc/runCommand:L165> running command: caldelscan
[16:08:55.140] INFO: ----------------------------------------------------------------------
[16:08:55.140] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[16:08:55.140] INFO: ----------------------------------------------------------------------
[16:08:55.283] INFO: Expecting 768 events.
[16:08:56.429] INFO: 768 events read in total (422ms).
[16:08:56.429] INFO: Test took 1281ms.
[16:08:56.447] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[16:08:57.232] INFO: Expecting 41600 events.
[16:09:00.321] INFO: 41600 events read in total (2562ms).
[16:09:00.322] INFO: Test took 3875ms.
[16:09:00.354] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:09:00.354] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 291781
[16:09:00.354] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step0_C0 .. HR_xeff_CalDelScan_step0_C15
[16:09:00.355] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[16:09:00.371] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[16:09:01.085] INFO: Expecting 41600 events.
[16:09:04.282] INFO: 41600 events read in total (2670ms).
[16:09:04.283] INFO: Test took 3912ms.
[16:09:04.315] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:09:04.315] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 300004
[16:09:04.315] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step1_C0 .. HR_xeff_CalDelScan_step1_C15
[16:09:04.315] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[16:09:04.333] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[16:09:05.044] INFO: Expecting 41600 events.
[16:09:08.247] INFO: 41600 events read in total (2676ms).
[16:09:08.248] INFO: Test took 3915ms.
[16:09:08.280] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:09:08.280] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 300276
[16:09:08.280] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step2_C0 .. HR_xeff_CalDelScan_step2_C15
[16:09:08.280] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[16:09:08.298] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[16:09:08.001] INFO: Expecting 41600 events.
[16:09:12.233] INFO: 41600 events read in total (2705ms).
[16:09:12.234] INFO: Test took 3936ms.
[16:09:12.267] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:09:12.267] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 301107
[16:09:12.267] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step3_C0 .. HR_xeff_CalDelScan_step3_C15
[16:09:12.267] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[16:09:12.285] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[16:09:12.992] INFO: Expecting 41600 events.
[16:09:16.218] INFO: 41600 events read in total (2699ms).
[16:09:16.219] INFO: Test took 3934ms.
[16:09:16.251] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:09:16.251] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 301571
[16:09:16.251] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step4_C0 .. HR_xeff_CalDelScan_step4_C15
[16:09:16.251] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[16:09:16.269] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[16:09:16.977] INFO: Expecting 41600 events.
[16:09:20.194] INFO: 41600 events read in total (2690ms).
[16:09:20.195] INFO: Test took 3926ms.
[16:09:20.227] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:09:20.227] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 300549
[16:09:20.227] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step5_C0 .. HR_xeff_CalDelScan_step5_C15
[16:09:20.227] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[16:09:20.245] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[16:09:20.955] INFO: Expecting 41600 events.
[16:09:24.188] INFO: 41600 events read in total (2706ms).
[16:09:24.189] INFO: Test took 3944ms.
[16:09:24.222] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:09:24.222] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 300764
[16:09:24.222] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step6_C0 .. HR_xeff_CalDelScan_step6_C15
[16:09:24.222] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[16:09:24.240] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[16:09:24.949] INFO: Expecting 41600 events.
[16:09:28.171] INFO: 41600 events read in total (2696ms).
[16:09:28.172] INFO: Test took 3932ms.
[16:09:28.204] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:09:28.204] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 301733
[16:09:28.204] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step7_C0 .. HR_xeff_CalDelScan_step7_C15
[16:09:28.205] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[16:09:28.223] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[16:09:28.932] INFO: Expecting 41600 events.
[16:09:32.156] INFO: 41600 events read in total (2698ms).
[16:09:32.157] INFO: Test took 3934ms.
[16:09:32.190] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:09:32.190] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 300901
[16:09:32.190] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step8_C0 .. HR_xeff_CalDelScan_step8_C15
[16:09:32.190] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[16:09:32.206] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[16:09:32.918] INFO: Expecting 41600 events.
[16:09:36.139] INFO: 41600 events read in total (2695ms).
[16:09:36.141] INFO: Test took 3935ms.
[16:09:36.173] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:09:36.173] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 301518
[16:09:36.173] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step9_C0 .. HR_xeff_CalDelScan_step9_C15
[16:09:36.173] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[16:09:36.191] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[16:09:36.900] INFO: Expecting 41600 events.
[16:09:40.134] INFO: 41600 events read in total (2707ms).
[16:09:40.135] INFO: Test took 3944ms.
[16:09:40.167] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:09:40.167] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 300973
[16:09:40.167] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step10_C0 .. HR_xeff_CalDelScan_step10_C15
[16:09:40.167] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[16:09:40.184] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[16:09:40.893] INFO: Expecting 41600 events.
[16:09:44.130] INFO: 41600 events read in total (2710ms).
[16:09:44.131] INFO: Test took 3947ms.
[16:09:44.164] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:09:44.164] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 301174
[16:09:44.164] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step11_C0 .. HR_xeff_CalDelScan_step11_C15
[16:09:44.164] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[16:09:44.180] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[16:09:44.891] INFO: Expecting 41600 events.
[16:09:48.116] INFO: 41600 events read in total (2698ms).
[16:09:48.117] INFO: Test took 3937ms.
[16:09:48.148] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:09:48.148] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 300844
[16:09:48.148] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step12_C0 .. HR_xeff_CalDelScan_step12_C15
[16:09:48.149] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[16:09:48.165] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[16:09:48.877] INFO: Expecting 41600 events.
[16:09:52.096] INFO: 41600 events read in total (2693ms).
[16:09:52.097] INFO: Test took 3932ms.
[16:09:52.130] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:09:52.130] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 301356
[16:09:52.130] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step13_C0 .. HR_xeff_CalDelScan_step13_C15
[16:09:52.130] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[16:09:52.147] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[16:09:52.854] INFO: Expecting 41600 events.
[16:09:56.085] INFO: 41600 events read in total (2704ms).
[16:09:56.086] INFO: Test took 3939ms.
[16:09:56.118] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:09:56.118] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 301008
[16:09:56.118] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step14_C0 .. HR_xeff_CalDelScan_step14_C15
[16:09:56.118] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[16:09:56.136] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[16:09:56.847] INFO: Expecting 41600 events.
[16:10:00.040] INFO: 41600 events read in total (2666ms).
[16:10:00.041] INFO: Test took 3905ms.
[16:10:00.073] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:10:00.073] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 299749
[16:10:00.073] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step15_C0 .. HR_xeff_CalDelScan_step15_C15
[16:10:00.073] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[16:10:00.091] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[16:10:00.798] INFO: Expecting 41600 events.
[16:10:04.030] INFO: 41600 events read in total (2705ms).
[16:10:04.031] INFO: Test took 3940ms.
[16:10:04.064] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:10:04.064] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 299613
[16:10:04.064] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step16_C0 .. HR_xeff_CalDelScan_step16_C15
[16:10:04.064] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[16:10:04.080] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[16:10:04.792] INFO: Expecting 41600 events.
[16:10:08.026] INFO: 41600 events read in total (2707ms).
[16:10:08.027] INFO: Test took 3947ms.
[16:10:08.060] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:10:08.060] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 300838
[16:10:08.060] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step17_C0 .. HR_xeff_CalDelScan_step17_C15
[16:10:08.061] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[16:10:08.077] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[16:10:08.787] INFO: Expecting 41600 events.
[16:10:11.006] INFO: 41600 events read in total (2693ms).
[16:10:12.007] INFO: Test took 3930ms.
[16:10:12.039] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:10:12.039] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 300086
[16:10:12.039] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step18_C0 .. HR_xeff_CalDelScan_step18_C15
[16:10:12.040] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[16:10:12.056] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[16:10:12.764] INFO: Expecting 41600 events.
[16:10:15.858] INFO: 41600 events read in total (2568ms).
[16:10:15.859] INFO: Test took 3803ms.
[16:10:15.891] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:10:15.891] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 293975
[16:10:15.891] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step19_C0 .. HR_xeff_CalDelScan_step19_C15
[16:10:15.891] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[16:10:16.232] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 0: caldel = 174 eff = 0.999808
[16:10:16.232] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 1: caldel = 180 eff = 0.999856
[16:10:16.232] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 2: caldel = 150 eff = 0.999712
[16:10:16.233] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 3: caldel = 155 eff = 0.999543
[16:10:16.233] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 4: caldel = 147 eff = 0.999591
[16:10:16.233] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 5: caldel = 149 eff = 0.999471
[16:10:16.233] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 6: caldel = 182 eff = 0.999543
[16:10:16.234] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 7: caldel = 151 eff = 0.999712
[16:10:16.234] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 8: caldel = 152 eff = 0.99976
[16:10:16.234] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 9: caldel = 150 eff = 0.999543
[16:10:16.234] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 10: caldel = 180 eff = 0.999591
[16:10:16.235] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 11: caldel = 152 eff = 0.999639
[16:10:16.235] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 12: caldel = 170 eff = 0.999736
[16:10:16.235] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 13: caldel = 172 eff = 0.999808
[16:10:16.235] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 14: caldel = 139 eff = 0.999928
[16:10:16.236] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 15: caldel = 147 eff = 0.999976
[16:10:16.239] DEBUG: <PixTestHighRate.cc/~PixTestHighRate:L258> PixTestHighRate dtor
[16:10:16.256] INFO: enter test to run
[16:10:33.671] INFO: test: HighRate no parameter change
[16:10:33.671] INFO: running: highrate
[16:10:33.671] DEBUG: <PixTestHighRate.cc/setParameter:L68> setting fParTriggerFrequency -> 20
[16:10:33.671] DEBUG: <PixTestHighRate.cc/init:L211> PixTestHighRate::init()
[16:10:33.671] DEBUG: <PixTestHighRate.cc/PixTestHighRate:L31> PixTestHighRate ctor(PixSetup &a, string, TGTab *)
[16:10:33.672] DEBUG: <PixTestHighRate.cc/runCommand:L165> running command: xpixelalive
[16:10:33.672] INFO: ----------------------------------------------------------------------
[16:10:33.672] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:10:33.672] INFO: ----------------------------------------------------------------------
[16:10:33.672] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: clk: 4
[16:10:33.672] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: ctr: 4
[16:10:33.672] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: sda: 19
[16:10:33.672] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: tin: 9
[16:10:33.672] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: level: 15
[16:10:33.672] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: triggerdelay: 0
[16:10:33.672] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: clk: 4
[16:10:33.673] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: ctr: 4
[16:10:33.673] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: sda: 19
[16:10:33.673] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: tin: 9
[16:10:33.673] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: level: 15
[16:10:33.673] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: triggerdelay: 20
[16:10:33.680] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[16:10:34.287] INFO: Expecting 208000 events.
[16:10:46.080] INFO: 208000 events read in total (11267ms).
[16:10:46.083] INFO: Test took 12403ms.
[16:10:46.218] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:10:46.218] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 1232728
[16:10:46.218] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists highRate_C0 .. highRate_C15
[16:10:46.218] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[16:10:46.465] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[16:10:46.465] INFO: number of red-efficiency pixels: 64 53 79 114 131 146 122 73 96 116 102 111 112 56 18 26
[16:10:46.465] INFO: number of X-ray hits detected: 58180 40007 61783 95886 99465 105928 106702 70522 71997 97176 94216 80874 84824 53295 20885 24428
[16:10:46.465] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[16:10:46.465] INFO: number of Vcal hits detected: 207934 207946 207918 207885 207866 207854 207873 207925 207903 207879 207898 207885 207879 207942 207982 207974
[16:10:46.465] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 100.0 100.0 99.9 100.0 100.0 100.0
[16:10:46.465] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 100.0 99.9 99.9 100.0 100.0 100.0
[16:10:46.465] INFO: X-ray hit rate [MHz/cm2]: 17.1 11.7 18.1 28.1 29.2 31.0 31.3 20.7 21.1 28.5 27.6 23.7 24.9 15.6 6.1 7.2
[16:10:46.465] INFO: PixTestHighRate::doXPixelAlive() done
[16:10:46.518] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: clk: 4
[16:10:46.518] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: ctr: 4
[16:10:46.518] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: sda: 19
[16:10:46.518] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: tin: 9
[16:10:46.518] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: level: 15
[16:10:46.518] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: triggerdelay: 0
[16:10:46.518] INFO: PixTest:: pg_setup set to default.
[16:10:46.518] DEBUG: <PixTestHighRate.cc/~PixTestHighRate:L258> PixTestHighRate dtor
[16:10:46.531] INFO: enter test to run
[16:11:09.014] INFO: test: HighRate no parameter change
[16:11:09.014] INFO: running: highrate
[16:11:09.015] DEBUG: <PixTestHighRate.cc/setParameter:L68> setting fParTriggerFrequency -> 20
[16:11:09.015] DEBUG: <PixTestHighRate.cc/init:L211> PixTestHighRate::init()
[16:11:09.015] DEBUG: <PixTestHighRate.cc/PixTestHighRate:L31> PixTestHighRate ctor(PixSetup &a, string, TGTab *)
[16:11:09.016] DEBUG: <PixTestHighRate.cc/runCommand:L165> running command: xpixelalive
[16:11:09.016] INFO: ----------------------------------------------------------------------
[16:11:09.016] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:11:09.016] INFO: ----------------------------------------------------------------------
[16:11:09.016] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: clk: 4
[16:11:09.016] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: ctr: 4
[16:11:09.017] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: sda: 19
[16:11:09.017] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: tin: 9
[16:11:09.017] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: level: 15
[16:11:09.017] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: triggerdelay: 0
[16:11:09.017] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: clk: 4
[16:11:09.017] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: ctr: 4
[16:11:09.017] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: sda: 19
[16:11:09.017] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: tin: 9
[16:11:09.017] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: level: 15
[16:11:09.017] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: triggerdelay: 20
[16:11:09.024] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[16:11:09.631] INFO: Expecting 208000 events.
[16:11:23.138] INFO: 208000 events read in total (12980ms).
[16:11:23.143] INFO: Test took 14119ms.
[16:11:23.427] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:11:23.427] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 2555984
[16:11:23.427] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists highRate_C0 .. highRate_C15
[16:11:23.427] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[16:11:23.727] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[16:11:23.727] INFO: number of red-efficiency pixels: 183 128 258 437 366 512 386 229 245 400 329 334 255 189 61 72
[16:11:23.727] INFO: number of X-ray hits detected: 124479 86254 131496 203284 210950 225912 226565 151138 153042 207812 201059 173592 182047 113845 45172 52777
[16:11:23.727] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[16:11:23.727] INFO: number of Vcal hits detected: 207813 207862 207723 207529 207600 207441 207581 207751 207734 207567 207656 207647 207731 207797 207939 207927
[16:11:23.727] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.8 99.8 99.9 99.9 99.8 99.8 99.8 99.9 99.9 100.0 100.0
[16:11:23.727] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.7 99.8 99.9 99.9 99.8 99.8 99.8 99.9 99.9 100.0 100.0
[16:11:23.727] INFO: X-ray hit rate [MHz/cm2]: 36.5 25.3 38.5 59.6 61.8 66.2 66.4 44.3 44.9 60.9 58.9 50.9 53.4 33.4 13.2 15.5
[16:11:23.727] INFO: PixTestHighRate::doXPixelAlive() done
[16:11:23.778] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: clk: 4
[16:11:23.778] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: ctr: 4
[16:11:23.778] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: sda: 19
[16:11:23.778] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: tin: 9
[16:11:23.778] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: level: 15
[16:11:23.778] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: triggerdelay: 0
[16:11:23.778] INFO: PixTest:: pg_setup set to default.
[16:11:23.778] DEBUG: <PixTestHighRate.cc/~PixTestHighRate:L258> PixTestHighRate dtor
[16:11:23.795] INFO: enter test to run
[16:11:41.318] INFO: test: HighRate no parameter change
[16:11:41.318] INFO: running: highrate
[16:11:41.318] DEBUG: <PixTestHighRate.cc/setParameter:L68> setting fParTriggerFrequency -> 20
[16:11:41.318] DEBUG: <PixTestHighRate.cc/init:L211> PixTestHighRate::init()
[16:11:41.318] DEBUG: <PixTestHighRate.cc/PixTestHighRate:L31> PixTestHighRate ctor(PixSetup &a, string, TGTab *)
[16:11:41.319] DEBUG: <PixTestHighRate.cc/runCommand:L165> running command: xpixelalive
[16:11:41.319] INFO: ----------------------------------------------------------------------
[16:11:41.319] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:11:41.319] INFO: ----------------------------------------------------------------------
[16:11:41.320] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: clk: 4
[16:11:41.320] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: ctr: 4
[16:11:41.320] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: sda: 19
[16:11:41.320] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: tin: 9
[16:11:41.320] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: level: 15
[16:11:41.320] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: triggerdelay: 0
[16:11:41.320] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: clk: 4
[16:11:41.320] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: ctr: 4
[16:11:41.320] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: sda: 19
[16:11:41.320] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: tin: 9
[16:11:41.320] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: level: 15
[16:11:41.320] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: triggerdelay: 20
[16:11:41.326] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[16:11:41.932] INFO: Expecting 208000 events.
[16:11:57.155] INFO: 208000 events read in total (14696ms).
[16:11:57.162] INFO: Test took 15836ms.
[16:11:57.586] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:11:57.586] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 3751708
[16:11:57.586] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists highRate_C0 .. highRate_C15
[16:11:57.586] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[16:11:57.927] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[16:11:57.927] INFO: number of red-efficiency pixels: 337 196 560 926 798 1228 889 461 506 855 658 691 572 372 95 88
[16:11:57.927] INFO: number of X-ray hits detected: 184528 126643 194217 300477 311782 333308 335750 224280 226566 307367 297737 257632 268956 170385 67328 78192
[16:11:57.927] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[16:11:57.927] INFO: number of Vcal hits detected: 207622 207789 207306 206876 207063 206434 206968 207449 207419 206994 207267 207204 207360 207571 207904 207911
[16:11:57.927] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.7 99.5 99.6 99.3 99.5 99.8 99.7 99.6 99.7 99.7 99.7 99.8 100.0 100.0
[16:11:57.927] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.7 99.5 99.5 99.2 99.5 99.7 99.7 99.5 99.6 99.6 99.7 99.8 100.0 100.0
[16:11:57.927] INFO: X-ray hit rate [MHz/cm2]: 54.1 37.1 56.9 88.1 91.4 97.7 98.4 65.7 66.4 90.1 87.3 75.5 78.8 49.9 19.7 22.9
[16:11:57.927] INFO: PixTestHighRate::doXPixelAlive() done
[16:11:57.977] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: clk: 4
[16:11:57.977] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: ctr: 4
[16:11:57.977] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: sda: 19
[16:11:57.977] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: tin: 9
[16:11:57.977] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: level: 15
[16:11:57.977] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: triggerdelay: 0
[16:11:57.977] INFO: PixTest:: pg_setup set to default.
[16:11:57.977] DEBUG: <PixTestHighRate.cc/~PixTestHighRate:L258> PixTestHighRate dtor
[16:11:57.996] INFO: enter test to run
[16:12:08.526] INFO: test: exit no parameter change
[16:12:08.527] DEBUG: <pXar.cc/main:L340> Final Analog Current: 387.5mA
[16:12:08.528] DEBUG: <pXar.cc/main:L341> Final Digital Current: 468.7mA
[16:12:08.528] DEBUG: <pXar.cc/main:L342> Final Module Temperature: 19.0 C
[16:12:08.528] DEBUG: <PixMonitor.cc/dumpSummaries:L39> PixMonitor::dumpSummaries
[16:12:08.838] QUIET: Connection to board 33 closed.
[16:12:08.839] INFO: pXar: this is the end, my friend
[16:12:08.839] DEBUG: <PixSetup.cc/~PixSetup:L68> PixSetup free fPxarMemory