[09:32:06.612] INFO: *** Welcome to pxar ***
[09:32:06.612] INFO: *** Today: 2017/02/07
[09:32:07.613] INFO: *** Version: v1.9.0-825-g6bc29
[09:32:07.613] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-1-02_FPIXTest-17C-FNAL-170203-1315-150V_2017-02-03_13h15m_1486149329/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-1-02_FPIXTest-17C-FNAL-170203-1315-150V_2017-02-03_13h15m_1486149329/000_FPIXTest_p17//dacParameters35_C15.dat
[09:32:07.694] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-1-02_FPIXTest-17C-FNAL-170203-1315-150V_2017-02-03_13h15m_1486149329/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-1-02_FPIXTest-17C-FNAL-170203-1315-150V_2017-02-03_13h15m_1486149329/000_FPIXTest_p17//tbmParameters_C0b.dat
[09:32:07.697] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-1-02_FPIXTest-17C-FNAL-170203-1315-150V_2017-02-03_13h15m_1486149329/000_FPIXTest_p17//defaultMaskFile.dat
[09:32:07.697] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-1-02_FPIXTest-17C-FNAL-170203-1315-150V_2017-02-03_13h15m_1486149329/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-1-02_FPIXTest-17C-FNAL-170203-1315-150V_2017-02-03_13h15m_1486149329/000_FPIXTest_p17//trimParameters35_C15.dat
[09:32:07.830] INFO: clk: 4
[09:32:07.830] INFO: ctr: 4
[09:32:07.830] INFO: sda: 19
[09:32:07.830] INFO: tin: 9
[09:32:07.830] INFO: level: 15
[09:32:07.830] INFO: triggerdelay: 0
[09:32:07.830] QUIET: Instanciating API for pxar v1.9.0+825~g6bc290c
[09:32:07.830] INFO: Log level: DEBUG
[09:32:07.849] QUIET: Connection to board DTB_WREKRL opened.
[09:32:07.853] 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:
------------------------------------------------------
[09:32:07.856] INFO: RPC call hashes of host and DTB match: 398089610
[09:32:09.416] INFO: DUT info:
[09:32:09.416] INFO: The DUT currently contains the following objects:
[09:32:09.416] INFO: 2 TBM Cores tbm08c (2 ON)
[09:32:09.416] INFO: TBM Core alpha (0): 7 registers set
[09:32:09.416] INFO: TBM Core beta (1): 7 registers set
[09:32:09.416] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[09:32:09.416] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[09:32:09.416] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[09:32:09.416] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[09:32:09.416] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[09:32:09.416] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[09:32:09.416] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[09:32:09.417] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[09:32:09.417] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[09:32:09.417] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[09:32:09.417] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[09:32:09.417] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[09:32:09.417] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[09:32:09.417] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[09:32:09.417] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[09:32:09.417] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[09:32:09.417] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[09:32:09.436] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->BB<-
[09:32:09.436] DEBUG: <PixTestParameters.cc/dump:L107> dumpall: checkbox(0)
[09:32:09.436] DEBUG: <PixTestParameters.cc/dump:L107> dumpproblematic: checkbox(0)
[09:32:09.436] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 5
[09:32:09.436] DEBUG: <PixTestParameters.cc/dump:L107> vcals: 250
[09:32:09.436] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->BB2<-
[09:32:09.436] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[09:32:09.436] DEBUG: <PixTestParameters.cc/dump:L107> vcals: 222
[09:32:09.437] DEBUG: <PixTestParameters.cc/dump:L107> plwidth: 35
[09:32:09.437] DEBUG: <PixTestParameters.cc/dump:L107> pix: 11,20
[09:32:09.437] DEBUG: <PixTestParameters.cc/dump:L107> targetia: 24
[09:32:09.437] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->BB3<-
[09:32:09.437] DEBUG: <PixTestParameters.cc/dump:L107> dumpall: checkbox(0)
[09:32:09.437] DEBUG: <PixTestParameters.cc/dump:L107> dumpproblematic: checkbox(0)
[09:32:09.437] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 5
[09:32:09.437] DEBUG: <PixTestParameters.cc/dump:L107> vcals: 250
[09:32:09.437] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->BB4<-
[09:32:09.437] DEBUG: <PixTestParameters.cc/dump:L107> savecaldelscan: checkbox(0)
[09:32:09.437] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 100
[09:32:09.437] DEBUG: <PixTestParameters.cc/dump:L107> cals: 1
[09:32:09.437] DEBUG: <PixTestParameters.cc/dump:L107> caldello: 80
[09:32:09.437] DEBUG: <PixTestParameters.cc/dump:L107> caldelhi: 200
[09:32:09.437] DEBUG: <PixTestParameters.cc/dump:L107> caldelstep: 10
[09:32:09.437] DEBUG: <PixTestParameters.cc/dump:L107> vthrcomplo: 70
[09:32:09.437] DEBUG: <PixTestParameters.cc/dump:L107> vthrcomphi: 130
[09:32:09.437] DEBUG: <PixTestParameters.cc/dump:L107> vthrcompstep: 5
[09:32:09.437] DEBUG: <PixTestParameters.cc/dump:L107> noisypixels: 10
[09:32:09.437] DEBUG: <PixTestParameters.cc/dump:L107> vcal: 255
[09:32:09.437] DEBUG: <PixTestParameters.cc/dump:L107> cut: 0.5
[09:32:09.437] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Cmd<-
[09:32:09.437] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->DacDacScan<-
[09:32:09.437] DEBUG: <PixTestParameters.cc/dump:L107> phmap: checkbox
[09:32:09.437] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[09:32:09.437] DEBUG: <PixTestParameters.cc/dump:L107> dac1: caldel
[09:32:09.437] DEBUG: <PixTestParameters.cc/dump:L107> dac1lo: 0
[09:32:09.437] DEBUG: <PixTestParameters.cc/dump:L107> dac1hi: 255
[09:32:09.437] DEBUG: <PixTestParameters.cc/dump:L107> dac2: vthrcomp
[09:32:09.437] DEBUG: <PixTestParameters.cc/dump:L107> dac2lo: 0
[09:32:09.437] DEBUG: <PixTestParameters.cc/dump:L107> dac2hi: 255
[09:32:09.437] DEBUG: <PixTestParameters.cc/dump:L107> pix: 11,20
[09:32:09.437] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->DacScan<-
[09:32:09.437] DEBUG: <PixTestParameters.cc/dump:L107> phmap: checkbox(1)
[09:32:09.437] DEBUG: <PixTestParameters.cc/dump:L107> allpixels: checkbox(0)
[09:32:09.437] DEBUG: <PixTestParameters.cc/dump:L107> unmasked: checkbox(0)
[09:32:09.437] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[09:32:09.437] DEBUG: <PixTestParameters.cc/dump:L107> dac: vcal
[09:32:09.438] DEBUG: <PixTestParameters.cc/dump:L107> daclo: 0
[09:32:09.438] DEBUG: <PixTestParameters.cc/dump:L107> dachi: 255
[09:32:09.438] DEBUG: <PixTestParameters.cc/dump:L107> pix: 11,20
[09:32:09.438] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->GainPedestal<-
[09:32:09.438] DEBUG: <PixTestParameters.cc/dump:L107> showfits: checkbox(0)
[09:32:09.438] DEBUG: <PixTestParameters.cc/dump:L107> extended: checkbox(0)
[09:32:09.438] DEBUG: <PixTestParameters.cc/dump:L107> dumphists: checkbox(0)
[09:32:09.438] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[09:32:09.438] DEBUG: <PixTestParameters.cc/dump:L107> vcalstep: 10
[09:32:09.438] DEBUG: <PixTestParameters.cc/dump:L107> measure: button
[09:32:09.438] DEBUG: <PixTestParameters.cc/dump:L107> fit: button
[09:32:09.438] DEBUG: <PixTestParameters.cc/dump:L107> save: button
[09:32:09.438] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->HighRate<-
[09:32:09.438] DEBUG: <PixTestParameters.cc/dump:L107> pix: 11,20
[09:32:09.438] DEBUG: <PixTestParameters.cc/dump:L107> trimhotpixels: button
[09:32:09.438] DEBUG: <PixTestParameters.cc/dump:L107> trimhotpixelthr: 200
[09:32:09.438] DEBUG: <PixTestParameters.cc/dump:L107> runsecondshotpixels: 10
[09:32:09.438] DEBUG: <PixTestParameters.cc/dump:L107> savetrimbits: checkbox(1)
[09:32:09.438] DEBUG: <PixTestParameters.cc/dump:L107> maskuntrimmable: checkbox(1)
[09:32:09.438] DEBUG: <PixTestParameters.cc/dump:L107> maskhotpixels: button
[09:32:09.438] DEBUG: <PixTestParameters.cc/dump:L107> savemaskfile: checkbox(0)
[09:32:09.438] DEBUG: <PixTestParameters.cc/dump:L107> maskfilename: default
[09:32:09.438] DEBUG: <PixTestParameters.cc/dump:L107> caldelscan: button
[09:32:09.438] DEBUG: <PixTestParameters.cc/dump:L107> xpixelalive: button
[09:32:09.438] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 50
[09:32:09.438] DEBUG: <PixTestParameters.cc/dump:L107> vcal: 200
[09:32:09.438] DEBUG: <PixTestParameters.cc/dump:L107> xnoisemaps: button
[09:32:09.438] DEBUG: <PixTestParameters.cc/dump:L107> daclo: 0
[09:32:09.438] DEBUG: <PixTestParameters.cc/dump:L107> dachi: 100
[09:32:09.438] DEBUG: <PixTestParameters.cc/dump:L107> dacs/step: 20
[09:32:09.438] DEBUG: <PixTestParameters.cc/dump:L107> rundaq: button
[09:32:09.438] DEBUG: <PixTestParameters.cc/dump:L107> trgfrequency(khz): 20
[09:32:09.438] DEBUG: <PixTestParameters.cc/dump:L107> runseconds: 2
[09:32:09.438] DEBUG: <PixTestParameters.cc/dump:L107> triggerdelay: 20
[09:32:09.438] DEBUG: <PixTestParameters.cc/dump:L107> delaytbm: checkbox
[09:32:09.438] DEBUG: <PixTestParameters.cc/dump:L107> filltree: checkbox
[09:32:09.438] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->IV<-
[09:32:09.438] DEBUG: <PixTestParameters.cc/dump:L107> port: /dev/FIXME
[09:32:09.438] DEBUG: <PixTestParameters.cc/dump:L107> voltagestart: 0
[09:32:09.438] DEBUG: <PixTestParameters.cc/dump:L107> voltagestop: 600
[09:32:09.438] DEBUG: <PixTestParameters.cc/dump:L107> voltagestep: 5
[09:32:09.439] DEBUG: <PixTestParameters.cc/dump:L107> delay: 1
[09:32:09.439] DEBUG: <PixTestParameters.cc/dump:L107> compliance(ua): 100
[09:32:09.439] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->PhOptimization<-
[09:32:09.439] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[09:32:09.439] DEBUG: <PixTestParameters.cc/dump:L107> safetymarginlow: 20
[09:32:09.439] DEBUG: <PixTestParameters.cc/dump:L107> saturationvcal: 100
[09:32:09.439] DEBUG: <PixTestParameters.cc/dump:L107> quantilesaturation: 0.98
[09:32:09.439] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->PixelAlive<-
[09:32:09.439] DEBUG: <PixTestParameters.cc/dump:L107> phmap: checkbox(0)
[09:32:09.439] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[09:32:09.439] DEBUG: <PixTestParameters.cc/dump:L107> vcal: 200
[09:32:09.439] DEBUG: <PixTestParameters.cc/dump:L107> alivetest: button
[09:32:09.439] DEBUG: <PixTestParameters.cc/dump:L107> masktest: button
[09:32:09.439] DEBUG: <PixTestParameters.cc/dump:L107> addressdecodingtest: button
[09:32:09.439] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Pretest<-
[09:32:09.439] DEBUG: <PixTestParameters.cc/dump:L107> programroc: button
[09:32:09.439] DEBUG: <PixTestParameters.cc/dump:L107> checkidig: button
[09:32:09.439] DEBUG: <PixTestParameters.cc/dump:L107> targetia: 24
[09:32:09.439] DEBUG: <PixTestParameters.cc/dump:L107> setvana: button
[09:32:09.439] DEBUG: <PixTestParameters.cc/dump:L107> iterations: 100
[09:32:09.439] DEBUG: <PixTestParameters.cc/dump:L107> settimings: button
[09:32:09.439] DEBUG: <PixTestParameters.cc/dump:L107> findtiming: button
[09:32:09.439] DEBUG: <PixTestParameters.cc/dump:L107> findworkingpixel: button
[09:32:09.439] DEBUG: <PixTestParameters.cc/dump:L107> setvthrcompcaldel: button
[09:32:09.439] DEBUG: <PixTestParameters.cc/dump:L107> pix: 11,20
[09:32:09.439] DEBUG: <PixTestParameters.cc/dump:L107> vcal: 250
[09:32:09.439] DEBUG: <PixTestParameters.cc/dump:L107> deltavthrcomp: 50
[09:32:09.439] DEBUG: <PixTestParameters.cc/dump:L107> fraccaldel: 0.5
[09:32:09.439] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 5
[09:32:09.439] DEBUG: <PixTestParameters.cc/dump:L107> savedacs: button
[09:32:09.439] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Readback<-
[09:32:09.439] DEBUG: <PixTestParameters.cc/dump:L107> calibratevd: button
[09:32:09.439] DEBUG: <PixTestParameters.cc/dump:L107> calibrateva: button
[09:32:09.439] DEBUG: <PixTestParameters.cc/dump:L107> calibrateia: button
[09:32:09.439] DEBUG: <PixTestParameters.cc/dump:L107> readbackvbg: button
[09:32:09.439] DEBUG: <PixTestParameters.cc/dump:L107> getcalibratedvbg: button
[09:32:09.439] DEBUG: <PixTestParameters.cc/dump:L107> usecalvd: checkbox(1)
[09:32:09.439] DEBUG: <PixTestParameters.cc/dump:L107> usecalva: checkbox(0)
[09:32:09.439] DEBUG: <PixTestParameters.cc/dump:L107> setvana: button
[09:32:09.439] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Scurves<-
[09:32:09.439] DEBUG: <PixTestParameters.cc/dump:L107> adjustvcal: checkbox(0)
[09:32:09.439] DEBUG: <PixTestParameters.cc/dump:L107> dumpall: checkbox(0)
[09:32:09.439] DEBUG: <PixTestParameters.cc/dump:L107> dumpproblematic: checkbox(0)
[09:32:09.439] DEBUG: <PixTestParameters.cc/dump:L107> dumpoutputfile: checkbox(0)
[09:32:09.440] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 50
[09:32:09.440] DEBUG: <PixTestParameters.cc/dump:L107> dac: Vcal
[09:32:09.440] DEBUG: <PixTestParameters.cc/dump:L107> daclo: 0
[09:32:09.440] DEBUG: <PixTestParameters.cc/dump:L107> dachi: 200
[09:32:09.440] DEBUG: <PixTestParameters.cc/dump:L107> dacs/step: -1
[09:32:09.440] DEBUG: <PixTestParameters.cc/dump:L107> ntrig/step: -1
[09:32:09.440] DEBUG: <PixTestParameters.cc/dump:L107> scurves: button
[09:32:09.440] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Timing<-
[09:32:09.440] DEBUG: <PixTestParameters.cc/dump:L107> targetclk: 4
[09:32:09.440] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10000
[09:32:09.440] DEBUG: <PixTestParameters.cc/dump:L107> clocksdascan: button
[09:32:09.440] DEBUG: <PixTestParameters.cc/dump:L107> notokenpass: checkbox(0)
[09:32:09.440] DEBUG: <PixTestParameters.cc/dump:L107> ignorereadback: checkbox(0)
[09:32:09.440] DEBUG: <PixTestParameters.cc/dump:L107> phasescan: button
[09:32:09.440] DEBUG: <PixTestParameters.cc/dump:L107> levelscan: button
[09:32:09.440] DEBUG: <PixTestParameters.cc/dump:L107> tbmphasescan: button
[09:32:09.440] DEBUG: <PixTestParameters.cc/dump:L107> rocdelayscan: button
[09:32:09.440] DEBUG: <PixTestParameters.cc/dump:L107> timingtest: button
[09:32:09.440] DEBUG: <PixTestParameters.cc/dump:L107> saveparameters: button
[09:32:09.440] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Trim<-
[09:32:09.440] DEBUG: <PixTestParameters.cc/dump:L107> trim: button
[09:32:09.440] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 8
[09:32:09.440] DEBUG: <PixTestParameters.cc/dump:L107> vcal: 35
[09:32:09.440] DEBUG: <PixTestParameters.cc/dump:L107> trimbits: button
[09:32:09.440] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Xray<-
[09:32:09.440] DEBUG: <PixTestParameters.cc/dump:L107> maskhotpixels: button
[09:32:09.440] DEBUG: <PixTestParameters.cc/dump:L107> savemaskfile: checkbox(0)
[09:32:09.440] DEBUG: <PixTestParameters.cc/dump:L107> maskfilename: default
[09:32:09.440] DEBUG: <PixTestParameters.cc/dump:L107> source: Ag
[09:32:09.440] DEBUG: <PixTestParameters.cc/dump:L107> phrun: button
[09:32:09.440] DEBUG: <PixTestParameters.cc/dump:L107> runseconds: 100
[09:32:09.440] DEBUG: <PixTestParameters.cc/dump:L107> trgfrequency(khz): 100
[09:32:09.440] DEBUG: <PixTestParameters.cc/dump:L107> ratescan: button
[09:32:09.440] DEBUG: <PixTestParameters.cc/dump:L107> vthrcompmin: 10
[09:32:09.440] DEBUG: <PixTestParameters.cc/dump:L107> vthrcompmax: 80
[09:32:09.440] DEBUG: <PixTestParameters.cc/dump:L107> stepseconds: 5
[09:32:09.440] DEBUG: <PixTestParameters.cc/dump:L107> delaytbm: checkbox
[09:32:09.440] DEBUG: <PixTestParameters.cc/dump:L107> filltree: checkbox
[09:32:09.443] DEBUG: <PixSetup.cc/init:L81> PixSetup init start; getCurrentRSS() = 29048832
[09:32:09.443] DEBUG: <PixSetup.cc/init:L87> fPixTestParameters = 0x1720220
[09:32:09.443] DEBUG: <PixSetup.cc/init:L88> fConfigParameters = 0x1646310
[09:32:09.443] DEBUG: <PixSetup.cc/init:L89> fPxarMemory = 0x7fb449d94010
[09:32:09.443] DEBUG: <PixSetup.cc/init:L90> fPxarMemHi = 0x7fb44ffff510
[09:32:09.443] DEBUG: <PixSetup.cc/init:L106> PixSetup init done; getCurrentRSS() = 29114368 fPxarMemory = 0x7fb449d94010
[09:32:09.444] DEBUG: <pXar.cc/main:L223> Initial Analog Current: 384.3mA
[09:32:09.445] DEBUG: <pXar.cc/main:L224> Initial Digital Current: 462.3mA
[09:32:09.445] DEBUG: <pXar.cc/main:L225> Initial Module Temperature: 2.3 C
[09:32:09.446] DEBUG: <PixTestFactory.cc/PixTestFactory:L53> PixTestFactory::PixTestFactory()
[09:32:09.856] INFO: enter 'restricted' command line mode
[09:32:09.856] INFO: enter test to run
[09:32:16.274] INFO: test: PixelAlive no parameter change
[09:32:16.274] INFO: running: pixelalive
[09:32:16.274] DEBUG: <PixTestAlive.cc/init:L83> PixTestAlive::init()
[09:32:16.290] DEBUG: <PixTestAlive.cc/PixTestAlive:L21> PixTestAlive ctor(PixSetup &a, string, TGTab *)
[09:32:16.290] DEBUG: <PixTestAlive.cc/runCommand:L62> running command: alivetest
[09:32:16.318] INFO: ----------------------------------------------------------------------
[09:32:16.318] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[09:32:16.318] INFO: ----------------------------------------------------------------------
[09:32:16.322] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[09:32:16.635] INFO: Expecting 41600 events.
[09:32:20.972] INFO: 41600 events read in total (3618ms).
[09:32:21.138] INFO: Test took 4816ms.
[09:32:21.153] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:32:21.153] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 66555
[09:32:21.153] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists PixelAlive_C0 .. PixelAlive_C15
[09:32:21.653] INFO: PixTestAlive::aliveTest() done
[09:32:21.653] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 5 0 0 0
[09:32:21.653] DEBUG: <PixTestAlive.cc/aliveTest:L199> number of red-efficiency pixels: 0 0 0 0 0 0 0 0 0 0 0 0 5 0 0 0
[09:32:21.653] DEBUG: <PixTestAlive.cc/~PixTestAlive:L115> PixTestAlive dtor
[09:32:21.828] INFO: enter test to run
[09:32:49.049] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[09:32:49.050] DEBUG: <PixTestParameters.cc/setTestParameter:L119> PixTestParameters: ->Xray<-
[09:32:49.050] DEBUG: <PixTestParameters.cc/setTestParameter:L124> setting source to new value DCLowRate
[09:32:49.050] INFO: running: xray
[09:32:49.050] DEBUG: <PixTestXray.cc/init:L135> PixTestXray::init()
[09:32:49.050] DEBUG: <PixTestXray.cc/PixTestXray:L28> PixTestXray ctor(PixSetup &a, string, TGTab *)
[09:32:49.050] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-1-02_FPIXTest-17C-FNAL-170203-1315-150V_2017-02-03_13h15m_1486149329/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-1-02_FPIXTest-17C-FNAL-170203-1315-150V_2017-02-03_13h15m_1486149329/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[09:32:49.334] DEBUG: <PixTestXray.cc/runCommand:L109> running command: phrun
[09:32:49.334] INFO: ----------------------------------------------------------------------
[09:32:49.334] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[09:32:49.334] INFO: ----------------------------------------------------------------------
[09:32:50.309] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[09:33:01.791] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[09:33:01.794] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[09:33:27.691] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 1131266 events.
[09:33:31.230] DEBUG: <PixTestXray.cc/processData:L823> # events read: 1131266, pixels seen in all events: 6676322
[09:33:31.380] INFO: Resuming triggers.
[09:33:42.856] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[09:33:42.860] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[09:34:08.619] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 1130614 events.
[09:34:12.176] DEBUG: <PixTestXray.cc/processData:L823> # events read: 1130614, pixels seen in all events: 6683524
[09:34:12.252] INFO: Resuming triggers.
[09:34:23.731] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[09:34:23.734] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[09:34:49.503] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 1130877 events.
[09:34:53.056] DEBUG: <PixTestXray.cc/processData:L823> # events read: 1130877, pixels seen in all events: 6681143
[09:34:53.133] INFO: Resuming triggers.
[09:35:04.610] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[09:35:04.613] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[09:35:30.380] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 1130680 events.
[09:35:33.880] DEBUG: <PixTestXray.cc/processData:L823> # events read: 1130680, pixels seen in all events: 6683429
[09:35:33.002] INFO: Resuming triggers.
[09:35:45.479] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[09:35:45.483] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[09:36:11.356] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 1130683 events.
[09:36:14.900] DEBUG: <PixTestXray.cc/processData:L823> # events read: 1130683, pixels seen in all events: 6683273
[09:36:14.929] INFO: Resuming triggers.
[09:36:26.403] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[09:36:26.458] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[09:36:52.264] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 1130388 events.
[09:36:55.772] DEBUG: <PixTestXray.cc/processData:L823> # events read: 1130388, pixels seen in all events: 6686435
[09:36:55.894] INFO: Resuming triggers.
[09:37:07.370] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[09:37:07.374] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[09:37:33.160] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 1130589 events.
[09:37:36.645] DEBUG: <PixTestXray.cc/processData:L823> # events read: 1130589, pixels seen in all events: 6684246
[09:37:36.768] INFO: Resuming triggers.
[09:37:48.244] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[09:37:48.248] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[09:38:14.159] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 1130611 events.
[09:38:17.952] DEBUG: <PixTestXray.cc/processData:L823> # events read: 1130611, pixels seen in all events: 6683677
[09:38:18.077] INFO: Resuming triggers.
[09:38:26.611] INFO: data taking finished, elapsed time: 100 seconds.
[09:38:26.807] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[09:38:45.640] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 840694 events.
[09:38:48.488] DEBUG: <PixTestXray.cc/processData:L823> # events read: 840694, pixels seen in all events: 4971867
[09:38:48.546] INFO: PixTest:: pg_setup set to default.
[09:38:48.549] INFO: PixTestXray::doPhRun() done
[09:38:48.549] DEBUG: <PixTestXray.cc/~PixTestXray:L218> PixTestXray dtor
[09:38:48.694] INFO: enter test to run
[09:40:31.767] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[09:40:31.767] DEBUG: <PixTestParameters.cc/setTestParameter:L119> PixTestParameters: ->Xray<-
[09:40:31.767] DEBUG: <PixTestParameters.cc/setTestParameter:L124> setting source to new value DCHighRate
[09:40:31.767] INFO: running: xray
[09:40:31.767] DEBUG: <PixTestXray.cc/init:L135> PixTestXray::init()
[09:40:31.767] DEBUG: <PixTestXray.cc/PixTestXray:L28> PixTestXray ctor(PixSetup &a, string, TGTab *)
[09:40:31.768] DEBUG: <PixTestXray.cc/runCommand:L109> running command: phrun
[09:40:31.768] INFO: ----------------------------------------------------------------------
[09:40:31.768] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[09:40:31.768] INFO: ----------------------------------------------------------------------
[09:40:32.732] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[09:40:39.206] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[09:40:39.210] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[09:41:02.429] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 637902 events.
[09:41:09.577] DEBUG: <PixTestXray.cc/processData:L823> # events read: 637902, pixels seen in all events: 12596876
[09:41:09.620] INFO: Resuming triggers.
[09:41:16.098] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[09:41:16.101] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[09:41:39.952] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 638160 events.
[09:41:47.112] DEBUG: <PixTestXray.cc/processData:L823> # events read: 638160, pixels seen in all events: 12595179
[09:41:47.158] INFO: Resuming triggers.
[09:41:53.636] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[09:41:53.640] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[09:42:18.097] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 638237 events.
[09:42:25.387] DEBUG: <PixTestXray.cc/processData:L823> # events read: 638237, pixels seen in all events: 12594076
[09:42:25.452] INFO: Resuming triggers.
[09:42:31.932] INFO: run duration 25 seconds, buffer almost full (81%), pausing triggers.
[09:42:31.935] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[09:42:56.317] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 638366 events.
[09:43:03.792] DEBUG: <PixTestXray.cc/processData:L823> # events read: 638366, pixels seen in all events: 12592000
[09:43:03.839] INFO: Resuming triggers.
[09:43:10.316] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[09:43:10.320] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[09:43:33.933] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 638078 events.
[09:43:40.485] DEBUG: <PixTestXray.cc/processData:L823> # events read: 638078, pixels seen in all events: 12595754
[09:43:40.531] INFO: Resuming triggers.
[09:43:47.009] INFO: run duration 38 seconds, buffer almost full (81%), pausing triggers.
[09:43:47.012] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[09:44:10.589] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 638132 events.
[09:44:17.297] DEBUG: <PixTestXray.cc/processData:L823> # events read: 638132, pixels seen in all events: 12595085
[09:44:17.341] INFO: Resuming triggers.
[09:44:23.817] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[09:44:23.821] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[09:44:47.526] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 638003 events.
[09:44:54.264] DEBUG: <PixTestXray.cc/processData:L823> # events read: 638003, pixels seen in all events: 12596226
[09:44:54.310] INFO: Resuming triggers.
[09:45:00.787] INFO: run duration 51 seconds, buffer almost full (81%), pausing triggers.
[09:45:00.791] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[09:45:24.441] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 638162 events.
[09:45:31.159] DEBUG: <PixTestXray.cc/processData:L823> # events read: 638162, pixels seen in all events: 12595023
[09:45:31.215] INFO: Resuming triggers.
[09:45:37.690] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[09:45:37.694] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[09:46:01.328] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 637881 events.
[09:46:07.878] DEBUG: <PixTestXray.cc/processData:L823> # events read: 637881, pixels seen in all events: 12597831
[09:46:07.933] INFO: Resuming triggers.
[09:46:14.410] INFO: run duration 64 seconds, buffer almost full (81%), pausing triggers.
[09:46:14.413] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[09:46:38.047] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 638072 events.
[09:46:44.724] DEBUG: <PixTestXray.cc/processData:L823> # events read: 638072, pixels seen in all events: 12594803
[09:46:44.777] INFO: Resuming triggers.
[09:46:51.251] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[09:46:51.254] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[09:47:14.801] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 637730 events.
[09:47:21.319] DEBUG: <PixTestXray.cc/processData:L823> # events read: 637730, pixels seen in all events: 12599122
[09:47:21.371] INFO: Resuming triggers.
[09:47:27.843] INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.
[09:47:27.847] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[09:47:51.429] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 637607 events.
[09:47:58.066] DEBUG: <PixTestXray.cc/processData:L823> # events read: 637607, pixels seen in all events: 12601677
[09:47:58.120] INFO: Resuming triggers.
[09:48:04.592] INFO: run duration 83 seconds, buffer almost full (81%), pausing triggers.
[09:48:04.596] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[09:48:28.137] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 637663 events.
[09:48:34.846] DEBUG: <PixTestXray.cc/processData:L823> # events read: 637663, pixels seen in all events: 12600535
[09:48:34.901] INFO: Resuming triggers.
[09:48:41.375] INFO: run duration 90 seconds, buffer almost full (81%), pausing triggers.
[09:48:41.378] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[09:49:04.939] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 637783 events.
[09:49:11.593] DEBUG: <PixTestXray.cc/processData:L823> # events read: 637783, pixels seen in all events: 12598177
[09:49:11.650] INFO: Resuming triggers.
[09:49:18.124] INFO: run duration 96 seconds, buffer almost full (81%), pausing triggers.
[09:49:18.128] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[09:49:41.730] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 637813 events.
[09:49:48.426] DEBUG: <PixTestXray.cc/processData:L823> # events read: 637813, pixels seen in all events: 12598002
[09:49:48.480] INFO: Resuming triggers.
[09:49:51.703] INFO: data taking finished, elapsed time: 100 seconds.
[09:49:51.898] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[09:50:03.737] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 317436 events.
[09:50:07.147] DEBUG: <PixTestXray.cc/processData:L823> # events read: 317436, pixels seen in all events: 6271253
[09:50:07.166] INFO: PixTest:: pg_setup set to default.
[09:50:07.169] INFO: PixTestXray::doPhRun() done
[09:50:07.169] DEBUG: <PixTestXray.cc/~PixTestXray:L218> PixTestXray dtor
[09:50:07.319] INFO: enter test to run
[09:50:32.170] INFO: test: HighRate no parameter change
[09:50:32.170] INFO: running: highrate
[09:50:32.185] DEBUG: <PixTestHighRate.cc/setParameter:L68> setting fParTriggerFrequency -> 20
[09:50:32.185] DEBUG: <PixTestHighRate.cc/init:L211> PixTestHighRate::init()
[09:50:32.186] DEBUG: <PixTestHighRate.cc/PixTestHighRate:L31> PixTestHighRate ctor(PixSetup &a, string, TGTab *)
[09:50:32.187] DEBUG: <PixTestHighRate.cc/runCommand:L165> running command: caldelscan
[09:50:32.187] INFO: ----------------------------------------------------------------------
[09:50:32.187] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[09:50:32.187] INFO: ----------------------------------------------------------------------
[09:50:32.338] INFO: Expecting 768 events.
[09:50:33.472] INFO: 768 events read in total (419ms).
[09:50:33.472] INFO: Test took 1269ms.
[09:50:33.493] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[09:50:34.275] INFO: Expecting 41600 events.
[09:50:37.337] INFO: 41600 events read in total (2535ms).
[09:50:37.338] INFO: Test took 3845ms.
[09:50:37.372] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:50:37.372] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 306416
[09:50:37.372] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step0_C0 .. HR_xeff_CalDelScan_step0_C15
[09:50:37.372] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[09:50:37.390] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[09:50:38.100] INFO: Expecting 41600 events.
[09:50:41.326] INFO: 41600 events read in total (2700ms).
[09:50:41.327] INFO: Test took 3937ms.
[09:50:41.362] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:50:41.362] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 316042
[09:50:41.363] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step1_C0 .. HR_xeff_CalDelScan_step1_C15
[09:50:41.363] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[09:50:41.380] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[09:50:42.085] INFO: Expecting 41600 events.
[09:50:45.332] INFO: 41600 events read in total (2720ms).
[09:50:45.333] INFO: Test took 3953ms.
[09:50:45.367] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:50:45.367] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 315652
[09:50:45.367] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step2_C0 .. HR_xeff_CalDelScan_step2_C15
[09:50:45.367] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[09:50:45.384] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[09:50:46.092] INFO: Expecting 41600 events.
[09:50:49.338] INFO: 41600 events read in total (2720ms).
[09:50:49.340] INFO: Test took 3956ms.
[09:50:49.374] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:50:49.374] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 316774
[09:50:49.374] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step3_C0 .. HR_xeff_CalDelScan_step3_C15
[09:50:49.374] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[09:50:49.393] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[09:50:50.098] INFO: Expecting 41600 events.
[09:50:53.361] INFO: 41600 events read in total (2736ms).
[09:50:53.362] INFO: Test took 3969ms.
[09:50:53.396] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:50:53.396] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 316711
[09:50:53.396] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step4_C0 .. HR_xeff_CalDelScan_step4_C15
[09:50:53.396] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[09:50:53.413] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[09:50:54.121] INFO: Expecting 41600 events.
[09:50:57.370] INFO: 41600 events read in total (2722ms).
[09:50:57.371] INFO: Test took 3958ms.
[09:50:57.405] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:50:57.405] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 316049
[09:50:57.405] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step5_C0 .. HR_xeff_CalDelScan_step5_C15
[09:50:57.405] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[09:50:57.422] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[09:50:58.130] INFO: Expecting 41600 events.
[09:51:01.399] INFO: 41600 events read in total (2742ms).
[09:51:01.400] INFO: Test took 3978ms.
[09:51:01.436] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:51:01.436] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 316615
[09:51:01.436] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step6_C0 .. HR_xeff_CalDelScan_step6_C15
[09:51:01.436] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[09:51:01.455] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[09:51:02.157] INFO: Expecting 41600 events.
[09:51:05.444] INFO: 41600 events read in total (2760ms).
[09:51:05.445] INFO: Test took 3990ms.
[09:51:05.480] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:51:05.480] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 317720
[09:51:05.480] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step7_C0 .. HR_xeff_CalDelScan_step7_C15
[09:51:05.480] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[09:51:05.498] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[09:51:06.199] INFO: Expecting 41600 events.
[09:51:09.475] INFO: 41600 events read in total (2749ms).
[09:51:09.476] INFO: Test took 3978ms.
[09:51:09.511] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:51:09.511] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 317107
[09:51:09.511] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step8_C0 .. HR_xeff_CalDelScan_step8_C15
[09:51:09.511] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[09:51:09.529] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[09:51:10.230] INFO: Expecting 41600 events.
[09:51:13.544] INFO: 41600 events read in total (2788ms).
[09:51:13.545] INFO: Test took 4016ms.
[09:51:13.580] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:51:13.580] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 317524
[09:51:13.580] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step9_C0 .. HR_xeff_CalDelScan_step9_C15
[09:51:13.580] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[09:51:13.598] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[09:51:14.301] INFO: Expecting 41600 events.
[09:51:17.575] INFO: 41600 events read in total (2747ms).
[09:51:17.577] INFO: Test took 3979ms.
[09:51:17.617] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:51:17.617] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 317609
[09:51:17.617] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step10_C0 .. HR_xeff_CalDelScan_step10_C15
[09:51:17.617] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[09:51:17.635] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[09:51:18.312] INFO: Expecting 41600 events.
[09:51:21.638] INFO: 41600 events read in total (2799ms).
[09:51:21.639] INFO: Test took 4004ms.
[09:51:21.674] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:51:21.674] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 317572
[09:51:21.674] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step11_C0 .. HR_xeff_CalDelScan_step11_C15
[09:51:21.675] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[09:51:21.693] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[09:51:22.398] INFO: Expecting 41600 events.
[09:51:25.692] INFO: 41600 events read in total (2767ms).
[09:51:25.693] INFO: Test took 4000ms.
[09:51:25.731] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:51:25.731] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 317914
[09:51:25.731] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step12_C0 .. HR_xeff_CalDelScan_step12_C15
[09:51:25.731] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[09:51:25.751] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[09:51:26.443] INFO: Expecting 41600 events.
[09:51:29.636] INFO: 41600 events read in total (2666ms).
[09:51:29.638] INFO: Test took 3887ms.
[09:51:29.684] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:51:29.684] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 316194
[09:51:29.684] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step13_C0 .. HR_xeff_CalDelScan_step13_C15
[09:51:29.684] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[09:51:29.728] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[09:51:30.393] INFO: Expecting 41600 events.
[09:51:33.502] INFO: 41600 events read in total (2582ms).
[09:51:33.503] INFO: Test took 3775ms.
[09:51:33.539] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:51:33.539] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 317118
[09:51:33.539] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step14_C0 .. HR_xeff_CalDelScan_step14_C15
[09:51:33.540] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[09:51:33.561] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[09:51:34.258] INFO: Expecting 41600 events.
[09:51:37.447] INFO: 41600 events read in total (2662ms).
[09:51:37.448] INFO: Test took 3887ms.
[09:51:37.484] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:51:37.484] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 316291
[09:51:37.484] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step15_C0 .. HR_xeff_CalDelScan_step15_C15
[09:51:37.484] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[09:51:37.503] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[09:51:38.201] INFO: Expecting 41600 events.
[09:51:41.327] INFO: 41600 events read in total (2599ms).
[09:51:41.327] INFO: Test took 3824ms.
[09:51:41.364] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:51:41.364] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 317088
[09:51:41.364] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step16_C0 .. HR_xeff_CalDelScan_step16_C15
[09:51:41.364] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[09:51:41.384] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[09:51:42.082] INFO: Expecting 41600 events.
[09:51:45.345] INFO: 41600 events read in total (2736ms).
[09:51:45.346] INFO: Test took 3962ms.
[09:51:45.381] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:51:45.381] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 317429
[09:51:45.381] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step17_C0 .. HR_xeff_CalDelScan_step17_C15
[09:51:45.382] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[09:51:45.399] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[09:51:46.106] INFO: Expecting 41600 events.
[09:51:49.367] INFO: 41600 events read in total (2734ms).
[09:51:49.368] INFO: Test took 3969ms.
[09:51:49.403] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:51:49.403] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 316758
[09:51:49.403] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step18_C0 .. HR_xeff_CalDelScan_step18_C15
[09:51:49.403] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[09:51:49.422] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[09:51:50.126] INFO: Expecting 41600 events.
[09:51:53.082] INFO: 41600 events read in total (2429ms).
[09:51:53.083] INFO: Test took 3661ms.
[09:51:53.118] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:51:53.118] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 310421
[09:51:53.118] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step19_C0 .. HR_xeff_CalDelScan_step19_C15
[09:51:53.118] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[09:51:53.454] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 0: caldel = 172 eff = 0.999808
[09:51:53.454] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 1: caldel = 156 eff = 0.999856
[09:51:53.454] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 2: caldel = 154 eff = 0.999688
[09:51:53.454] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 3: caldel = 181 eff = 0.999591
[09:51:53.455] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 4: caldel = 168 eff = 0.999519
[09:51:53.455] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 5: caldel = 161 eff = 0.999615
[09:51:53.455] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 6: caldel = 173 eff = 0.999591
[09:51:53.455] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 7: caldel = 170 eff = 0.999712
[09:51:53.456] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 8: caldel = 141 eff = 0.999736
[09:51:53.456] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 9: caldel = 143 eff = 0.999519
[09:51:53.456] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 10: caldel = 158 eff = 0.999663
[09:51:53.456] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 11: caldel = 158 eff = 0.99976
[09:51:53.457] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 12: caldel = 163 eff = 0.998413
[09:51:53.457] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 13: caldel = 154 eff = 0.999784
[09:51:53.457] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 14: caldel = 178 eff = 0.999928
[09:51:53.457] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 15: caldel = 159 eff = 0.999952
[09:51:53.461] DEBUG: <PixTestHighRate.cc/~PixTestHighRate:L258> PixTestHighRate dtor
[09:51:53.487] INFO: enter test to run
[09:53:12.137] INFO: test: HighRate no parameter change
[09:53:12.137] INFO: running: highrate
[09:53:12.137] DEBUG: <PixTestHighRate.cc/setParameter:L68> setting fParTriggerFrequency -> 20
[09:53:12.137] DEBUG: <PixTestHighRate.cc/init:L211> PixTestHighRate::init()
[09:53:12.137] DEBUG: <PixTestHighRate.cc/PixTestHighRate:L31> PixTestHighRate ctor(PixSetup &a, string, TGTab *)
[09:53:12.138] DEBUG: <PixTestHighRate.cc/runCommand:L165> running command: xpixelalive
[09:53:12.138] INFO: ----------------------------------------------------------------------
[09:53:12.138] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[09:53:12.138] INFO: ----------------------------------------------------------------------
[09:53:12.138] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: clk: 4
[09:53:12.138] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: ctr: 4
[09:53:12.138] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: sda: 19
[09:53:12.138] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: tin: 9
[09:53:12.138] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: level: 15
[09:53:12.138] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: triggerdelay: 0
[09:53:12.138] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: clk: 4
[09:53:12.138] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: ctr: 4
[09:53:12.138] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: sda: 19
[09:53:12.138] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: tin: 9
[09:53:12.138] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: level: 15
[09:53:12.138] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: triggerdelay: 20
[09:53:12.158] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[09:53:12.765] INFO: Expecting 208000 events.
[09:53:24.547] INFO: 208000 events read in total (11255ms).
[09:53:24.550] INFO: Test took 12392ms.
[09:53:24.699] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:53:24.699] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 1310953
[09:53:24.699] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists highRate_C0 .. highRate_C15
[09:53:24.700] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[09:53:24.952] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 5 0 0 0
[09:53:24.952] INFO: number of red-efficiency pixels: 84 61 96 117 136 129 132 86 65 148 115 128 105 76 39 33
[09:53:24.952] INFO: number of X-ray hits detected: 58883 41078 67327 100252 107264 109450 111295 78480 76551 109292 103996 87465 88002 57709 21548 25806
[09:53:24.952] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[09:53:24.952] INFO: number of Vcal hits detected: 207915 207939 207903 207878 207862 207870 207863 207912 207935 207844 207882 207868 207648 207923 207951 207967
[09:53:24.952] 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 99.9 99.9 100.0 100.0 100.0 100.0
[09:53:24.952] 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 99.9 99.9 99.8 100.0 100.0 100.0
[09:53:24.952] INFO: X-ray hit rate [MHz/cm2]: 17.3 12.0 19.7 29.4 31.4 32.1 32.6 23.0 22.4 32.0 30.5 25.6 25.8 16.9 6.3 7.6
[09:53:24.952] INFO: PixTestHighRate::doXPixelAlive() done
[09:53:24.996] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: clk: 4
[09:53:24.996] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: ctr: 4
[09:53:24.996] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: sda: 19
[09:53:24.997] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: tin: 9
[09:53:24.997] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: level: 15
[09:53:24.997] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: triggerdelay: 0
[09:53:24.997] INFO: PixTest:: pg_setup set to default.
[09:53:24.997] DEBUG: <PixTestHighRate.cc/~PixTestHighRate:L258> PixTestHighRate dtor
[09:53:25.027] INFO: enter test to run
[09:53:42.729] INFO: test: HighRate no parameter change
[09:53:42.729] INFO: running: highrate
[09:53:42.729] DEBUG: <PixTestHighRate.cc/setParameter:L68> setting fParTriggerFrequency -> 20
[09:53:42.729] DEBUG: <PixTestHighRate.cc/init:L211> PixTestHighRate::init()
[09:53:42.729] DEBUG: <PixTestHighRate.cc/PixTestHighRate:L31> PixTestHighRate ctor(PixSetup &a, string, TGTab *)
[09:53:42.730] DEBUG: <PixTestHighRate.cc/runCommand:L165> running command: xpixelalive
[09:53:42.730] INFO: ----------------------------------------------------------------------
[09:53:42.730] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[09:53:42.730] INFO: ----------------------------------------------------------------------
[09:53:42.730] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: clk: 4
[09:53:42.731] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: ctr: 4
[09:53:42.731] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: sda: 19
[09:53:42.731] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: tin: 9
[09:53:42.731] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: level: 15
[09:53:42.731] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: triggerdelay: 0
[09:53:42.731] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: clk: 4
[09:53:42.731] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: ctr: 4
[09:53:42.731] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: sda: 19
[09:53:42.731] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: tin: 9
[09:53:42.731] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: level: 15
[09:53:42.731] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: triggerdelay: 20
[09:53:42.738] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[09:53:43.351] INFO: Expecting 208000 events.
[09:53:57.022] INFO: 208000 events read in total (13144ms).
[09:53:57.028] INFO: Test took 14290ms.
[09:53:57.338] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:53:57.338] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 2821931
[09:53:57.338] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists highRate_C0 .. highRate_C15
[09:53:57.338] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[09:53:57.646] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 5 0 0 0
[09:53:57.646] INFO: number of red-efficiency pixels: 218 132 298 370 449 474 451 273 302 437 440 409 391 218 61 59
[09:53:57.646] INFO: number of X-ray hits detected: 130289 91090 149558 220677 238868 241644 247186 173109 169325 241983 230772 193330 193938 127824 48275 57508
[09:53:57.646] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[09:53:57.646] INFO: number of Vcal hits detected: 207769 207858 207674 207599 207505 207469 207504 207712 207679 207529 207511 207556 207340 207766 207924 207941
[09:53:57.646] 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.8 99.9 100.0 100.0
[09:53:57.646] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.8 99.8 99.7 99.8 99.9 99.8 99.8 99.8 99.8 99.7 99.9 100.0 100.0
[09:53:57.646] INFO: X-ray hit rate [MHz/cm2]: 38.2 26.7 43.8 64.7 70.0 70.8 72.5 50.7 49.6 70.9 67.6 56.7 56.8 37.5 14.1 16.9
[09:53:57.646] INFO: PixTestHighRate::doXPixelAlive() done
[09:53:57.694] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: clk: 4
[09:53:57.694] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: ctr: 4
[09:53:57.694] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: sda: 19
[09:53:57.694] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: tin: 9
[09:53:57.694] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: level: 15
[09:53:57.694] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: triggerdelay: 0
[09:53:57.694] INFO: PixTest:: pg_setup set to default.
[09:53:57.694] DEBUG: <PixTestHighRate.cc/~PixTestHighRate:L258> PixTestHighRate dtor
[09:53:57.707] INFO: enter test to run
[09:54:15.961] INFO: test: HighRate no parameter change
[09:54:15.961] INFO: running: highrate
[09:54:15.961] DEBUG: <PixTestHighRate.cc/setParameter:L68> setting fParTriggerFrequency -> 20
[09:54:15.961] DEBUG: <PixTestHighRate.cc/init:L211> PixTestHighRate::init()
[09:54:15.961] DEBUG: <PixTestHighRate.cc/PixTestHighRate:L31> PixTestHighRate ctor(PixSetup &a, string, TGTab *)
[09:54:15.962] DEBUG: <PixTestHighRate.cc/runCommand:L165> running command: xpixelalive
[09:54:15.962] INFO: ----------------------------------------------------------------------
[09:54:15.962] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[09:54:15.962] INFO: ----------------------------------------------------------------------
[09:54:15.962] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: clk: 4
[09:54:15.962] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: ctr: 4
[09:54:15.962] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: sda: 19
[09:54:15.962] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: tin: 9
[09:54:15.962] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: level: 15
[09:54:15.962] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: triggerdelay: 0
[09:54:15.962] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: clk: 4
[09:54:15.962] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: ctr: 4
[09:54:15.963] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: sda: 19
[09:54:15.963] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: tin: 9
[09:54:15.963] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: level: 15
[09:54:15.963] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: triggerdelay: 20
[09:54:15.969] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[09:54:16.581] INFO: Expecting 208000 events.
[09:54:32.690] INFO: 208000 events read in total (15583ms).
[09:54:32.697] INFO: Test took 16729ms.
[09:54:33.183] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:54:33.183] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 4256327
[09:54:33.183] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists highRate_C0 .. highRate_C15
[09:54:33.184] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[09:54:33.546] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 5 0 0 0
[09:54:33.546] INFO: number of red-efficiency pixels: 496 283 743 810 984 1107 1088 570 610 1114 1020 921 865 464 112 80
[09:54:33.546] INFO: number of X-ray hits detected: 197300 139351 227061 336638 361264 367036 375451 264536 257642 366931 350447 294936 294809 193905 74202 88263
[09:54:33.546] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[09:54:33.546] INFO: number of Vcal hits detected: 207408 207686 206996 207018 206781 206572 206625 207291 207267 206554 206721 206854 206728 207459 207868 207919
[09:54:33.546] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.6 99.6 99.5 99.4 99.4 99.7 99.7 99.4 99.5 99.5 99.6 99.8 99.9 100.0
[09:54:33.546] INFO: Vcal hit overall efficiency (%): 99.7 99.8 99.5 99.5 99.4 99.3 99.3 99.7 99.6 99.3 99.4 99.4 99.4 99.7 99.9 100.0
[09:54:33.546] INFO: X-ray hit rate [MHz/cm2]: 57.8 40.8 66.6 98.7 105.9 107.6 110.0 77.5 75.5 107.6 102.7 86.4 86.4 56.8 21.7 25.9
[09:54:33.546] INFO: PixTestHighRate::doXPixelAlive() done
[09:54:33.595] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: clk: 4
[09:54:33.595] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: ctr: 4
[09:54:33.595] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: sda: 19
[09:54:33.595] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: tin: 9
[09:54:33.595] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: level: 15
[09:54:33.595] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: triggerdelay: 0
[09:54:33.595] INFO: PixTest:: pg_setup set to default.
[09:54:33.595] DEBUG: <PixTestHighRate.cc/~PixTestHighRate:L258> PixTestHighRate dtor
[09:54:33.613] INFO: enter test to run
[09:54:41.016] INFO: test: exit no parameter change
[09:54:41.018] DEBUG: <pXar.cc/main:L340> Final Analog Current: 389.1mA
[09:54:41.018] DEBUG: <pXar.cc/main:L341> Final Digital Current: 464.7mA
[09:54:41.018] DEBUG: <pXar.cc/main:L342> Final Module Temperature: 19.0 C
[09:54:41.018] DEBUG: <PixMonitor.cc/dumpSummaries:L39> PixMonitor::dumpSummaries
[09:54:41.452] QUIET: Connection to board 33 closed.
[09:54:41.482] INFO: pXar: this is the end, my friend
[09:54:41.482] DEBUG: <PixSetup.cc/~PixSetup:L68> PixSetup free fPxarMemory