[13:28:28.590] INFO: *** Welcome to pxar ***
[13:28:28.590] INFO: *** Today: 2016/04/19
[13:28:28.609] INFO: *** Version: v1.9.0-796-gef167-dirty
[13:28:28.609] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-L-1-06_FPIXTest-17C-FNAL-160415-0858_2016-04-15_08h58m_1460728701/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-1-06_FPIXTest-17C-FNAL-160415-0858_2016-04-15_08h58m_1460728701/000_FPIXTest_p17//dacParameters35_C15.dat
[13:28:28.610] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-L-1-06_FPIXTest-17C-FNAL-160415-0858_2016-04-15_08h58m_1460728701/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-L-1-06_FPIXTest-17C-FNAL-160415-0858_2016-04-15_08h58m_1460728701/000_FPIXTest_p17//tbmParameters_C0b.dat
[13:28:28.610] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-L-1-06_FPIXTest-17C-FNAL-160415-0858_2016-04-15_08h58m_1460728701/000_FPIXTest_p17//defaultMaskFile.dat
[13:28:28.620] INFO: MASKED Roc 0 col/row: 2 4
[13:28:28.620] INFO: MASKED Roc 0 col/row: 4 33
[13:28:28.620] INFO: MASKED Roc 3 col/row: 9 18
[13:28:28.620] INFO: MASKED Roc 3 col/row: 12 43
[13:28:28.620] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-L-1-06_FPIXTest-17C-FNAL-160415-0858_2016-04-15_08h58m_1460728701/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-1-06_FPIXTest-17C-FNAL-160415-0858_2016-04-15_08h58m_1460728701/000_FPIXTest_p17//trimParameters35_C15.dat
[13:28:28.620] INFO: masking Roc 0 col/row: 2 4
[13:28:28.620] INFO: masking Roc 0 col/row: 4 33
[13:28:28.638] INFO: masking Roc 3 col/row: 9 18
[13:28:28.638] INFO: masking Roc 3 col/row: 12 43
[13:28:28.692] INFO: clk: 4
[13:28:28.692] INFO: ctr: 4
[13:28:28.692] INFO: sda: 19
[13:28:28.692] INFO: tin: 9
[13:28:28.692] INFO: level: 15
[13:28:28.692] INFO: triggerdelay: 0
[13:28:28.692] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[13:28:28.692] INFO: Log level: INFO
[13:28:28.710] QUIET: Connection to board DTB_WREKRL opened.
[13:28:28.713] 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:
------------------------------------------------------
[13:28:28.716] INFO: RPC call hashes of host and DTB match: 398089610
[13:28:30.247] INFO: DUT info:
[13:28:30.247] INFO: The DUT currently contains the following objects:
[13:28:30.247] INFO: 2 TBM Cores tbm08c (2 ON)
[13:28:30.247] INFO: TBM Core alpha (0): 7 registers set
[13:28:30.247] INFO: TBM Core beta (1): 7 registers set
[13:28:30.247] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[13:28:30.247] INFO: ROC 0: 19 DACs set, Pixels: 2 masked, 0 active.
[13:28:30.247] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[13:28:30.247] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[13:28:30.247] INFO: ROC 3: 19 DACs set, Pixels: 2 masked, 0 active.
[13:28:30.248] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[13:28:30.248] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[13:28:30.248] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[13:28:30.248] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[13:28:30.248] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[13:28:30.248] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[13:28:30.248] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[13:28:30.248] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[13:28:30.248] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[13:28:30.248] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[13:28:30.248] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[13:28:30.248] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[13:28:30.651] INFO: enter 'restricted' command line mode
[13:28:30.651] INFO: enter test to run
[13:28:46.896] INFO: test: PixelAlive no parameter change
[13:28:46.896] INFO: running: pixelalive
[13:28:46.905] INFO: ----------------------------------------------------------------------
[13:28:46.906] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[13:28:46.906] INFO: ----------------------------------------------------------------------
[13:28:46.908] INFO: ROC 0 masking pixel 2/4
[13:28:46.908] INFO: ROC 0 masking pixel 4/33
[13:28:46.908] INFO: ROC 3 masking pixel 9/18
[13:28:46.908] INFO: ROC 3 masking pixel 12/43
[13:28:47.229] INFO: Expecting 41600 events.
[13:28:51.560] INFO: 41600 events read in total (3613ms).
[13:28:51.729] INFO: Test took 4821ms.
[13:28:51.740] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:28:51.001] INFO: PixTestAlive::aliveTest() done
[13:28:51.001] INFO: number of dead pixels (per ROC): 2 0 0 2 0 0 2 0 0 0 0 0 0 0 0 1
[13:28:51.001] INFO: ROC 0 masking pixel 2/4
[13:28:51.001] INFO: ROC 0 masking pixel 4/33
[13:28:51.001] INFO: ROC 3 masking pixel 9/18
[13:28:51.001] INFO: ROC 3 masking pixel 12/43
[13:28:52.035] INFO: enter test to run
[13:29:22.528] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[13:29:22.528] INFO: running: highrate
[13:29:22.529] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-L-1-06_FPIXTest-17C-FNAL-160415-0858_2016-04-15_08h58m_1460728701/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-1-06_FPIXTest-17C-FNAL-160415-0858_2016-04-15_08h58m_1460728701/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[13:29:22.688] INFO: ----------------------------------------------------------------------
[13:29:22.688] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[13:29:22.688] INFO: ----------------------------------------------------------------------
[13:29:22.688] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[13:29:22.688] INFO: edge/corner pixel THR is adjusted
[13:29:22.688] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:29:23.647] INFO: Collecting data for 5 seconds...
[13:29:28.663] INFO: Done with hot pixel readout
[13:29:40.629] INFO: PixTest:: pg_setup set to default.
[13:29:40.630] INFO: 6 hot pixels found in step 0
[13:29:41.623] INFO: Collecting data for 5 seconds...
[13:29:46.639] INFO: Done with hot pixel readout
[13:29:58.547] INFO: PixTest:: pg_setup set to default.
[13:29:58.548] INFO: 4 hot pixels found in step 1
[13:29:59.542] INFO: Collecting data for 5 seconds...
[13:30:04.558] INFO: Done with hot pixel readout
[13:30:16.519] INFO: PixTest:: pg_setup set to default.
[13:30:16.520] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:30:16.520] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:30:16.520] INFO: 6 hot pixels found in step 2
[13:30:17.515] INFO: Collecting data for 5 seconds...
[13:30:22.531] INFO: Done with hot pixel readout
[13:30:34.498] INFO: PixTest:: pg_setup set to default.
[13:30:34.499] INFO: 4 hot pixels found in step 3
[13:30:35.493] INFO: Collecting data for 5 seconds...
[13:30:40.509] INFO: Done with hot pixel readout
[13:30:52.446] INFO: PixTest:: pg_setup set to default.
[13:30:52.447] INFO: 7 hot pixels found in step 4
[13:30:53.441] INFO: Collecting data for 5 seconds...
[13:30:58.457] INFO: Done with hot pixel readout
[13:31:10.414] INFO: PixTest:: pg_setup set to default.
[13:31:10.415] INFO: 6 hot pixels found in step 5
[13:31:11.409] INFO: Collecting data for 5 seconds...
[13:31:16.426] INFO: Done with hot pixel readout
[13:31:28.355] INFO: PixTest:: pg_setup set to default.
[13:31:28.355] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:31:28.355] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:31:28.356] INFO: 4 hot pixels found in step 6
[13:31:29.351] INFO: Collecting data for 5 seconds...
[13:31:34.368] INFO: Done with hot pixel readout
[13:31:46.318] INFO: PixTest:: pg_setup set to default.
[13:31:46.318] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:31:46.319] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:31:46.319] INFO: 5 hot pixels found in step 7
[13:31:47.313] INFO: Collecting data for 5 seconds...
[13:31:52.329] INFO: Done with hot pixel readout
[13:32:04.244] INFO: PixTest:: pg_setup set to default.
[13:32:04.244] INFO: 1 hot pixels found in step 8
[13:32:05.240] INFO: Collecting data for 5 seconds...
[13:32:10.256] INFO: Done with hot pixel readout
[13:32:22.211] INFO: PixTest:: pg_setup set to default.
[13:32:22.211] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:32:22.212] INFO: 4 hot pixels found in step 9
[13:32:23.206] INFO: Collecting data for 5 seconds...
[13:32:28.222] INFO: Done with hot pixel readout
[13:32:40.160] INFO: PixTest:: pg_setup set to default.
[13:32:40.160] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:32:40.161] INFO: 7 hot pixels found in step 10
[13:32:41.155] INFO: Collecting data for 5 seconds...
[13:32:46.172] INFO: Done with hot pixel readout
[13:32:58.139] INFO: PixTest:: pg_setup set to default.
[13:32:58.140] INFO: 3 hot pixels found in step 11
[13:32:59.135] INFO: Collecting data for 5 seconds...
[13:33:04.152] INFO: Done with hot pixel readout
[13:33:16.126] INFO: PixTest:: pg_setup set to default.
[13:33:16.126] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:33:16.126] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:33:16.127] INFO: 3 hot pixels found in step 12
[13:33:17.121] INFO: Collecting data for 5 seconds...
[13:33:22.137] INFO: Done with hot pixel readout
[13:33:34.111] INFO: PixTest:: pg_setup set to default.
[13:33:34.112] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:33:34.112] INFO: 3 hot pixels found in step 13
[13:33:35.107] INFO: Collecting data for 5 seconds...
[13:33:40.123] INFO: Done with hot pixel readout
[13:33:52.011] INFO: PixTest:: pg_setup set to default.
[13:33:52.012] INFO: 1 hot pixels found in step 14
[13:33:52.050] INFO: 1 hot pixels could not be trimmed and have been masked.
[13:33:52.054] INFO: PixTest::trimHotPixels() done
[13:33:52.054] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-06_FPIXTest-17C-FNAL-160415-0858_2016-04-15_08h58m_1460728701/000_FPIXTest_p17//trimParameters35_C0.dat
[13:33:52.059] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-06_FPIXTest-17C-FNAL-160415-0858_2016-04-15_08h58m_1460728701/000_FPIXTest_p17//trimParameters35_C1.dat
[13:33:52.065] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-06_FPIXTest-17C-FNAL-160415-0858_2016-04-15_08h58m_1460728701/000_FPIXTest_p17//trimParameters35_C2.dat
[13:33:52.071] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-06_FPIXTest-17C-FNAL-160415-0858_2016-04-15_08h58m_1460728701/000_FPIXTest_p17//trimParameters35_C3.dat
[13:33:52.077] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-06_FPIXTest-17C-FNAL-160415-0858_2016-04-15_08h58m_1460728701/000_FPIXTest_p17//trimParameters35_C4.dat
[13:33:52.082] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-06_FPIXTest-17C-FNAL-160415-0858_2016-04-15_08h58m_1460728701/000_FPIXTest_p17//trimParameters35_C5.dat
[13:33:52.087] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-06_FPIXTest-17C-FNAL-160415-0858_2016-04-15_08h58m_1460728701/000_FPIXTest_p17//trimParameters35_C6.dat
[13:33:52.092] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-06_FPIXTest-17C-FNAL-160415-0858_2016-04-15_08h58m_1460728701/000_FPIXTest_p17//trimParameters35_C7.dat
[13:33:52.097] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-06_FPIXTest-17C-FNAL-160415-0858_2016-04-15_08h58m_1460728701/000_FPIXTest_p17//trimParameters35_C8.dat
[13:33:52.102] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-06_FPIXTest-17C-FNAL-160415-0858_2016-04-15_08h58m_1460728701/000_FPIXTest_p17//trimParameters35_C9.dat
[13:33:52.108] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-06_FPIXTest-17C-FNAL-160415-0858_2016-04-15_08h58m_1460728701/000_FPIXTest_p17//trimParameters35_C10.dat
[13:33:52.113] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-06_FPIXTest-17C-FNAL-160415-0858_2016-04-15_08h58m_1460728701/000_FPIXTest_p17//trimParameters35_C11.dat
[13:33:52.118] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-06_FPIXTest-17C-FNAL-160415-0858_2016-04-15_08h58m_1460728701/000_FPIXTest_p17//trimParameters35_C12.dat
[13:33:52.123] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-06_FPIXTest-17C-FNAL-160415-0858_2016-04-15_08h58m_1460728701/000_FPIXTest_p17//trimParameters35_C13.dat
[13:33:52.128] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-06_FPIXTest-17C-FNAL-160415-0858_2016-04-15_08h58m_1460728701/000_FPIXTest_p17//trimParameters35_C14.dat
[13:33:52.134] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-06_FPIXTest-17C-FNAL-160415-0858_2016-04-15_08h58m_1460728701/000_FPIXTest_p17//trimParameters35_C15.dat
[13:33:52.139] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-L-1-06_FPIXTest-17C-FNAL-160415-0858_2016-04-15_08h58m_1460728701/000_FPIXTest_p17//defaultMaskFile.dat
[13:33:52.149] INFO: enter test to run
[13:34:23.910] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[13:34:23.910] INFO: running: highrate
[13:34:23.914] INFO: ----------------------------------------------------------------------
[13:34:23.914] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[13:34:23.914] INFO: ----------------------------------------------------------------------
[13:34:23.914] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[13:34:23.914] INFO: edge/corner pixel THR is adjusted
[13:34:23.914] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:34:24.872] INFO: Collecting data for 1 seconds...
[13:34:25.875] INFO: Done with hot pixel readout
[13:34:29.976] INFO: PixTest:: pg_setup set to default.
[13:34:29.977] INFO: 0 hot pixels found in step 0
[13:34:29.982] INFO: 0 hot pixels could not be trimmed and have been masked.
[13:34:30.071] INFO: PixTest::trimHotPixels() done
[13:34:30.071] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-06_FPIXTest-17C-FNAL-160415-0858_2016-04-15_08h58m_1460728701/000_FPIXTest_p17//trimParameters35_C0.dat
[13:34:30.080] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-06_FPIXTest-17C-FNAL-160415-0858_2016-04-15_08h58m_1460728701/000_FPIXTest_p17//trimParameters35_C1.dat
[13:34:30.085] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-06_FPIXTest-17C-FNAL-160415-0858_2016-04-15_08h58m_1460728701/000_FPIXTest_p17//trimParameters35_C2.dat
[13:34:30.090] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-06_FPIXTest-17C-FNAL-160415-0858_2016-04-15_08h58m_1460728701/000_FPIXTest_p17//trimParameters35_C3.dat
[13:34:30.096] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-06_FPIXTest-17C-FNAL-160415-0858_2016-04-15_08h58m_1460728701/000_FPIXTest_p17//trimParameters35_C4.dat
[13:34:30.101] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-06_FPIXTest-17C-FNAL-160415-0858_2016-04-15_08h58m_1460728701/000_FPIXTest_p17//trimParameters35_C5.dat
[13:34:30.106] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-06_FPIXTest-17C-FNAL-160415-0858_2016-04-15_08h58m_1460728701/000_FPIXTest_p17//trimParameters35_C6.dat
[13:34:30.111] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-06_FPIXTest-17C-FNAL-160415-0858_2016-04-15_08h58m_1460728701/000_FPIXTest_p17//trimParameters35_C7.dat
[13:34:30.116] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-06_FPIXTest-17C-FNAL-160415-0858_2016-04-15_08h58m_1460728701/000_FPIXTest_p17//trimParameters35_C8.dat
[13:34:30.122] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-06_FPIXTest-17C-FNAL-160415-0858_2016-04-15_08h58m_1460728701/000_FPIXTest_p17//trimParameters35_C9.dat
[13:34:30.127] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-06_FPIXTest-17C-FNAL-160415-0858_2016-04-15_08h58m_1460728701/000_FPIXTest_p17//trimParameters35_C10.dat
[13:34:30.132] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-06_FPIXTest-17C-FNAL-160415-0858_2016-04-15_08h58m_1460728701/000_FPIXTest_p17//trimParameters35_C11.dat
[13:34:30.137] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-06_FPIXTest-17C-FNAL-160415-0858_2016-04-15_08h58m_1460728701/000_FPIXTest_p17//trimParameters35_C12.dat
[13:34:30.142] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-06_FPIXTest-17C-FNAL-160415-0858_2016-04-15_08h58m_1460728701/000_FPIXTest_p17//trimParameters35_C13.dat
[13:34:30.148] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-06_FPIXTest-17C-FNAL-160415-0858_2016-04-15_08h58m_1460728701/000_FPIXTest_p17//trimParameters35_C14.dat
[13:34:30.153] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-06_FPIXTest-17C-FNAL-160415-0858_2016-04-15_08h58m_1460728701/000_FPIXTest_p17//trimParameters35_C15.dat
[13:34:30.158] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-L-1-06_FPIXTest-17C-FNAL-160415-0858_2016-04-15_08h58m_1460728701/000_FPIXTest_p17//defaultMaskFile.dat
[13:34:30.168] INFO: enter test to run
[13:34:59.693] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[13:34:59.693] INFO: running: xray
[13:34:59.695] INFO: ----------------------------------------------------------------------
[13:34:59.695] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:34:59.695] INFO: ----------------------------------------------------------------------
[13:34:59.698] INFO: ROC 0 masking pixel 2/4
[13:34:59.698] INFO: ROC 0 masking pixel 4/33
[13:34:59.698] INFO: ROC 3 masking pixel 9/18
[13:34:59.698] INFO: ROC 3 masking pixel 12/43
[13:35:00.658] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:35:11.886] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[13:35:39.344] INFO: Resuming triggers.
[13:35:50.576] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[13:36:19.893] INFO: Resuming triggers.
[13:36:31.125] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[13:37:00.653] INFO: Resuming triggers.
[13:37:11.885] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[13:37:41.306] INFO: Resuming triggers.
[13:37:52.536] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[13:38:21.987] INFO: Resuming triggers.
[13:38:33.216] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[13:39:02.689] INFO: Resuming triggers.
[13:39:13.920] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[13:39:43.362] INFO: Resuming triggers.
[13:39:54.591] INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[13:40:23.005] INFO: Resuming triggers.
[13:40:34.482] INFO: data taking finished, elapsed time: 100 seconds.
[13:41:02.007] INFO: PixTest:: pg_setup set to default.
[13:41:02.011] INFO: PixTestXray::doPhRun() done
[13:41:02.203] INFO: enter test to run
[13:41:40.027] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[13:41:40.027] INFO: running: xray
[13:41:40.028] INFO: ----------------------------------------------------------------------
[13:41:40.028] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:41:40.028] INFO: ----------------------------------------------------------------------
[13:41:40.032] INFO: ROC 0 masking pixel 2/4
[13:41:40.032] INFO: ROC 0 masking pixel 4/33
[13:41:40.032] INFO: ROC 3 masking pixel 9/18
[13:41:40.032] INFO: ROC 3 masking pixel 12/43
[13:41:40.991] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:41:47.436] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[13:42:17.354] INFO: Resuming triggers.
[13:42:23.798] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[13:42:53.991] INFO: Resuming triggers.
[13:43:00.440] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[13:43:30.613] INFO: Resuming triggers.
[13:43:37.057] INFO: run duration 25 seconds, buffer almost full (81%), pausing triggers.
[13:44:07.072] INFO: Resuming triggers.
[13:44:13.519] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[13:44:43.479] INFO: Resuming triggers.
[13:44:49.926] INFO: run duration 38 seconds, buffer almost full (81%), pausing triggers.
[13:45:19.992] INFO: Resuming triggers.
[13:45:26.440] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[13:45:53.587] INFO: Resuming triggers.
[13:46:00.029] INFO: run duration 51 seconds, buffer almost full (81%), pausing triggers.
[13:46:29.962] INFO: Resuming triggers.
[13:46:36.408] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[13:47:06.410] INFO: Resuming triggers.
[13:47:12.858] INFO: run duration 64 seconds, buffer almost full (81%), pausing triggers.
[13:47:42.812] INFO: Resuming triggers.
[13:47:49.258] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[13:48:19.253] INFO: Resuming triggers.
[13:48:25.703] INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.
[13:48:55.662] INFO: Resuming triggers.
[13:49:02.109] INFO: run duration 83 seconds, buffer almost full (81%), pausing triggers.
[13:49:32.071] INFO: Resuming triggers.
[13:49:38.521] INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[13:50:08.533] INFO: Resuming triggers.
[13:50:14.982] INFO: run duration 96 seconds, buffer almost full (81%), pausing triggers.
[13:50:44.823] INFO: Resuming triggers.
[13:50:48.449] INFO: data taking finished, elapsed time: 100 seconds.
[13:51:05.648] INFO: PixTest:: pg_setup set to default.
[13:51:05.652] INFO: PixTestXray::doPhRun() done
[13:51:05.800] INFO: enter test to run
[13:51:31.582] INFO: test: HighRate no parameter change
[13:51:31.582] INFO: running: highrate
[13:51:31.583] INFO: ----------------------------------------------------------------------
[13:51:31.583] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[13:51:31.583] INFO: ----------------------------------------------------------------------
[13:51:31.725] INFO: Expecting 768 events.
[13:51:32.859] INFO: 768 events read in total (419ms).
[13:51:32.859] INFO: Test took 1268ms.
[13:51:32.864] INFO: ROC 0 masking pixel 2/4
[13:51:32.864] INFO: ROC 0 masking pixel 4/33
[13:51:32.865] INFO: ROC 3 masking pixel 9/18
[13:51:32.865] INFO: ROC 3 masking pixel 12/43
[13:51:33.663] INFO: Expecting 41600 events.
[13:51:36.730] INFO: 41600 events read in total (2540ms).
[13:51:36.731] INFO: Test took 3863ms.
[13:51:36.765] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:51:37.490] INFO: Expecting 41600 events.
[13:51:40.674] INFO: 41600 events read in total (2657ms).
[13:51:40.675] INFO: Test took 3892ms.
[13:51:40.709] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:51:41.436] INFO: Expecting 41600 events.
[13:51:44.683] INFO: 41600 events read in total (2720ms).
[13:51:44.684] INFO: Test took 3956ms.
[13:51:44.719] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:51:45.444] INFO: Expecting 41600 events.
[13:51:48.652] INFO: 41600 events read in total (2682ms).
[13:51:48.653] INFO: Test took 3916ms.
[13:51:48.688] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:51:49.411] INFO: Expecting 41600 events.
[13:51:52.661] INFO: 41600 events read in total (2724ms).
[13:51:52.662] INFO: Test took 3955ms.
[13:51:52.698] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:51:53.420] INFO: Expecting 41600 events.
[13:51:56.668] INFO: 41600 events read in total (2721ms).
[13:51:56.669] INFO: Test took 3953ms.
[13:51:56.704] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:51:57.426] INFO: Expecting 41600 events.
[13:52:00.678] INFO: 41600 events read in total (2725ms).
[13:52:00.679] INFO: Test took 3957ms.
[13:52:00.714] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:52:01.437] INFO: Expecting 41600 events.
[13:52:04.684] INFO: 41600 events read in total (2720ms).
[13:52:04.685] INFO: Test took 3952ms.
[13:52:04.720] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:52:05.442] INFO: Expecting 41600 events.
[13:52:08.695] INFO: 41600 events read in total (2726ms).
[13:52:08.696] INFO: Test took 3957ms.
[13:52:08.731] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:52:09.456] INFO: Expecting 41600 events.
[13:52:12.702] INFO: 41600 events read in total (2719ms).
[13:52:12.703] INFO: Test took 3953ms.
[13:52:12.738] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:52:13.461] INFO: Expecting 41600 events.
[13:52:16.719] INFO: 41600 events read in total (2731ms).
[13:52:16.720] INFO: Test took 3965ms.
[13:52:16.755] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:52:17.477] INFO: Expecting 41600 events.
[13:52:20.731] INFO: 41600 events read in total (2727ms).
[13:52:20.732] INFO: Test took 3959ms.
[13:52:20.767] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:52:21.491] INFO: Expecting 41600 events.
[13:52:24.737] INFO: 41600 events read in total (2719ms).
[13:52:24.738] INFO: Test took 3953ms.
[13:52:24.773] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:52:25.496] INFO: Expecting 41600 events.
[13:52:28.745] INFO: 41600 events read in total (2722ms).
[13:52:28.746] INFO: Test took 3955ms.
[13:52:28.781] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:52:29.502] INFO: Expecting 41600 events.
[13:52:32.764] INFO: 41600 events read in total (2735ms).
[13:52:32.765] INFO: Test took 3966ms.
[13:52:32.800] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:52:33.521] INFO: Expecting 41600 events.
[13:52:36.785] INFO: 41600 events read in total (2737ms).
[13:52:36.786] INFO: Test took 3968ms.
[13:52:36.820] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:52:37.544] INFO: Expecting 41600 events.
[13:52:40.793] INFO: 41600 events read in total (2722ms).
[13:52:40.794] INFO: Test took 3956ms.
[13:52:40.830] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:52:41.552] INFO: Expecting 41600 events.
[13:52:44.789] INFO: 41600 events read in total (2710ms).
[13:52:44.790] INFO: Test took 3943ms.
[13:52:44.824] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:52:45.548] INFO: Expecting 41600 events.
[13:52:48.783] INFO: 41600 events read in total (2708ms).
[13:52:48.784] INFO: Test took 3941ms.
[13:52:48.818] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:52:49.540] INFO: Expecting 41600 events.
[13:52:52.657] INFO: 41600 events read in total (2590ms).
[13:52:52.658] INFO: Test took 3821ms.
[13:52:52.692] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:52:53.054] INFO: enter test to run
[13:53:05.253] INFO: test: HighRate no parameter change
[13:53:05.254] INFO: running: highrate
[13:53:05.255] INFO: ----------------------------------------------------------------------
[13:53:05.255] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:53:05.255] INFO: ----------------------------------------------------------------------
[13:53:05.264] INFO: ROC 0 masking pixel 2/4
[13:53:05.264] INFO: ROC 0 masking pixel 4/33
[13:53:05.264] INFO: ROC 3 masking pixel 9/18
[13:53:05.265] INFO: ROC 3 masking pixel 12/43
[13:53:05.869] INFO: Expecting 208000 events.
[13:53:17.807] INFO: 208000 events read in total (11411ms).
[13:53:17.811] INFO: Test took 12546ms.
[13:53:17.962] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:53:18.216] INFO: number of dead pixels (per ROC): 2 0 0 2 0 0 2 0 0 0 0 0 0 0 0 1
[13:53:18.216] INFO: number of red-efficiency pixels: 69 67 94 135 141 152 146 82 97 121 123 107 97 67 41 22
[13:53:18.216] INFO: number of X-ray hits detected: 70434 46318 69646 113317 110035 119173 118063 82195 78660 100856 101371 87183 88605 51566 24557 25545
[13:53:18.216] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:53:18.216] INFO: number of Vcal hits detected: 207831 207933 207905 207762 207851 207844 207751 207914 207900 207875 207876 207892 207902 207932 207957 207929
[13:53:18.216] 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 100.0 100.0 100.0 100.0 100.0
[13:53:18.216] INFO: Vcal hit overall efficiency (%): 99.9 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
[13:53:18.216] INFO: X-ray hit rate [MHz/cm2]: 20.6 13.6 20.4 33.2 32.3 34.9 34.6 24.1 23.1 29.6 29.7 25.6 26.0 15.1 7.2 7.5
[13:53:18.216] INFO: PixTestHighRate::doXPixelAlive() done
[13:53:18.263] INFO: PixTest:: pg_setup set to default.
[13:53:18.274] INFO: enter test to run
[13:53:40.501] INFO: test: HighRate no parameter change
[13:53:40.501] INFO: running: highrate
[13:53:40.502] INFO: ----------------------------------------------------------------------
[13:53:40.502] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:53:40.502] INFO: ----------------------------------------------------------------------
[13:53:40.510] INFO: ROC 0 masking pixel 2/4
[13:53:40.510] INFO: ROC 0 masking pixel 4/33
[13:53:40.510] INFO: ROC 3 masking pixel 9/18
[13:53:40.510] INFO: ROC 3 masking pixel 12/43
[13:53:41.113] INFO: Expecting 208000 events.
[13:53:54.972] INFO: 208000 events read in total (13332ms).
[13:53:54.977] INFO: Test took 14466ms.
[13:53:55.297] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:53:55.601] INFO: number of dead pixels (per ROC): 2 0 0 2 0 0 2 0 0 0 0 0 0 0 0 1
[13:53:55.601] INFO: number of red-efficiency pixels: 247 176 329 435 393 466 545 272 268 456 448 257 282 184 88 69
[13:53:55.601] INFO: number of X-ray hits detected: 150019 98952 149354 240227 234120 250912 252637 174622 168272 214812 215926 185676 188665 109322 52459 54416
[13:53:55.601] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:53:55.601] INFO: number of Vcal hits detected: 207635 207814 207631 207434 207573 207504 207311 207712 207724 207505 207521 207725 207699 207811 207912 207882
[13:53:55.601] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.8 99.8 99.8 99.8 99.7 99.9 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[13:53:55.601] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.8 99.7 99.8 99.8 99.7 99.9 99.9 99.8 99.8 99.9 99.9 99.9 100.0 99.9
[13:53:55.601] INFO: X-ray hit rate [MHz/cm2]: 44.0 29.0 43.8 70.4 68.6 73.5 74.0 51.2 49.3 63.0 63.3 54.4 55.3 32.0 15.4 15.9
[13:53:55.601] INFO: PixTestHighRate::doXPixelAlive() done
[13:53:55.646] INFO: PixTest:: pg_setup set to default.
[13:53:55.661] INFO: enter test to run
[13:54:20.781] INFO: test: HighRate no parameter change
[13:54:20.781] INFO: running: highrate
[13:54:20.783] INFO: ----------------------------------------------------------------------
[13:54:20.783] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:54:20.783] INFO: ----------------------------------------------------------------------
[13:54:20.791] INFO: ROC 0 masking pixel 2/4
[13:54:20.791] INFO: ROC 0 masking pixel 4/33
[13:54:20.791] INFO: ROC 3 masking pixel 9/18
[13:54:20.791] INFO: ROC 3 masking pixel 12/43
[13:54:21.392] INFO: Expecting 208000 events.
[13:54:37.240] INFO: 208000 events read in total (15321ms).
[13:54:37.247] INFO: Test took 16456ms.
[13:54:37.739] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:54:38.098] INFO: number of dead pixels (per ROC): 2 0 0 2 0 0 2 0 0 0 0 0 0 0 0 1
[13:54:38.098] INFO: number of red-efficiency pixels: 471 357 744 1070 959 1041 1237 607 550 1010 999 569 692 413 120 111
[13:54:38.098] INFO: number of X-ray hits detected: 225562 149703 224390 362824 352819 378902 379320 263509 253579 323805 325887 280919 284051 164159 79148 82430
[13:54:38.098] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:54:38.098] INFO: number of Vcal hits detected: 207342 207592 206981 206563 206837 206720 206274 207274 207385 206757 206791 207367 207212 207520 207874 207838
[13:54:38.098] INFO: Vcal hit fiducial efficiency (%): 99.8 99.8 99.6 99.4 99.5 99.4 99.3 99.7 99.7 99.5 99.5 99.7 99.7 99.8 99.9 99.9
[13:54:38.098] INFO: Vcal hit overall efficiency (%): 99.7 99.8 99.5 99.3 99.4 99.4 99.2 99.7 99.7 99.4 99.4 99.7 99.6 99.8 99.9 99.9
[13:54:38.098] INFO: X-ray hit rate [MHz/cm2]: 66.1 43.9 65.8 106.3 103.4 111.1 111.2 77.2 74.3 94.9 95.5 82.3 83.3 48.1 23.2 24.2
[13:54:38.098] INFO: PixTestHighRate::doXPixelAlive() done
[13:54:38.146] INFO: PixTest:: pg_setup set to default.
[13:54:38.160] INFO: enter test to run
[13:54:43.229] INFO: test: exit no parameter change
[13:54:43.613] QUIET: Connection to board 33 closed.
[13:54:43.613] INFO: pXar: this is the end, my friend