[09:23:32.477] INFO: *** Welcome to pxar ***
[09:23:32.477] INFO: *** Today: 2016/04/14
[09:23:32.901] INFO: *** Version: v1.9.0-796-gef167-dirty
[09:23:32.901] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-L-2-22_FPIXTest-17C-FNAL-160413-0856_2016-04-13_08h56m_1460555795/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-2-22_FPIXTest-17C-FNAL-160413-0856_2016-04-13_08h56m_1460555795/000_FPIXTest_p17//dacParameters35_C15.dat
[09:23:32.934] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-L-2-22_FPIXTest-17C-FNAL-160413-0856_2016-04-13_08h56m_1460555795/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-L-2-22_FPIXTest-17C-FNAL-160413-0856_2016-04-13_08h56m_1460555795/000_FPIXTest_p17//tbmParameters_C0b.dat
[09:23:32.934] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-L-2-22_FPIXTest-17C-FNAL-160413-0856_2016-04-13_08h56m_1460555795/000_FPIXTest_p17//defaultMaskFile.dat
[09:23:32.942] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-L-2-22_FPIXTest-17C-FNAL-160413-0856_2016-04-13_08h56m_1460555795/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-2-22_FPIXTest-17C-FNAL-160413-0856_2016-04-13_08h56m_1460555795/000_FPIXTest_p17//trimParameters35_C15.dat
[09:23:33.033] INFO: clk: 4
[09:23:33.033] INFO: ctr: 4
[09:23:33.033] INFO: sda: 19
[09:23:33.033] INFO: tin: 9
[09:23:33.033] INFO: level: 15
[09:23:33.033] INFO: triggerdelay: 0
[09:23:33.033] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[09:23:33.033] INFO: Log level: INFO
[09:23:33.052] QUIET: Connection to board DTB_WREKRL opened.
[09:23:33.055] 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:23:33.058] INFO: RPC call hashes of host and DTB match: 398089610
[09:23:34.587] INFO: DUT info:
[09:23:34.588] INFO: The DUT currently contains the following objects:
[09:23:34.588] INFO: 2 TBM Cores tbm08c (2 ON)
[09:23:34.588] INFO: TBM Core alpha (0): 7 registers set
[09:23:34.588] INFO: TBM Core beta (1): 7 registers set
[09:23:34.588] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[09:23:34.588] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[09:23:34.588] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[09:23:34.588] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[09:23:34.588] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[09:23:34.588] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[09:23:34.588] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[09:23:34.588] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[09:23:34.588] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[09:23:34.588] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[09:23:34.588] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[09:23:34.588] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[09:23:34.588] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[09:23:34.588] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[09:23:34.588] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[09:23:34.588] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[09:23:34.588] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[09:23:34.992] INFO: enter 'restricted' command line mode
[09:23:34.992] INFO: enter test to run
[09:23:42.591] INFO: test: PixelAlive no parameter change
[09:23:42.591] INFO: running: pixelalive
[09:23:42.600] INFO: ----------------------------------------------------------------------
[09:23:42.600] 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:23:42.600] INFO: ----------------------------------------------------------------------
[09:23:42.921] INFO: Expecting 41600 events.
[09:23:47.240] INFO: 41600 events read in total (3600ms).
[09:23:47.409] INFO: Test took 4806ms.
[09:23:47.420] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:23:47.699] INFO: PixTestAlive::aliveTest() done
[09:23:47.699] INFO: number of dead pixels (per ROC): 0 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[09:23:47.729] INFO: enter test to run
[09:24:23.655] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[09:24:23.655] INFO: running: highrate
[09:24:23.655] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-L-2-22_FPIXTest-17C-FNAL-160413-0856_2016-04-13_08h56m_1460555795/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-2-22_FPIXTest-17C-FNAL-160413-0856_2016-04-13_08h56m_1460555795/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[09:24:23.882] INFO: ----------------------------------------------------------------------
[09:24:23.882] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[09:24:23.882] INFO: ----------------------------------------------------------------------
[09:24:23.882] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[09:24:23.882] INFO: edge/corner pixel THR is adjusted
[09:24:23.882] INFO: PixTestHighRate::trimHotPixels: step 0...
[09:24:24.842] INFO: Collecting data for 5 seconds...
[09:24:29.859] INFO: Done with hot pixel readout
[09:24:41.746] INFO: PixTest:: pg_setup set to default.
[09:24:41.747] INFO: 7 hot pixels found in step 0
[09:24:42.737] INFO: Collecting data for 5 seconds...
[09:24:47.753] INFO: Done with hot pixel readout
[09:24:59.611] INFO: PixTest:: pg_setup set to default.
[09:24:59.611] INFO: 13 hot pixels found in step 1
[09:25:00.605] INFO: Collecting data for 5 seconds...
[09:25:05.621] INFO: Done with hot pixel readout
[09:25:17.500] INFO: PixTest:: pg_setup set to default.
[09:25:17.501] INFO: 7 hot pixels found in step 2
[09:25:18.495] INFO: Collecting data for 5 seconds...
[09:25:23.512] INFO: Done with hot pixel readout
[09:25:35.404] INFO: PixTest:: pg_setup set to default.
[09:25:35.405] INFO: 11 hot pixels found in step 3
[09:25:36.399] INFO: Collecting data for 5 seconds...
[09:25:41.416] INFO: Done with hot pixel readout
[09:25:53.277] INFO: PixTest:: pg_setup set to default.
[09:25:53.277] INFO: 7 hot pixels found in step 4
[09:25:54.272] INFO: Collecting data for 5 seconds...
[09:25:59.289] INFO: Done with hot pixel readout
[09:26:11.153] INFO: PixTest:: pg_setup set to default.
[09:26:11.154] INFO: 6 hot pixels found in step 5
[09:26:12.147] INFO: Collecting data for 5 seconds...
[09:26:17.163] INFO: Done with hot pixel readout
[09:26:29.032] INFO: PixTest:: pg_setup set to default.
[09:26:29.033] INFO: 7 hot pixels found in step 6
[09:26:30.026] INFO: Collecting data for 5 seconds...
[09:26:35.042] INFO: Done with hot pixel readout
[09:26:46.926] INFO: PixTest:: pg_setup set to default.
[09:26:46.927] INFO: 5 hot pixels found in step 7
[09:26:47.922] INFO: Collecting data for 5 seconds...
[09:26:52.938] INFO: Done with hot pixel readout
[09:27:04.595] INFO: PixTest:: pg_setup set to default.
[09:27:04.596] INFO: 3 hot pixels found in step 8
[09:27:05.590] INFO: Collecting data for 5 seconds...
[09:27:10.606] INFO: Done with hot pixel readout
[09:27:22.497] INFO: PixTest:: pg_setup set to default.
[09:27:22.498] INFO: 3 hot pixels found in step 9
[09:27:23.492] INFO: Collecting data for 5 seconds...
[09:27:28.508] INFO: Done with hot pixel readout
[09:27:40.412] INFO: PixTest:: pg_setup set to default.
[09:27:40.412] INFO: 7 hot pixels found in step 10
[09:27:41.407] INFO: Collecting data for 5 seconds...
[09:27:46.424] INFO: Done with hot pixel readout
[09:27:58.299] INFO: PixTest:: pg_setup set to default.
[09:27:58.300] INFO: 4 hot pixels found in step 11
[09:27:59.295] INFO: Collecting data for 5 seconds...
[09:28:04.312] INFO: Done with hot pixel readout
[09:28:16.180] INFO: PixTest:: pg_setup set to default.


