[14:55:43.093] INFO: *** Welcome to pxar ***
[14:55:43.093] INFO: *** Today: 2017/02/02
[14:55:43.519] INFO: *** Version: v1.9.0-825-g6bc29
[14:55:43.519] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-5-37_FPIXTest-17C-FNAL-170118-1508-150V_2017-01-18_15h21m_1484774497/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-5-37_FPIXTest-17C-FNAL-170118-1508-150V_2017-01-18_15h21m_1484774497/000_FPIXTest_p17//dacParameters35_C15.dat
[14:55:43.571] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-5-37_FPIXTest-17C-FNAL-170118-1508-150V_2017-01-18_15h21m_1484774497/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-5-37_FPIXTest-17C-FNAL-170118-1508-150V_2017-01-18_15h21m_1484774497/000_FPIXTest_p17//tbmParameters_C0b.dat
[14:55:43.576] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-5-37_FPIXTest-17C-FNAL-170118-1508-150V_2017-01-18_15h21m_1484774497/000_FPIXTest_p17//defaultMaskFile.dat
[14:55:43.579] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-5-37_FPIXTest-17C-FNAL-170118-1508-150V_2017-01-18_15h21m_1484774497/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-5-37_FPIXTest-17C-FNAL-170118-1508-150V_2017-01-18_15h21m_1484774497/000_FPIXTest_p17//trimParameters35_C15.dat
[14:55:43.697] INFO: clk: 4
[14:55:43.697] INFO: ctr: 4
[14:55:43.697] INFO: sda: 19
[14:55:43.697] INFO: tin: 9
[14:55:43.697] INFO: level: 15
[14:55:43.697] INFO: triggerdelay: 0
[14:55:43.697] QUIET: Instanciating API for pxar v1.9.0+825~g6bc290c
[14:55:43.697] INFO: Log level: DEBUG
[14:55:43.715] QUIET: Connection to board DTB_WREKRL opened.
[14:55:43.719] 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:
------------------------------------------------------
[14:55:43.722] INFO: RPC call hashes of host and DTB match: 398089610
[14:55:45.256] INFO: DUT info:
[14:55:45.256] INFO: The DUT currently contains the following objects:
[14:55:45.256] INFO: 2 TBM Cores tbm08c (2 ON)
[14:55:45.256] INFO: TBM Core alpha (0): 7 registers set
[14:55:45.256] INFO: TBM Core beta (1): 7 registers set
[14:55:45.256] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[14:55:45.256] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[14:55:45.256] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[14:55:45.256] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[14:55:45.256] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[14:55:45.256] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[14:55:45.256] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[14:55:45.256] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[14:55:45.256] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[14:55:45.256] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[14:55:45.256] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[14:55:45.256] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[14:55:45.256] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[14:55:45.256] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[14:55:45.256] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[14:55:45.256] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[14:55:45.256] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[14:55:45.257] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->BB<-
[14:55:45.257] DEBUG: <PixTestParameters.cc/dump:L107> dumpall: checkbox(0)
[14:55:45.257] DEBUG: <PixTestParameters.cc/dump:L107> dumpproblematic: checkbox(0)
[14:55:45.257] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 5
[14:55:45.257] DEBUG: <PixTestParameters.cc/dump:L107> vcals: 250
[14:55:45.257] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->BB2<-
[14:55:45.257] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[14:55:45.257] DEBUG: <PixTestParameters.cc/dump:L107> vcals: 222
[14:55:45.257] DEBUG: <PixTestParameters.cc/dump:L107> plwidth: 35
[14:55:45.257] DEBUG: <PixTestParameters.cc/dump:L107> pix: 11,20
[14:55:45.257] DEBUG: <PixTestParameters.cc/dump:L107> targetia: 24
[14:55:45.257] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->BB3<-
[14:55:45.257] DEBUG: <PixTestParameters.cc/dump:L107> dumpall: checkbox(0)
[14:55:45.257] DEBUG: <PixTestParameters.cc/dump:L107> dumpproblematic: checkbox(0)
[14:55:45.257] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 5
[14:55:45.257] DEBUG: <PixTestParameters.cc/dump:L107> vcals: 250
[14:55:45.257] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->BB4<-
[14:55:45.257] DEBUG: <PixTestParameters.cc/dump:L107> savecaldelscan: checkbox(0)
[14:55:45.257] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 100
[14:55:45.257] DEBUG: <PixTestParameters.cc/dump:L107> cals: 1
[14:55:45.257] DEBUG: <PixTestParameters.cc/dump:L107> caldello: 80
[14:55:45.257] DEBUG: <PixTestParameters.cc/dump:L107> caldelhi: 200
[14:55:45.257] DEBUG: <PixTestParameters.cc/dump:L107> caldelstep: 10
[14:55:45.257] DEBUG: <PixTestParameters.cc/dump:L107> vthrcomplo: 70
[14:55:45.257] DEBUG: <PixTestParameters.cc/dump:L107> vthrcomphi: 130
[14:55:45.257] DEBUG: <PixTestParameters.cc/dump:L107> vthrcompstep: 5
[14:55:45.258] DEBUG: <PixTestParameters.cc/dump:L107> noisypixels: 10
[14:55:45.258] DEBUG: <PixTestParameters.cc/dump:L107> vcal: 255
[14:55:45.258] DEBUG: <PixTestParameters.cc/dump:L107> cut: 0.5
[14:55:45.258] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Cmd<-
[14:55:45.258] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->DacDacScan<-
[14:55:45.258] DEBUG: <PixTestParameters.cc/dump:L107> phmap: checkbox
[14:55:45.258] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[14:55:45.258] DEBUG: <PixTestParameters.cc/dump:L107> dac1: caldel
[14:55:45.258] DEBUG: <PixTestParameters.cc/dump:L107> dac1lo: 0
[14:55:45.258] DEBUG: <PixTestParameters.cc/dump:L107> dac1hi: 255
[14:55:45.258] DEBUG: <PixTestParameters.cc/dump:L107> dac2: vthrcomp
[14:55:45.258] DEBUG: <PixTestParameters.cc/dump:L107> dac2lo: 0
[14:55:45.258] DEBUG: <PixTestParameters.cc/dump:L107> dac2hi: 255
[14:55:45.258] DEBUG: <PixTestParameters.cc/dump:L107> pix: 11,20
[14:55:45.258] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->DacScan<-
[14:55:45.258] DEBUG: <PixTestParameters.cc/dump:L107> phmap: checkbox(1)
[14:55:45.258] DEBUG: <PixTestParameters.cc/dump:L107> allpixels: checkbox(0)
[14:55:45.258] DEBUG: <PixTestParameters.cc/dump:L107> unmasked: checkbox(0)
[14:55:45.258] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[14:55:45.258] DEBUG: <PixTestParameters.cc/dump:L107> dac: vcal
[14:55:45.258] DEBUG: <PixTestParameters.cc/dump:L107> daclo: 0
[14:55:45.258] DEBUG: <PixTestParameters.cc/dump:L107> dachi: 255
[14:55:45.258] DEBUG: <PixTestParameters.cc/dump:L107> pix: 11,20
[14:55:45.258] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->GainPedestal<-
[14:55:45.258] DEBUG: <PixTestParameters.cc/dump:L107> showfits: checkbox(0)
[14:55:45.258] DEBUG: <PixTestParameters.cc/dump:L107> extended: checkbox(0)
[14:55:45.258] DEBUG: <PixTestParameters.cc/dump:L107> dumphists: checkbox(0)
[14:55:45.258] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[14:55:45.258] DEBUG: <PixTestParameters.cc/dump:L107> vcalstep: 10
[14:55:45.258] DEBUG: <PixTestParameters.cc/dump:L107> measure: button
[14:55:45.258] DEBUG: <PixTestParameters.cc/dump:L107> fit: button
[14:55:45.258] DEBUG: <PixTestParameters.cc/dump:L107> save: button
[14:55:45.258] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->HighRate<-
[14:55:45.258] DEBUG: <PixTestParameters.cc/dump:L107> pix: 11,20
[14:55:45.258] DEBUG: <PixTestParameters.cc/dump:L107> trimhotpixels: button
[14:55:45.258] DEBUG: <PixTestParameters.cc/dump:L107> trimhotpixelthr: 200
[14:55:45.258] DEBUG: <PixTestParameters.cc/dump:L107> runsecondshotpixels: 10
[14:55:45.258] DEBUG: <PixTestParameters.cc/dump:L107> savetrimbits: checkbox(1)
[14:55:45.258] DEBUG: <PixTestParameters.cc/dump:L107> maskuntrimmable: checkbox(1)
[14:55:45.258] DEBUG: <PixTestParameters.cc/dump:L107> maskhotpixels: button
[14:55:45.258] DEBUG: <PixTestParameters.cc/dump:L107> savemaskfile: checkbox(0)
[14:55:45.259] DEBUG: <PixTestParameters.cc/dump:L107> maskfilename: default
[14:55:45.259] DEBUG: <PixTestParameters.cc/dump:L107> caldelscan: button
[14:55:45.259] DEBUG: <PixTestParameters.cc/dump:L107> xpixelalive: button
[14:55:45.259] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 50
[14:55:45.259] DEBUG: <PixTestParameters.cc/dump:L107> vcal: 200
[14:55:45.259] DEBUG: <PixTestParameters.cc/dump:L107> xnoisemaps: button
[14:55:45.259] DEBUG: <PixTestParameters.cc/dump:L107> daclo: 0
[14:55:45.259] DEBUG: <PixTestParameters.cc/dump:L107> dachi: 100
[14:55:45.259] DEBUG: <PixTestParameters.cc/dump:L107> dacs/step: 20
[14:55:45.259] DEBUG: <PixTestParameters.cc/dump:L107> rundaq: button
[14:55:45.259] DEBUG: <PixTestParameters.cc/dump:L107> trgfrequency(khz): 20
[14:55:45.259] DEBUG: <PixTestParameters.cc/dump:L107> runseconds: 2
[14:55:45.259] DEBUG: <PixTestParameters.cc/dump:L107> triggerdelay: 20
[14:55:45.259] DEBUG: <PixTestParameters.cc/dump:L107> delaytbm: checkbox
[14:55:45.259] DEBUG: <PixTestParameters.cc/dump:L107> filltree: checkbox
[14:55:45.259] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->IV<-
[14:55:45.259] DEBUG: <PixTestParameters.cc/dump:L107> port: /dev/FIXME
[14:55:45.259] DEBUG: <PixTestParameters.cc/dump:L107> voltagestart: 0
[14:55:45.259] DEBUG: <PixTestParameters.cc/dump:L107> voltagestop: 600
[14:55:45.259] DEBUG: <PixTestParameters.cc/dump:L107> voltagestep: 5
[14:55:45.259] DEBUG: <PixTestParameters.cc/dump:L107> delay: 1
[14:55:45.259] DEBUG: <PixTestParameters.cc/dump:L107> compliance(ua): 100
[14:55:45.259] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->PhOptimization<-
[14:55:45.259] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[14:55:45.259] DEBUG: <PixTestParameters.cc/dump:L107> safetymarginlow: 20
[14:55:45.259] DEBUG: <PixTestParameters.cc/dump:L107> saturationvcal: 100
[14:55:45.259] DEBUG: <PixTestParameters.cc/dump:L107> quantilesaturation: 0.98
[14:55:45.259] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->PixelAlive<-
[14:55:45.259] DEBUG: <PixTestParameters.cc/dump:L107> phmap: checkbox(0)
[14:55:45.259] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10
[14:55:45.259] DEBUG: <PixTestParameters.cc/dump:L107> vcal: 200
[14:55:45.259] DEBUG: <PixTestParameters.cc/dump:L107> alivetest: button
[14:55:45.259] DEBUG: <PixTestParameters.cc/dump:L107> masktest: button
[14:55:45.259] DEBUG: <PixTestParameters.cc/dump:L107> addressdecodingtest: button
[14:55:45.259] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Pretest<-
[14:55:45.259] DEBUG: <PixTestParameters.cc/dump:L107> programroc: button
[14:55:45.259] DEBUG: <PixTestParameters.cc/dump:L107> checkidig: button
[14:55:45.259] DEBUG: <PixTestParameters.cc/dump:L107> targetia: 24
[14:55:45.259] DEBUG: <PixTestParameters.cc/dump:L107> setvana: button
[14:55:45.259] DEBUG: <PixTestParameters.cc/dump:L107> iterations: 100
[14:55:45.259] DEBUG: <PixTestParameters.cc/dump:L107> settimings: button
[14:55:45.259] DEBUG: <PixTestParameters.cc/dump:L107> findtiming: button
[14:55:45.259] DEBUG: <PixTestParameters.cc/dump:L107> findworkingpixel: button
[14:55:45.259] DEBUG: <PixTestParameters.cc/dump:L107> setvthrcompcaldel: button
[14:55:45.260] DEBUG: <PixTestParameters.cc/dump:L107> pix: 11,20
[14:55:45.260] DEBUG: <PixTestParameters.cc/dump:L107> vcal: 250
[14:55:45.260] DEBUG: <PixTestParameters.cc/dump:L107> deltavthrcomp: 50
[14:55:45.260] DEBUG: <PixTestParameters.cc/dump:L107> fraccaldel: 0.5
[14:55:45.260] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 5
[14:55:45.260] DEBUG: <PixTestParameters.cc/dump:L107> savedacs: button
[14:55:45.260] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Readback<-
[14:55:45.260] DEBUG: <PixTestParameters.cc/dump:L107> calibratevd: button
[14:55:45.260] DEBUG: <PixTestParameters.cc/dump:L107> calibrateva: button
[14:55:45.260] DEBUG: <PixTestParameters.cc/dump:L107> calibrateia: button
[14:55:45.260] DEBUG: <PixTestParameters.cc/dump:L107> readbackvbg: button
[14:55:45.260] DEBUG: <PixTestParameters.cc/dump:L107> getcalibratedvbg: button
[14:55:45.260] DEBUG: <PixTestParameters.cc/dump:L107> usecalvd: checkbox(1)
[14:55:45.260] DEBUG: <PixTestParameters.cc/dump:L107> usecalva: checkbox(0)
[14:55:45.260] DEBUG: <PixTestParameters.cc/dump:L107> setvana: button
[14:55:45.260] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Scurves<-
[14:55:45.260] DEBUG: <PixTestParameters.cc/dump:L107> adjustvcal: checkbox(0)
[14:55:45.260] DEBUG: <PixTestParameters.cc/dump:L107> dumpall: checkbox(0)
[14:55:45.260] DEBUG: <PixTestParameters.cc/dump:L107> dumpproblematic: checkbox(0)
[14:55:45.260] DEBUG: <PixTestParameters.cc/dump:L107> dumpoutputfile: checkbox(0)
[14:55:45.260] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 50
[14:55:45.260] DEBUG: <PixTestParameters.cc/dump:L107> dac: Vcal
[14:55:45.260] DEBUG: <PixTestParameters.cc/dump:L107> daclo: 0
[14:55:45.260] DEBUG: <PixTestParameters.cc/dump:L107> dachi: 200
[14:55:45.260] DEBUG: <PixTestParameters.cc/dump:L107> dacs/step: -1
[14:55:45.260] DEBUG: <PixTestParameters.cc/dump:L107> ntrig/step: -1
[14:55:45.260] DEBUG: <PixTestParameters.cc/dump:L107> scurves: button
[14:55:45.260] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Timing<-
[14:55:45.260] DEBUG: <PixTestParameters.cc/dump:L107> targetclk: 4
[14:55:45.260] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 10000
[14:55:45.260] DEBUG: <PixTestParameters.cc/dump:L107> clocksdascan: button
[14:55:45.260] DEBUG: <PixTestParameters.cc/dump:L107> notokenpass: checkbox(0)
[14:55:45.260] DEBUG: <PixTestParameters.cc/dump:L107> ignorereadback: checkbox(0)
[14:55:45.260] DEBUG: <PixTestParameters.cc/dump:L107> phasescan: button
[14:55:45.260] DEBUG: <PixTestParameters.cc/dump:L107> levelscan: button
[14:55:45.260] DEBUG: <PixTestParameters.cc/dump:L107> tbmphasescan: button
[14:55:45.260] DEBUG: <PixTestParameters.cc/dump:L107> rocdelayscan: button
[14:55:45.260] DEBUG: <PixTestParameters.cc/dump:L107> timingtest: button
[14:55:45.260] DEBUG: <PixTestParameters.cc/dump:L107> saveparameters: button
[14:55:45.260] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Trim<-
[14:55:45.260] DEBUG: <PixTestParameters.cc/dump:L107> trim: button
[14:55:45.260] DEBUG: <PixTestParameters.cc/dump:L107> ntrig: 8
[14:55:45.260] DEBUG: <PixTestParameters.cc/dump:L107> vcal: 35
[14:55:45.260] DEBUG: <PixTestParameters.cc/dump:L107> trimbits: button
[14:55:45.260] DEBUG: <PixTestParameters.cc/dump:L104> PixTestParameters: ->Xray<-
[14:55:45.261] DEBUG: <PixTestParameters.cc/dump:L107> maskhotpixels: button
[14:55:45.261] DEBUG: <PixTestParameters.cc/dump:L107> savemaskfile: checkbox(0)
[14:55:45.261] DEBUG: <PixTestParameters.cc/dump:L107> maskfilename: default
[14:55:45.261] DEBUG: <PixTestParameters.cc/dump:L107> source: Ag
[14:55:45.261] DEBUG: <PixTestParameters.cc/dump:L107> phrun: button
[14:55:45.261] DEBUG: <PixTestParameters.cc/dump:L107> runseconds: 100
[14:55:45.261] DEBUG: <PixTestParameters.cc/dump:L107> trgfrequency(khz): 100
[14:55:45.261] DEBUG: <PixTestParameters.cc/dump:L107> ratescan: button
[14:55:45.261] DEBUG: <PixTestParameters.cc/dump:L107> vthrcompmin: 10
[14:55:45.261] DEBUG: <PixTestParameters.cc/dump:L107> vthrcompmax: 80
[14:55:45.261] DEBUG: <PixTestParameters.cc/dump:L107> stepseconds: 5
[14:55:45.261] DEBUG: <PixTestParameters.cc/dump:L107> delaytbm: checkbox
[14:55:45.261] DEBUG: <PixTestParameters.cc/dump:L107> filltree: checkbox
[14:55:45.263] DEBUG: <PixSetup.cc/init:L81> PixSetup init start; getCurrentRSS() = 29052928
[14:55:45.263] DEBUG: <PixSetup.cc/init:L87> fPixTestParameters = 0xd4a220
[14:55:45.263] DEBUG: <PixSetup.cc/init:L88> fConfigParameters = 0xc70310
[14:55:45.263] DEBUG: <PixSetup.cc/init:L89> fPxarMemory = 0x7f1369d94010
[14:55:45.263] DEBUG: <PixSetup.cc/init:L90> fPxarMemHi = 0x7f136ffff510
[14:55:45.263] DEBUG: <PixSetup.cc/init:L106> PixSetup init done; getCurrentRSS() = 29118464 fPxarMemory = 0x7f1369d94010
[14:55:45.268] DEBUG: <pXar.cc/main:L223> Initial Analog Current: 381mA
[14:55:45.269] DEBUG: <pXar.cc/main:L224> Initial Digital Current: 463.1mA
[14:55:45.269] DEBUG: <pXar.cc/main:L225> Initial Module Temperature: 1.5 C
[14:55:45.269] DEBUG: <PixTestFactory.cc/PixTestFactory:L53> PixTestFactory::PixTestFactory()
[14:55:45.670] INFO: enter 'restricted' command line mode
[14:55:45.670] INFO: enter test to run
[14:55:50.141] INFO: test: PixelAlive no parameter change
[14:55:50.141] INFO: running: pixelalive
[14:55:50.141] DEBUG: <PixTestAlive.cc/init:L83> PixTestAlive::init()
[14:55:50.145] DEBUG: <PixTestAlive.cc/PixTestAlive:L21> PixTestAlive ctor(PixSetup &a, string, TGTab *)
[14:55:50.145] DEBUG: <PixTestAlive.cc/runCommand:L62> running command: alivetest
[14:55:50.149] INFO: ----------------------------------------------------------------------
[14:55:50.150] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[14:55:50.150] INFO: ----------------------------------------------------------------------
[14:55:50.152] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[14:55:50.466] INFO: Expecting 41600 events.
[14:55:54.817] INFO: 41600 events read in total (3632ms).
[14:55:54.979] INFO: Test took 4827ms.
[14:55:54.993] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:55:54.993] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 66557
[14:55:54.994] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists PixelAlive_C0 .. PixelAlive_C15
[14:55:55.255] INFO: PixTestAlive::aliveTest() done
[14:55:55.255] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 1 0 0 0 0 2 0
[14:55:55.255] DEBUG: <PixTestAlive.cc/aliveTest:L199> number of red-efficiency pixels: 0 0 0 0 0 0 0 0 0 1 0 0 1 0 2 0
[14:55:55.255] DEBUG: <PixTestAlive.cc/~PixTestAlive:L115> PixTestAlive dtor
[14:55:55.295] INFO: enter test to run
[14:56:21.988] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[14:56:21.989] DEBUG: <PixTestParameters.cc/setTestParameter:L119> PixTestParameters: ->Xray<-
[14:56:21.989] DEBUG: <PixTestParameters.cc/setTestParameter:L124> setting source to new value DCLowRate
[14:56:21.989] INFO: running: xray
[14:56:21.989] DEBUG: <PixTestXray.cc/init:L135> PixTestXray::init()
[14:56:21.989] DEBUG: <PixTestXray.cc/PixTestXray:L28> PixTestXray ctor(PixSetup &a, string, TGTab *)
[14:56:21.989] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-5-37_FPIXTest-17C-FNAL-170118-1508-150V_2017-01-18_15h21m_1484774497/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-5-37_FPIXTest-17C-FNAL-170118-1508-150V_2017-01-18_15h21m_1484774497/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[14:56:22.241] DEBUG: <PixTestXray.cc/runCommand:L109> running command: phrun
[14:56:22.241] INFO: ----------------------------------------------------------------------
[14:56:22.241] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:56:22.241] INFO: ----------------------------------------------------------------------
[14:56:23.207] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:56:34.579] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[14:56:34.583] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[14:56:59.656] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 1120429 events.
[14:57:03.780] DEBUG: <PixTestXray.cc/processData:L823> # events read: 1120429, pixels seen in all events: 6806167
[14:57:03.909] INFO: Resuming triggers.
[14:57:15.283] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[14:57:15.286] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[14:57:39.906] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 1120514 events.
[14:57:44.554] DEBUG: <PixTestXray.cc/processData:L823> # events read: 1120514, pixels seen in all events: 6805052
[14:57:44.583] INFO: Resuming triggers.
[14:57:55.956] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[14:57:55.960] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[14:58:20.346] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 1120430 events.
[14:58:24.414] DEBUG: <PixTestXray.cc/processData:L823> # events read: 1120430, pixels seen in all events: 6805871
[14:58:24.493] INFO: Resuming triggers.
[14:58:35.866] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[14:58:35.869] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[14:59:00.928] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 1120367 events.
[14:59:05.163] DEBUG: <PixTestXray.cc/processData:L823> # events read: 1120367, pixels seen in all events: 6806980
[14:59:05.199] INFO: Resuming triggers.
[14:59:16.569] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[14:59:16.626] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[14:59:42.663] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 1120112 events.
[14:59:46.778] DEBUG: <PixTestXray.cc/processData:L823> # events read: 1120112, pixels seen in all events: 6810080
[14:59:46.808] INFO: Resuming triggers.
[14:59:58.175] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[14:59:58.231] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[15:00:24.647] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 1119787 events.
[15:00:28.514] DEBUG: <PixTestXray.cc/processData:L823> # events read: 1119787, pixels seen in all events: 6813895
[15:00:28.544] INFO: Resuming triggers.
[15:00:39.911] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[15:00:39.971] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[15:01:06.648] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 1119859 events.
[15:01:10.404] DEBUG: <PixTestXray.cc/processData:L823> # events read: 1119859, pixels seen in all events: 6812916
[15:01:10.530] INFO: Resuming triggers.
[15:01:21.904] INFO: run duration 90 seconds, buffer almost full (81%), pausing triggers.
[15:01:21.908] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[15:01:48.803] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 1120516 events.
[15:01:52.597] DEBUG: <PixTestXray.cc/processData:L823> # events read: 1120516, pixels seen in all events: 6805278
[15:01:52.674] INFO: Resuming triggers.
[15:02:02.069] INFO: data taking finished, elapsed time: 100 seconds.
[15:02:02.265] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[15:02:23.681] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 925577 events.
[15:02:26.786] DEBUG: <PixTestXray.cc/processData:L823> # events read: 925577, pixels seen in all events: 5624271
[15:02:26.812] INFO: PixTest:: pg_setup set to default.
[15:02:26.815] INFO: PixTestXray::doPhRun() done
[15:02:26.815] DEBUG: <PixTestXray.cc/~PixTestXray:L218> PixTestXray dtor
[15:02:27.022] INFO: enter test to run
[15:03:19.298] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[15:03:19.298] DEBUG: <PixTestParameters.cc/setTestParameter:L119> PixTestParameters: ->Xray<-
[15:03:19.298] DEBUG: <PixTestParameters.cc/setTestParameter:L124> setting source to new value DCHighRate
[15:03:19.298] INFO: running: xray
[15:03:19.298] DEBUG: <PixTestXray.cc/init:L135> PixTestXray::init()
[15:03:19.298] DEBUG: <PixTestXray.cc/PixTestXray:L28> PixTestXray ctor(PixSetup &a, string, TGTab *)
[15:03:19.299] DEBUG: <PixTestXray.cc/runCommand:L109> running command: phrun
[15:03:19.299] INFO: ----------------------------------------------------------------------
[15:03:19.299] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:03:19.299] INFO: ----------------------------------------------------------------------
[15:03:20.264] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:03:26.967] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[15:03:26.970] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[15:03:50.753] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 660439 events.
[15:03:57.555] DEBUG: <PixTestXray.cc/processData:L823> # events read: 660439, pixels seen in all events: 12327533
[15:03:57.601] INFO: Resuming triggers.
[15:04:04.306] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[15:04:04.309] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[15:04:28.116] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 660481 events.
[15:04:34.767] DEBUG: <PixTestXray.cc/processData:L823> # events read: 660481, pixels seen in all events: 12327041
[15:04:34.817] INFO: Resuming triggers.
[15:04:41.521] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[15:04:41.524] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[15:05:05.270] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 660438 events.
[15:05:11.892] DEBUG: <PixTestXray.cc/processData:L823> # events read: 660438, pixels seen in all events: 12326299
[15:05:11.941] INFO: Resuming triggers.
[15:05:18.647] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[15:05:18.651] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[15:05:42.460] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 660633 events.
[15:05:49.134] DEBUG: <PixTestXray.cc/processData:L823> # events read: 660633, pixels seen in all events: 12325311
[15:05:49.182] INFO: Resuming triggers.
[15:05:55.891] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[15:05:55.894] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[15:06:19.636] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 660903 events.
[15:06:26.227] DEBUG: <PixTestXray.cc/processData:L823> # events read: 660903, pixels seen in all events: 12321780
[15:06:26.274] INFO: Resuming triggers.
[15:06:32.978] INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[15:06:32.981] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[15:06:56.706] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 660438 events.
[15:07:03.478] DEBUG: <PixTestXray.cc/processData:L823> # events read: 660438, pixels seen in all events: 12326447
[15:07:03.527] INFO: Resuming triggers.
[15:07:10.231] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[15:07:10.234] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[15:07:34.022] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 660464 events.
[15:07:40.676] DEBUG: <PixTestXray.cc/processData:L823> # events read: 660464, pixels seen in all events: 12326548
[15:07:40.731] INFO: Resuming triggers.
[15:07:47.438] INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[15:07:47.441] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[15:08:11.151] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 660699 events.
[15:08:17.645] DEBUG: <PixTestXray.cc/processData:L823> # events read: 660699, pixels seen in all events: 12323981
[15:08:17.694] INFO: Resuming triggers.
[15:08:24.398] INFO: run duration 60 seconds, buffer almost full (81%), pausing triggers.
[15:08:24.401] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[15:08:48.144] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 660429 events.
[15:08:54.777] DEBUG: <PixTestXray.cc/processData:L823> # events read: 660429, pixels seen in all events: 12326973
[15:08:54.827] INFO: Resuming triggers.
[15:09:01.530] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[15:09:01.533] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[15:09:25.680] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 660313 events.
[15:09:33.071] DEBUG: <PixTestXray.cc/processData:L823> # events read: 660313, pixels seen in all events: 12327796
[15:09:33.128] INFO: Resuming triggers.
[15:09:39.832] INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[15:09:39.836] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[15:10:03.700] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 660437 events.
[15:10:10.502] DEBUG: <PixTestXray.cc/processData:L823> # events read: 660437, pixels seen in all events: 12327108
[15:10:10.553] INFO: Resuming triggers.
[15:10:17.258] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[15:10:17.261] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[15:10:41.163] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 660484 events.
[15:10:48.075] DEBUG: <PixTestXray.cc/processData:L823> # events read: 660484, pixels seen in all events: 12326943
[15:10:48.135] INFO: Resuming triggers.
[15:10:54.838] INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[15:10:54.841] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[15:11:18.832] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 660337 events.
[15:11:25.945] DEBUG: <PixTestXray.cc/processData:L823> # events read: 660337, pixels seen in all events: 12328348
[15:11:26.009] INFO: Resuming triggers.
[15:11:32.712] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[15:11:32.716] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[15:11:56.612] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 660381 events.
[15:12:04.086] DEBUG: <PixTestXray.cc/processData:L823> # events read: 660381, pixels seen in all events: 12327788
[15:12:04.150] INFO: Resuming triggers.
[15:12:10.629] INFO: data taking finished, elapsed time: 100 seconds.
[15:12:10.824] DEBUG: <PixTestXray.cc/processData:L754> Getting Event Buffer
[15:12:33.645] DEBUG: <PixTestXray.cc/processData:L772> Processing Data: 638197 events.
[15:12:40.358] DEBUG: <PixTestXray.cc/processData:L823> # events read: 638197, pixels seen in all events: 11921249
[15:12:40.418] INFO: PixTest:: pg_setup set to default.
[15:12:40.421] INFO: PixTestXray::doPhRun() done
[15:12:40.421] DEBUG: <PixTestXray.cc/~PixTestXray:L218> PixTestXray dtor
[15:12:40.573] INFO: enter test to run
[15:14:46.645] INFO: test: HighRate no parameter change
[15:14:46.645] INFO: running: highrate
[15:14:46.661] DEBUG: <PixTestHighRate.cc/setParameter:L68> setting fParTriggerFrequency -> 20
[15:14:46.662] DEBUG: <PixTestHighRate.cc/init:L211> PixTestHighRate::init()
[15:14:46.662] DEBUG: <PixTestHighRate.cc/PixTestHighRate:L31> PixTestHighRate ctor(PixSetup &a, string, TGTab *)
[15:14:46.663] DEBUG: <PixTestHighRate.cc/runCommand:L165> running command: caldelscan
[15:14:46.663] INFO: ----------------------------------------------------------------------
[15:14:46.663] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[15:14:46.663] INFO: ----------------------------------------------------------------------
[15:14:46.814] INFO: Expecting 768 events.
[15:14:47.947] INFO: 768 events read in total (418ms).
[15:14:47.948] INFO: Test took 1269ms.
[15:14:47.961] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[15:14:48.750] INFO: Expecting 41600 events.
[15:14:52.557] INFO: 41600 events read in total (3280ms).
[15:14:52.560] INFO: Test took 4599ms.
[15:14:52.653] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:14:52.653] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 839614
[15:14:52.653] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step0_C0 .. HR_xeff_CalDelScan_step0_C15
[15:14:52.653] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[15:14:52.691] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[15:14:53.304] INFO: Expecting 41600 events.
[15:14:57.214] INFO: 41600 events read in total (3384ms).
[15:14:57.217] INFO: Test took 4526ms.
[15:14:57.311] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:14:57.311] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 850107
[15:14:57.311] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step1_C0 .. HR_xeff_CalDelScan_step1_C15
[15:14:57.311] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[15:14:57.348] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[15:14:57.961] INFO: Expecting 41600 events.
[15:15:01.980] INFO: 41600 events read in total (3492ms).
[15:15:01.982] INFO: Test took 4634ms.
[15:15:02.077] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:15:02.077] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 853871
[15:15:02.077] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step2_C0 .. HR_xeff_CalDelScan_step2_C15
[15:15:02.078] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[15:15:02.115] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[15:15:02.728] INFO: Expecting 41600 events.
[15:15:06.609] INFO: 41600 events read in total (3354ms).
[15:15:06.612] INFO: Test took 4497ms.
[15:15:06.707] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:15:06.707] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 854056
[15:15:06.707] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step3_C0 .. HR_xeff_CalDelScan_step3_C15
[15:15:06.708] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[15:15:06.746] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[15:15:07.358] INFO: Expecting 41600 events.
[15:15:11.275] INFO: 41600 events read in total (3390ms).
[15:15:11.278] INFO: Test took 4532ms.
[15:15:11.370] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:15:11.370] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 854615
[15:15:11.370] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step4_C0 .. HR_xeff_CalDelScan_step4_C15
[15:15:11.370] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[15:15:11.409] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[15:15:12.021] INFO: Expecting 41600 events.
[15:15:15.945] INFO: 41600 events read in total (3397ms).
[15:15:15.947] INFO: Test took 4538ms.
[15:15:16.040] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:15:16.040] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 853337
[15:15:16.040] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step5_C0 .. HR_xeff_CalDelScan_step5_C15
[15:15:16.040] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[15:15:16.078] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[15:15:16.690] INFO: Expecting 41600 events.
[15:15:20.641] INFO: 41600 events read in total (3424ms).
[15:15:20.643] INFO: Test took 4565ms.
[15:15:20.737] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:15:20.737] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 854998
[15:15:20.737] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step6_C0 .. HR_xeff_CalDelScan_step6_C15
[15:15:20.737] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[15:15:20.775] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[15:15:21.389] INFO: Expecting 41600 events.
[15:15:25.290] INFO: 41600 events read in total (3375ms).
[15:15:25.292] INFO: Test took 4516ms.
[15:15:25.388] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:15:25.388] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 855004
[15:15:25.388] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step7_C0 .. HR_xeff_CalDelScan_step7_C15
[15:15:25.389] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[15:15:25.426] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[15:15:26.038] INFO: Expecting 41600 events.
[15:15:30.059] INFO: 41600 events read in total (3494ms).
[15:15:30.061] INFO: Test took 4635ms.
[15:15:30.157] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:15:30.157] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 855226
[15:15:30.157] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step8_C0 .. HR_xeff_CalDelScan_step8_C15
[15:15:30.157] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[15:15:30.197] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[15:15:30.808] INFO: Expecting 41600 events.
[15:15:34.843] INFO: 41600 events read in total (3508ms).
[15:15:34.845] INFO: Test took 4648ms.
[15:15:34.938] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:15:34.938] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 854688
[15:15:34.938] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step9_C0 .. HR_xeff_CalDelScan_step9_C15
[15:15:34.939] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[15:15:34.976] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[15:15:35.589] INFO: Expecting 41600 events.
[15:15:39.623] INFO: 41600 events read in total (3507ms).
[15:15:39.625] INFO: Test took 4649ms.
[15:15:39.720] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:15:39.720] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 855663
[15:15:39.720] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step10_C0 .. HR_xeff_CalDelScan_step10_C15
[15:15:39.721] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[15:15:39.759] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[15:15:40.371] INFO: Expecting 41600 events.
[15:15:44.363] INFO: 41600 events read in total (3465ms).
[15:15:44.365] INFO: Test took 4606ms.
[15:15:44.460] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:15:44.460] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 853845
[15:15:44.460] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step11_C0 .. HR_xeff_CalDelScan_step11_C15
[15:15:44.460] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[15:15:44.499] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[15:15:45.112] INFO: Expecting 41600 events.
[15:15:49.102] INFO: 41600 events read in total (3463ms).
[15:15:49.104] INFO: Test took 4605ms.
[15:15:49.199] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:15:49.199] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 853525
[15:15:49.199] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step12_C0 .. HR_xeff_CalDelScan_step12_C15
[15:15:49.200] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[15:15:49.238] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[15:15:49.851] INFO: Expecting 41600 events.
[15:15:53.854] INFO: 41600 events read in total (3477ms).
[15:15:53.857] INFO: Test took 4619ms.
[15:15:53.952] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:15:53.952] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 855072
[15:15:53.952] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step13_C0 .. HR_xeff_CalDelScan_step13_C15
[15:15:53.952] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[15:15:53.990] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[15:15:54.602] INFO: Expecting 41600 events.
[15:15:58.484] INFO: 41600 events read in total (3355ms).
[15:15:58.486] INFO: Test took 4496ms.
[15:15:58.577] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:15:58.577] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 855572
[15:15:58.577] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step14_C0 .. HR_xeff_CalDelScan_step14_C15
[15:15:58.577] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[15:15:58.616] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[15:15:59.228] INFO: Expecting 41600 events.
[15:16:03.089] INFO: 41600 events read in total (3334ms).
[15:16:03.091] INFO: Test took 4475ms.
[15:16:03.183] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:16:03.183] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 854834
[15:16:03.183] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step15_C0 .. HR_xeff_CalDelScan_step15_C15
[15:16:03.183] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[15:16:03.221] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[15:16:03.832] INFO: Expecting 41600 events.
[15:16:07.688] INFO: 41600 events read in total (3329ms).
[15:16:07.690] INFO: Test took 4469ms.
[15:16:07.783] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:16:07.783] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 854367
[15:16:07.783] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step16_C0 .. HR_xeff_CalDelScan_step16_C15
[15:16:07.783] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[15:16:07.822] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[15:16:08.434] INFO: Expecting 41600 events.
[15:16:12.284] INFO: 41600 events read in total (3323ms).
[15:16:12.286] INFO: Test took 4464ms.
[15:16:12.377] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:16:12.377] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 854268
[15:16:12.377] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step17_C0 .. HR_xeff_CalDelScan_step17_C15
[15:16:12.378] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[15:16:12.417] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[15:16:13.028] INFO: Expecting 41600 events.
[15:16:16.781] INFO: 41600 events read in total (3226ms).
[15:16:16.783] INFO: Test took 4366ms.
[15:16:16.874] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:16:16.875] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 852902
[15:16:16.875] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step18_C0 .. HR_xeff_CalDelScan_step18_C15
[15:16:16.875] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[15:16:16.913] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[15:16:17.525] INFO: Expecting 41600 events.
[15:16:21.169] INFO: 41600 events read in total (3117ms).
[15:16:21.171] INFO: Test took 4258ms.
[15:16:21.261] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:16:21.261] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 846637
[15:16:21.261] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists HR_xeff_CalDelScan_step19_C0 .. HR_xeff_CalDelScan_step19_C15
[15:16:21.261] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[15:16:21.519] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 0: caldel = 179 eff = 0.997909
[15:16:21.519] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 1: caldel = 161 eff = 0.999183
[15:16:21.520] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 2: caldel = 171 eff = 0.998077
[15:16:21.520] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 3: caldel = 175 eff = 0.99649
[15:16:21.520] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 4: caldel = 178 eff = 0.996274
[15:16:21.520] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 5: caldel = 162 eff = 0.995673
[15:16:21.521] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 6: caldel = 158 eff = 0.995986
[15:16:21.521] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 7: caldel = 172 eff = 0.997188
[15:16:21.521] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 8: caldel = 173 eff = 0.996659
[15:16:21.521] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 9: caldel = 147 eff = 0.995
[15:16:21.522] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 10: caldel = 156 eff = 0.996058
[15:16:21.522] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 11: caldel = 149 eff = 0.996851
[15:16:21.522] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 12: caldel = 158 eff = 0.996971
[15:16:21.522] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 13: caldel = 157 eff = 0.997813
[15:16:21.523] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 14: caldel = 174 eff = 0.999183
[15:16:21.523] DEBUG: <PixTestHighRate.cc/doCalDelScan:L435> roc 15: caldel = 162 eff = 0.999591
[15:16:21.527] DEBUG: <PixTestHighRate.cc/~PixTestHighRate:L258> PixTestHighRate dtor
[15:16:21.547] INFO: enter test to run
[15:16:36.500] INFO: test: HighRate no parameter change
[15:16:36.500] INFO: running: highrate
[15:16:36.500] DEBUG: <PixTestHighRate.cc/setParameter:L68> setting fParTriggerFrequency -> 20
[15:16:36.500] DEBUG: <PixTestHighRate.cc/init:L211> PixTestHighRate::init()
[15:16:36.500] DEBUG: <PixTestHighRate.cc/PixTestHighRate:L31> PixTestHighRate ctor(PixSetup &a, string, TGTab *)
[15:16:36.501] DEBUG: <PixTestHighRate.cc/runCommand:L165> running command: xpixelalive
[15:16:36.501] INFO: ----------------------------------------------------------------------
[15:16:36.501] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:16:36.502] INFO: ----------------------------------------------------------------------
[15:16:36.502] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: clk: 4
[15:16:36.502] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: ctr: 4
[15:16:36.502] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: sda: 19
[15:16:36.502] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: tin: 9
[15:16:36.502] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: level: 15
[15:16:36.502] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: triggerdelay: 0
[15:16:36.502] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: clk: 4
[15:16:36.502] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: ctr: 4
[15:16:36.502] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: sda: 19
[15:16:36.502] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: tin: 9
[15:16:36.502] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: level: 15
[15:16:36.502] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: triggerdelay: 20
[15:16:36.511] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[15:16:37.120] INFO: Expecting 208000 events.
[15:16:52.628] INFO: 208000 events read in total (14981ms).
[15:16:52.635] INFO: Test took 16124ms.
[15:16:53.074] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:16:53.074] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 3957264
[15:16:53.074] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists highRate_C0 .. highRate_C15
[15:16:53.074] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[15:16:53.420] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 1 0 0 0 0 2 0
[15:16:53.420] INFO: number of red-efficiency pixels: 380 143 395 722 730 766 748 514 557 863 772 618 583 392 86 88
[15:16:53.420] INFO: number of X-ray hits detected: 210287 116094 190069 298977 315902 335614 323849 250937 273724 335758 327892 279509 296276 184080 71147 80592
[15:16:53.420] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:16:53.420] INFO: number of Vcal hits detected: 207555 207843 207541 207167 207172 207088 207136 207421 207381 206941 207092 207272 207327 207537 207813 207912
[15:16:53.420] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.8 99.6 99.6 99.6 99.6 99.7 99.7 99.6 99.6 99.7 99.7 99.8 100.0 100.0
[15:16:53.420] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.8 99.6 99.6 99.6 99.6 99.7 99.7 99.5 99.6 99.7 99.7 99.8 99.9 100.0
[15:16:53.420] INFO: X-ray hit rate [MHz/cm2]: 61.6 34.0 55.7 87.6 92.6 98.4 94.9 73.6 80.2 98.4 96.1 81.9 86.8 54.0 20.9 23.6
[15:16:53.420] INFO: PixTestHighRate::doXPixelAlive() done
[15:16:53.473] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: clk: 4
[15:16:53.473] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: ctr: 4
[15:16:53.473] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: sda: 19
[15:16:53.473] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: tin: 9
[15:16:53.473] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: level: 15
[15:16:53.473] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: triggerdelay: 0
[15:16:53.473] INFO: PixTest:: pg_setup set to default.
[15:16:53.473] DEBUG: <PixTestHighRate.cc/~PixTestHighRate:L258> PixTestHighRate dtor
[15:16:53.487] INFO: enter test to run
[15:17:28.252] INFO: test: HighRate no parameter change
[15:17:28.252] INFO: running: highrate
[15:17:28.253] DEBUG: <PixTestHighRate.cc/setParameter:L68> setting fParTriggerFrequency -> 20
[15:17:28.253] DEBUG: <PixTestHighRate.cc/init:L211> PixTestHighRate::init()
[15:17:28.253] DEBUG: <PixTestHighRate.cc/PixTestHighRate:L31> PixTestHighRate ctor(PixSetup &a, string, TGTab *)
[15:17:28.254] DEBUG: <PixTestHighRate.cc/runCommand:L165> running command: xpixelalive
[15:17:28.254] INFO: ----------------------------------------------------------------------
[15:17:28.254] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:17:28.254] INFO: ----------------------------------------------------------------------
[15:17:28.254] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: clk: 4
[15:17:28.254] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: ctr: 4
[15:17:28.254] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: sda: 19
[15:17:28.254] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: tin: 9
[15:17:28.254] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: level: 15
[15:17:28.254] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: triggerdelay: 0
[15:17:28.254] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: clk: 4
[15:17:28.254] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: ctr: 4
[15:17:28.254] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: sda: 19
[15:17:28.254] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: tin: 9
[15:17:28.254] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: level: 15
[15:17:28.254] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: triggerdelay: 20
[15:17:28.261] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[15:17:28.864] INFO: Expecting 208000 events.
[15:17:40.508] INFO: 208000 events read in total (11117ms).
[15:17:40.511] INFO: Test took 12250ms.
[15:17:40.645] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:17:40.645] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 1189583
[15:17:40.645] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists highRate_C0 .. highRate_C15
[15:17:40.645] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[15:17:40.892] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 1 0 0 0 0 2 0
[15:17:40.892] INFO: number of red-efficiency pixels: 69 40 60 87 95 123 83 63 83 111 101 89 77 72 30 31
[15:17:40.892] INFO: number of X-ray hits detected: 60822 33310 55194 86429 91315 96333 92944 72317 78712 97288 94880 80441 86826 52976 20424 22815
[15:17:40.892] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:17:40.892] INFO: number of Vcal hits detected: 207929 207960 207939 207912 207903 207875 207917 207937 207917 207839 207895 207908 207916 207927 207872 207969
[15:17:40.892] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 100.0 100.0 99.9 100.0 100.0 100.0 99.9 100.0 100.0 100.0 100.0 100.0 100.0
[15:17:40.892] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 100.0 100.0 99.9 100.0 100.0 100.0 99.9 99.9 100.0 100.0 100.0 99.9 100.0
[15:17:40.892] INFO: X-ray hit rate [MHz/cm2]: 17.8 9.8 16.2 25.3 26.8 28.2 27.2 21.2 23.1 28.5 27.8 23.6 25.4 15.5 6.0 6.7
[15:17:40.892] INFO: PixTestHighRate::doXPixelAlive() done
[15:17:40.937] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: clk: 4
[15:17:40.937] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: ctr: 4
[15:17:40.938] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: sda: 19
[15:17:40.938] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: tin: 9
[15:17:40.938] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: level: 15
[15:17:40.938] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: triggerdelay: 0
[15:17:40.938] INFO: PixTest:: pg_setup set to default.
[15:17:40.938] DEBUG: <PixTestHighRate.cc/~PixTestHighRate:L258> PixTestHighRate dtor
[15:17:40.948] INFO: enter test to run
[15:18:00.492] INFO: test: HighRate no parameter change
[15:18:00.492] INFO: running: highrate
[15:18:00.492] DEBUG: <PixTestHighRate.cc/setParameter:L68> setting fParTriggerFrequency -> 20
[15:18:00.492] DEBUG: <PixTestHighRate.cc/init:L211> PixTestHighRate::init()
[15:18:00.492] DEBUG: <PixTestHighRate.cc/PixTestHighRate:L31> PixTestHighRate ctor(PixSetup &a, string, TGTab *)
[15:18:00.493] DEBUG: <PixTestHighRate.cc/runCommand:L165> running command: xpixelalive
[15:18:00.493] INFO: ----------------------------------------------------------------------
[15:18:00.493] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:18:00.493] INFO: ----------------------------------------------------------------------
[15:18:00.493] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: clk: 4
[15:18:00.493] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: ctr: 4
[15:18:00.494] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: sda: 19
[15:18:00.494] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: tin: 9
[15:18:00.494] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: level: 15
[15:18:00.494] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L464> old set: triggerdelay: 0
[15:18:00.494] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: clk: 4
[15:18:00.494] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: ctr: 4
[15:18:00.494] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: sda: 19
[15:18:00.494] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: tin: 9
[15:18:00.494] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: level: 15
[15:18:00.494] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L480> setting: triggerdelay: 20
[15:18:00.501] DEBUG: <PixTest.cc/efficiencyMaps:L396> attempt #0
[15:18:01.107] INFO: Expecting 208000 events.
[15:18:14.752] INFO: 208000 events read in total (13118ms).
[15:18:14.757] INFO: Test took 14256ms.
[15:18:15.057] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:18:15.057] DEBUG: <PixTest.cc/efficiencyMaps:L407> eff result size = 2730642
[15:18:15.057] DEBUG: <PixTest.cc/efficiencyMaps:L412> Create hists highRate_C0 .. highRate_C15
[15:18:15.057] DEBUG: <PixTest.cc/efficiencyMaps:L426> booking xray maps for unmasked detector
[15:18:15.357] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 1 0 0 0 0 2 0
[15:18:15.358] INFO: number of red-efficiency pixels: 197 103 181 347 348 422 358 256 288 389 354 346 290 197 68 61
[15:18:15.358] INFO: number of X-ray hits detected: 143481 78993 130302 205268 217331 230937 221175 171996 186581 229662 224006 191652 202736 126388 48338 55239
[15:18:15.358] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:18:15.358] INFO: number of Vcal hits detected: 207796 207897 207814 207628 207629 207545 207613 207728 207700 207524 207613 207639 207695 207788 207833 207938
[15:18:15.358] INFO: Vcal hit fiducial efficiency (%): 99.9 100.0 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
[15:18:15.358] INFO: Vcal hit overall efficiency (%): 99.9 100.0 99.9 99.8 99.8 99.8 99.8 99.9 99.9 99.8 99.8 99.8 99.9 99.9 99.9 100.0
[15:18:15.358] INFO: X-ray hit rate [MHz/cm2]: 42.1 23.2 38.2 60.2 63.7 67.7 64.8 50.4 54.7 67.3 65.7 56.2 59.4 37.0 14.2 16.2
[15:18:15.358] INFO: PixTestHighRate::doXPixelAlive() done
[15:18:15.405] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: clk: 4
[15:18:15.405] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: ctr: 4
[15:18:15.405] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: sda: 19
[15:18:15.405] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: tin: 9
[15:18:15.405] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: level: 15
[15:18:15.405] DEBUG: <PixTestHighRate.cc/doXPixelAlive:L599> resetting: triggerdelay: 0
[15:18:15.405] INFO: PixTest:: pg_setup set to default.
[15:18:15.405] DEBUG: <PixTestHighRate.cc/~PixTestHighRate:L258> PixTestHighRate dtor
[15:18:15.421] INFO: enter test to run
[15:18:28.731] INFO: test: exit no parameter change
[15:18:28.732] DEBUG: <pXar.cc/main:L340> Final Analog Current: 385.1mA
[15:18:28.733] DEBUG: <pXar.cc/main:L341> Final Digital Current: 466.3mA
[15:18:28.733] DEBUG: <pXar.cc/main:L342> Final Module Temperature: 18.5 C
[15:18:28.733] DEBUG: <PixMonitor.cc/dumpSummaries:L39> PixMonitor::dumpSummaries
[15:18:29.011] QUIET: Connection to board 33 closed.
[15:18:29.025] INFO: pXar: this is the end, my friend
[15:18:29.025] DEBUG: <PixSetup.cc/~PixSetup:L68> PixSetup free fPxarMemory