[09:28:16.181] INFO: 5 hot pixels found in step 12
[09:28:17.174] INFO: Collecting data for 5 seconds...
[09:28:22.190] INFO: Done with hot pixel readout
[09:28:34.014] INFO: PixTest:: pg_setup set to default.
[09:28:34.015] INFO: 2 hot pixels found in step 13
[09:28:35.009] INFO: Collecting data for 5 seconds...
[09:28:40.025] INFO: Done with hot pixel readout
[09:28:51.881] INFO: PixTest:: pg_setup set to default.
[09:28:51.881] INFO: 3 hot pixels found in step 14
[09:28:51.920] INFO: 3 hot pixels could not be trimmed and have been masked.
[09:28:51.923] INFO: PixTest::trimHotPixels() done
[09:28:51.923] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-22_FPIXTest-17C-FNAL-160413-0856_2016-04-13_08h56m_1460555795/000_FPIXTest_p17//trimParameters35_C0.dat
[09:28:51.946] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-22_FPIXTest-17C-FNAL-160413-0856_2016-04-13_08h56m_1460555795/000_FPIXTest_p17//trimParameters35_C1.dat
[09:28:51.958] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-22_FPIXTest-17C-FNAL-160413-0856_2016-04-13_08h56m_1460555795/000_FPIXTest_p17//trimParameters35_C2.dat
[09:28:51.967] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-22_FPIXTest-17C-FNAL-160413-0856_2016-04-13_08h56m_1460555795/000_FPIXTest_p17//trimParameters35_C3.dat
[09:28:51.973] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-22_FPIXTest-17C-FNAL-160413-0856_2016-04-13_08h56m_1460555795/000_FPIXTest_p17//trimParameters35_C4.dat
[09:28:51.978] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-22_FPIXTest-17C-FNAL-160413-0856_2016-04-13_08h56m_1460555795/000_FPIXTest_p17//trimParameters35_C5.dat
[09:28:51.984] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-22_FPIXTest-17C-FNAL-160413-0856_2016-04-13_08h56m_1460555795/000_FPIXTest_p17//trimParameters35_C6.dat
[09:28:51.989] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-22_FPIXTest-17C-FNAL-160413-0856_2016-04-13_08h56m_1460555795/000_FPIXTest_p17//trimParameters35_C7.dat
[09:28:51.994] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-22_FPIXTest-17C-FNAL-160413-0856_2016-04-13_08h56m_1460555795/000_FPIXTest_p17//trimParameters35_C8.dat
[09:28:51.999] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-22_FPIXTest-17C-FNAL-160413-0856_2016-04-13_08h56m_1460555795/000_FPIXTest_p17//trimParameters35_C9.dat
[09:28:51.005] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-22_FPIXTest-17C-FNAL-160413-0856_2016-04-13_08h56m_1460555795/000_FPIXTest_p17//trimParameters35_C10.dat
[09:28:52.010] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-22_FPIXTest-17C-FNAL-160413-0856_2016-04-13_08h56m_1460555795/000_FPIXTest_p17//trimParameters35_C11.dat
[09:28:52.015] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-22_FPIXTest-17C-FNAL-160413-0856_2016-04-13_08h56m_1460555795/000_FPIXTest_p17//trimParameters35_C12.dat
[09:28:52.021] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-22_FPIXTest-17C-FNAL-160413-0856_2016-04-13_08h56m_1460555795/000_FPIXTest_p17//trimParameters35_C13.dat
[09:28:52.026] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-22_FPIXTest-17C-FNAL-160413-0856_2016-04-13_08h56m_1460555795/000_FPIXTest_p17//trimParameters35_C14.dat
[09:28:52.031] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-22_FPIXTest-17C-FNAL-160413-0856_2016-04-13_08h56m_1460555795/000_FPIXTest_p17//trimParameters35_C15.dat
[09:28:52.036] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-L-2-22_FPIXTest-17C-FNAL-160413-0856_2016-04-13_08h56m_1460555795/000_FPIXTest_p17//defaultMaskFile.dat
[09:28:52.046] INFO: enter test to run
[09:29:28.453] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[09:29:28.453] INFO: running: highrate
[09:29:28.457] INFO: ----------------------------------------------------------------------
[09:29:28.457] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[09:29:28.457] INFO: ----------------------------------------------------------------------
[09:29:28.457] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[09:29:28.458] INFO: edge/corner pixel THR is adjusted
[09:29:28.458] INFO: PixTestHighRate::trimHotPixels: step 0...
[09:29:29.415] INFO: Collecting data for 1 seconds...
[09:29:30.419] INFO: Done with hot pixel readout
[09:29:34.597] INFO: PixTest:: pg_setup set to default.
[09:29:34.598] INFO: 0 hot pixels found in step 0
[09:29:34.603] INFO: 0 hot pixels could not be trimmed and have been masked.
[09:29:34.688] INFO: PixTest::trimHotPixels() done
[09:29:34.688] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-22_FPIXTest-17C-FNAL-160413-0856_2016-04-13_08h56m_1460555795/000_FPIXTest_p17//trimParameters35_C0.dat
[09:29:34.699] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-22_FPIXTest-17C-FNAL-160413-0856_2016-04-13_08h56m_1460555795/000_FPIXTest_p17//trimParameters35_C1.dat
[09:29:34.704] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-22_FPIXTest-17C-FNAL-160413-0856_2016-04-13_08h56m_1460555795/000_FPIXTest_p17//trimParameters35_C2.dat
[09:29:34.709] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-22_FPIXTest-17C-FNAL-160413-0856_2016-04-13_08h56m_1460555795/000_FPIXTest_p17//trimParameters35_C3.dat
[09:29:34.715] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-22_FPIXTest-17C-FNAL-160413-0856_2016-04-13_08h56m_1460555795/000_FPIXTest_p17//trimParameters35_C4.dat
[09:29:34.720] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-22_FPIXTest-17C-FNAL-160413-0856_2016-04-13_08h56m_1460555795/000_FPIXTest_p17//trimParameters35_C5.dat
[09:29:34.725] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-22_FPIXTest-17C-FNAL-160413-0856_2016-04-13_08h56m_1460555795/000_FPIXTest_p17//trimParameters35_C6.dat
[09:29:34.731] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-22_FPIXTest-17C-FNAL-160413-0856_2016-04-13_08h56m_1460555795/000_FPIXTest_p17//trimParameters35_C7.dat
[09:29:34.736] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-22_FPIXTest-17C-FNAL-160413-0856_2016-04-13_08h56m_1460555795/000_FPIXTest_p17//trimParameters35_C8.dat
[09:29:34.741] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-22_FPIXTest-17C-FNAL-160413-0856_2016-04-13_08h56m_1460555795/000_FPIXTest_p17//trimParameters35_C9.dat
[09:29:34.747] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-22_FPIXTest-17C-FNAL-160413-0856_2016-04-13_08h56m_1460555795/000_FPIXTest_p17//trimParameters35_C10.dat
[09:29:34.752] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-22_FPIXTest-17C-FNAL-160413-0856_2016-04-13_08h56m_1460555795/000_FPIXTest_p17//trimParameters35_C11.dat
[09:29:34.757] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-22_FPIXTest-17C-FNAL-160413-0856_2016-04-13_08h56m_1460555795/000_FPIXTest_p17//trimParameters35_C12.dat
[09:29:34.762] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-22_FPIXTest-17C-FNAL-160413-0856_2016-04-13_08h56m_1460555795/000_FPIXTest_p17//trimParameters35_C13.dat
[09:29:34.767] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-22_FPIXTest-17C-FNAL-160413-0856_2016-04-13_08h56m_1460555795/000_FPIXTest_p17//trimParameters35_C14.dat
[09:29:34.773] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-22_FPIXTest-17C-FNAL-160413-0856_2016-04-13_08h56m_1460555795/000_FPIXTest_p17//trimParameters35_C15.dat
[09:29:34.778] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-L-2-22_FPIXTest-17C-FNAL-160413-0856_2016-04-13_08h56m_1460555795/000_FPIXTest_p17//defaultMaskFile.dat
[09:29:34.788] INFO: enter test to run
[09:30:02.828] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[09:30:02.828] INFO: running: xray
[09:30:02.829] INFO: ----------------------------------------------------------------------
[09:30:02.829] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[09:30:02.829] INFO: ----------------------------------------------------------------------
[09:30:03.791] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[09:30:15.337] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[09:30:44.561] INFO: Resuming triggers.
[09:30:56.103] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[09:31:25.468] INFO: Resuming triggers.
[09:31:37.011] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[09:32:06.259] INFO: Resuming triggers.
[09:32:17.804] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[09:32:47.046] INFO: Resuming triggers.
[09:32:58.585] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[09:33:27.877] INFO: Resuming triggers.
[09:33:39.420] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[09:34:08.679] INFO: Resuming triggers.
[09:34:20.217] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[09:34:49.530] INFO: Resuming triggers.
[09:35:01.071] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[09:35:30.300] INFO: Resuming triggers.
[09:35:38.290] INFO: data taking finished, elapsed time: 100 seconds.
[09:35:58.763] INFO: PixTest:: pg_setup set to default.
[09:35:58.767] INFO: PixTestXray::doPhRun() done
[09:35:58.939] INFO: enter test to run
[09:36:27.938] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[09:36:27.938] INFO: running: xray
[09:36:27.939] INFO: ----------------------------------------------------------------------
[09:36:27.939] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[09:36:27.939] INFO: ----------------------------------------------------------------------
[09:36:28.902] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[09:36:35.227] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[09:37:05.192] INFO: Resuming triggers.
[09:37:11.518] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[09:37:41.618] INFO: Resuming triggers.
[09:37:47.945] INFO: run duration 18 seconds, buffer almost full (81%), pausing triggers.
[09:38:18.039] INFO: Resuming triggers.
[09:38:24.364] INFO: run duration 25 seconds, buffer almost full (81%), pausing triggers.
[09:38:54.291] INFO: Resuming triggers.
[09:39:00.616] INFO: run duration 31 seconds, buffer almost full (81%), pausing triggers.
[09:39:27.782] INFO: Resuming triggers.
[09:39:34.109] INFO: run duration 37 seconds, buffer almost full (81%), pausing triggers.
[09:40:04.188] INFO: Resuming triggers.
[09:40:10.514] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[09:40:40.678] INFO: Resuming triggers.
[09:40:47.007] INFO: run duration 50 seconds, buffer almost full (81%), pausing triggers.
[09:41:17.066] INFO: Resuming triggers.
[09:41:23.391] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[09:41:53.432] INFO: Resuming triggers.
[09:41:59.758] INFO: run duration 63 seconds, buffer almost full (81%), pausing triggers.
[09:42:29.912] INFO: Resuming triggers.
[09:42:36.235] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[09:43:06.319] INFO: Resuming triggers.
[09:43:12.643] INFO: run duration 75 seconds, buffer almost full (81%), pausing triggers.
[09:43:42.679] INFO: Resuming triggers.
[09:43:48.003] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[09:44:19.010] INFO: Resuming triggers.
[09:44:25.331] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[09:44:55.358] INFO: Resuming triggers.
[09:45:01.680] INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[09:45:31.743] INFO: Resuming triggers.
[09:45:37.197] INFO: data taking finished, elapsed time: 100 seconds.
[09:46:03.320] INFO: PixTest:: pg_setup set to default.
[09:46:03.323] INFO: PixTestXray::doPhRun() done
[09:46:03.471] INFO: enter test to run
[09:46:51.765] INFO: test: HighRate no parameter change
[09:46:51.765] INFO: running: highrate
[09:46:51.766] INFO: ----------------------------------------------------------------------
[09:46:51.766] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[09:46:51.766] INFO: ----------------------------------------------------------------------
[09:46:51.908] INFO: Expecting 768 events.
[09:46:53.041] INFO: 768 events read in total (418ms).
[09:46:53.042] INFO: Test took 1268ms.
[09:46:53.845] INFO: Expecting 41600 events.
[09:46:56.938] INFO: 41600 events read in total (2566ms).
[09:46:56.939] INFO: Test took 3888ms.
[09:46:56.972] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:46:57.697] INFO: Expecting 41600 events.
[09:47:00.892] INFO: 41600 events read in total (2668ms).
[09:47:00.893] INFO: Test took 3904ms.
[09:47:00.927] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:47:01.652] INFO: Expecting 41600 events.
[09:47:04.887] INFO: 41600 events read in total (2708ms).
[09:47:04.888] INFO: Test took 3944ms.
[09:47:04.922] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:47:05.647] INFO: Expecting 41600 events.
[09:47:08.871] INFO: 41600 events read in total (2697ms).
[09:47:08.872] INFO: Test took 3931ms.
[09:47:08.905] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:47:09.629] INFO: Expecting 41600 events.
[09:47:12.855] INFO: 41600 events read in total (2699ms).
[09:47:12.856] INFO: Test took 3932ms.
[09:47:12.889] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:47:13.614] INFO: Expecting 41600 events.
[09:47:16.850] INFO: 41600 events read in total (2709ms).
[09:47:16.851] INFO: Test took 3944ms.
[09:47:16.885] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:47:17.607] INFO: Expecting 41600 events.
[09:47:20.835] INFO: 41600 events read in total (2702ms).
[09:47:20.836] INFO: Test took 3933ms.
[09:47:20.870] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:47:21.594] INFO: Expecting 41600 events.
[09:47:24.830] INFO: 41600 events read in total (2709ms).
[09:47:24.831] INFO: Test took 3942ms.
[09:47:24.865] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:47:25.586] INFO: Expecting 41600 events.
[09:47:28.827] INFO: 41600 events read in total (2714ms).
[09:47:28.828] INFO: Test took 3945ms.
[09:47:28.862] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:47:29.586] INFO: Expecting 41600 events.
[09:47:32.823] INFO: 41600 events read in total (2710ms).
[09:47:32.824] INFO: Test took 3945ms.
[09:47:32.857] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:47:33.582] INFO: Expecting 41600 events.
[09:47:36.819] INFO: 41600 events read in total (2710ms).
[09:47:36.820] INFO: Test took 3946ms.
[09:47:36.854] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:47:37.578] INFO: Expecting 41600 events.
[09:47:40.826] INFO: 41600 events read in total (2721ms).
[09:47:40.827] INFO: Test took 3954ms.
[09:47:40.861] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:47:41.583] INFO: Expecting 41600 events.
[09:47:44.815] INFO: 41600 events read in total (2705ms).
[09:47:44.816] INFO: Test took 3937ms.
[09:47:44.849] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:47:45.577] INFO: Expecting 41600 events.
[09:47:48.808] INFO: 41600 events read in total (2704ms).
[09:47:48.809] INFO: Test took 3941ms.
[09:47:48.843] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:47:49.568] INFO: Expecting 41600 events.
[09:47:52.806] INFO: 41600 events read in total (2712ms).
[09:47:52.807] INFO: Test took 3946ms.
[09:47:52.841] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:47:53.567] INFO: Expecting 41600 events.
[09:47:56.802] INFO: 41600 events read in total (2708ms).
[09:47:56.803] INFO: Test took 3944ms.
[09:47:56.837] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:47:57.563] INFO: Expecting 41600 events.
[09:48:00.796] INFO: 41600 events read in total (2706ms).
[09:48:00.797] INFO: Test took 3942ms.
[09:48:00.831] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:48:01.556] INFO: Expecting 41600 events.
[09:48:04.793] INFO: 41600 events read in total (2710ms).
[09:48:04.794] INFO: Test took 3946ms.
[09:48:04.828] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:48:05.552] INFO: Expecting 41600 events.
[09:48:08.777] INFO: 41600 events read in total (2698ms).
[09:48:08.778] INFO: Test took 3933ms.
[09:48:08.812] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:48:09.537] INFO: Expecting 41600 events.
[09:48:12.585] INFO: 41600 events read in total (2522ms).
[09:48:12.587] INFO: Test took 3756ms.
[09:48:12.619] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:48:12.984] INFO: enter test to run
[09:48:40.524] INFO: test: HighRate no parameter change
[09:48:40.524] INFO: running: highrate
[09:48:40.525] INFO: ----------------------------------------------------------------------
[09:48:40.525] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[09:48:40.525] INFO: ----------------------------------------------------------------------
[09:48:41.144] INFO: Expecting 208000 events.
[09:48:52.946] INFO: 208000 events read in total (11276ms).
[09:48:52.949] INFO: Test took 12416ms.
[09:48:53.091] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:48:53.342] INFO: number of dead pixels (per ROC): 0 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[09:48:53.342] INFO: number of red-efficiency pixels: 80 64 88 148 148 136 136 82 92 123 115 103 94 58 30 26
[09:48:53.342] INFO: number of X-ray hits detected: 64287 45658 67836 108366 113650 114650 111252 79332 77253 96406 91396 82376 86433 51674 23236 25785
[09:48:53.342] 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:48:53.342] INFO: number of Vcal hits detected: 207915 207886 207906 207849 207849 207858 207862 207914 207908 207875 207885 207896 207903 207941 207970 207974
[09:48:53.342] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 100.0 100.0 100.0 100.0 100.0 100.0
[09:48:53.342] INFO: Vcal hit overall efficiency (%): 100.0 99.9 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
[09:48:53.342] INFO: X-ray hit rate [MHz/cm2]: 18.8 13.4 19.9 31.8 33.3 33.6 32.6 23.3 22.6 28.3 26.8 24.1 25.3 15.1 6.8 7.6
[09:48:53.342] INFO: PixTestHighRate::doXPixelAlive() done
[09:48:53.393] INFO: PixTest:: pg_setup set to default.
[09:48:53.408] INFO: enter test to run
[09:49:13.900] INFO: test: HighRate no parameter change
[09:49:13.900] INFO: running: highrate
[09:49:13.901] INFO: ----------------------------------------------------------------------
[09:49:13.901] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[09:49:13.901] INFO: ----------------------------------------------------------------------
[09:49:14.520] INFO: Expecting 208000 events.
[09:49:26.364] INFO: 208000 events read in total (11317ms).
[09:49:26.370] INFO: Test took 12459ms.
[09:49:26.686] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:49:26.994] INFO: number of dead pixels (per ROC): 0 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[09:49:26.994] INFO: number of red-efficiency pixels: 227 170 346 616 502 605 515 309 251 474 338 380 303 175 55 61
[09:49:26.994] INFO: number of X-ray hits detected: 143208 101465 151221 241646 252477 254336 246393 176426 172751 212763 202999 183407 190772 115715 51646 58500
[09:49:26.994] 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:49:26.994] INFO: number of Vcal hits detected: 207760 207768 207614 207314 207455 207312 207452 207663 207738 207486 207637 207601 207676 207815 207945 207938
[09:49:26.994] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.8 99.7 99.8 99.7 99.8 99.9 99.9 99.8 99.8 99.8 99.9 99.9 100.0 100.0
[09:49:26.994] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.7 99.7 99.7 99.7 99.8 99.9 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[09:49:26.994] INFO: X-ray hit rate [MHz/cm2]: 42.0 29.7 44.3 70.8 74.0 74.5 72.2 51.7 50.6 62.4 59.5 53.8 55.9 33.9 15.1 17.1
[09:49:26.994] INFO: PixTestHighRate::doXPixelAlive() done
[09:49:27.038] INFO: PixTest:: pg_setup set to default.
[09:49:27.047] INFO: enter test to run
[09:50:14.956] INFO: test: HighRate no parameter change
[09:50:14.956] INFO: running: highrate
[09:50:14.957] INFO: ----------------------------------------------------------------------
[09:50:14.957] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[09:50:14.957] INFO: ----------------------------------------------------------------------
[09:50:15.574] INFO: Expecting 208000 events.
[09:50:31.482] INFO: 208000 events read in total (15382ms).
[09:50:31.490] INFO: Test took 16524ms.
[09:50:31.970] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:50:32.329] INFO: number of dead pixels (per ROC): 0 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[09:50:32.329] INFO: number of red-efficiency pixels: 406 323 780 1390 1112 1410 1112 607 507 1117 756 846 640 397 112 117
[09:50:32.329] INFO: number of X-ray hits detected: 217657 155062 229307 366653 383453 385810 374688 266383 261662 324986 307927 279122 290118 176630 78651 89183
[09:50:32.329] 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:50:32.329] INFO: number of Vcal hits detected: 207529 207594 206885 206159 206630 206117 206568 207261 207430 206610 207114 206994 207262 207552 207885 207879
[09:50:32.329] INFO: Vcal hit fiducial efficiency (%): 99.8 99.8 99.5 99.2 99.4 99.2 99.4 99.7 99.7 99.4 99.6 99.6 99.7 99.8 99.9 99.9
[09:50:32.329] INFO: Vcal hit overall efficiency (%): 99.8 99.8 99.5 99.1 99.3 99.1 99.3 99.6 99.7 99.3 99.6 99.5 99.6 99.8 99.9 99.9
[09:50:32.329] INFO: X-ray hit rate [MHz/cm2]: 63.8 45.4 67.2 107.5 112.4 113.1 109.8 78.1 76.7 95.3 90.3 81.8 85.0 51.8 23.1 26.1
[09:50:32.329] INFO: PixTestHighRate::doXPixelAlive() done
[09:50:32.376] INFO: PixTest:: pg_setup set to default.
[09:50:32.389] INFO: enter test to run
[09:50:40.499] INFO: test: exit no parameter change
[09:50:40.914] QUIET: Connection to board 33 closed.
[09:50:40.915] INFO: pXar: this is the end, my friend