[09:36:22.980] INFO: *** Welcome to pxar ***
[09:36:22.980] INFO: *** Today: 2016/08/19
[09:36:22.997] INFO: *** Version: v1.9.0-818-g96727
[09:36:22.997] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//dacParameters35_C15.dat
[09:36:22.998] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//tbmParameters_C0b.dat
[09:36:22.999] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//defaultMaskFile.dat
[09:36:22.999] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C15.dat
[09:36:23.074] INFO: clk: 4
[09:36:23.074] INFO: ctr: 4
[09:36:23.074] INFO: sda: 19
[09:36:23.074] INFO: tin: 9
[09:36:23.074] INFO: level: 15
[09:36:23.074] INFO: triggerdelay: 0
[09:36:23.074] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[09:36:23.074] INFO: Log level: INFO
[09:36:23.092] QUIET: Connection to board DTB_WREKRL opened.
[09:36:23.096] 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:36:23.099] INFO: RPC call hashes of host and DTB match: 398089610
[09:36:24.623] INFO: DUT info:
[09:36:24.623] INFO: The DUT currently contains the following objects:
[09:36:24.623] INFO: 2 TBM Cores tbm08c (2 ON)
[09:36:24.623] INFO: TBM Core alpha (0): 7 registers set
[09:36:24.623] INFO: TBM Core beta (1): 7 registers set
[09:36:24.623] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[09:36:24.623] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[09:36:24.623] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[09:36:24.623] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[09:36:24.623] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[09:36:24.623] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[09:36:24.623] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[09:36:24.623] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[09:36:24.623] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[09:36:24.623] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[09:36:24.623] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[09:36:24.623] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[09:36:24.623] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[09:36:24.623] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[09:36:24.623] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[09:36:24.624] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[09:36:24.624] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[09:36:25.027] INFO: enter 'restricted' command line mode
[09:36:25.027] INFO: enter test to run
[09:36:29.851] INFO: test: PixelAlive no parameter change
[09:36:29.851] INFO: running: pixelalive
[09:36:29.860] INFO: ----------------------------------------------------------------------
[09:36:29.860] 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:36:29.860] INFO: ----------------------------------------------------------------------
[09:36:30.178] INFO: Expecting 41600 events.
[09:36:34.457] INFO: 41600 events read in total (3561ms).
[09:36:34.627] INFO: Test took 4764ms.
[09:36:34.636] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:36:34.902] INFO: PixTestAlive::aliveTest() done
[09:36:34.902] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 4 0 0 0 0 0 0 0
[09:36:34.929] INFO: enter test to run
[09:37:00.426] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[09:37:00.426] INFO: running: highrate
[09:37:00.427] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[09:37:00.586] INFO: ----------------------------------------------------------------------
[09:37:00.586] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[09:37:00.586] INFO: ----------------------------------------------------------------------
[09:37:00.586] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[09:37:00.586] INFO: edge/corner pixel THR is adjusted
[09:37:00.586] INFO: PixTestHighRate::trimHotPixels: step 0...
[09:37:01.545] INFO: Collecting data for 5 seconds...
[09:37:06.562] INFO: Done with hot pixel readout
[09:37:16.748] INFO: PixTest:: pg_setup set to default.






[09:37:16.749] INFO: 21 hot pixels found in step 0
[09:37:17.736] INFO: Collecting data for 5 seconds...
[09:37:22.753] INFO: Done with hot pixel readout
[09:37:34.118] INFO: PixTest:: pg_setup set to default.



[09:37:34.119] INFO: 10 hot pixels found in step 1
[09:37:35.113] INFO: Collecting data for 5 seconds...
[09:37:40.129] INFO: Done with hot pixel readout
[09:37:51.119] INFO: PixTest:: pg_setup set to default.





[09:37:51.120] INFO: 15 hot pixels found in step 2
[09:37:52.110] INFO: Collecting data for 5 seconds...
[09:37:57.126] INFO: Done with hot pixel readout
[09:38:08.603] INFO: PixTest:: pg_setup set to default.






[09:38:08.604] INFO: 7 hot pixels found in step 3
[09:38:09.594] INFO: Collecting data for 5 seconds...
[09:38:14.611] INFO: Done with hot pixel readout
[09:38:26.073] INFO: PixTest:: pg_setup set to default.




[09:38:26.074] INFO: 8 hot pixels found in step 4
[09:38:27.065] INFO: Collecting data for 5 seconds...
[09:38:32.081] INFO: Done with hot pixel readout
[09:38:42.963] INFO: PixTest:: pg_setup set to default.





[09:38:42.964] INFO: 7 hot pixels found in step 5
[09:38:43.955] INFO: Collecting data for 5 seconds...
[09:38:48.970] INFO: Done with hot pixel readout
[09:39:00.320] INFO: PixTest:: pg_setup set to default.




[09:39:00.321] INFO: 8 hot pixels found in step 6
[09:39:01.311] INFO: Collecting data for 5 seconds...
[09:39:06.328] INFO: Done with hot pixel readout
[09:39:17.638] INFO: PixTest:: pg_setup set to default.






[09:39:17.639] INFO: 9 hot pixels found in step 7
[09:39:18.629] INFO: Collecting data for 5 seconds...
[09:39:23.643] INFO: Done with hot pixel readout
[09:39:34.760] INFO: PixTest:: pg_setup set to default.





[09:39:34.761] INFO: 8 hot pixels found in step 8
[09:39:35.751] INFO: Collecting data for 5 seconds...
[09:39:40.768] INFO: Done with hot pixel readout
[09:39:52.308] INFO: PixTest:: pg_setup set to default.





[09:39:52.309] INFO: 10 hot pixels found in step 9
[09:39:53.299] INFO: Collecting data for 5 seconds...
[09:39:58.316] INFO: Done with hot pixel readout
[09:40:09.840] INFO: PixTest:: pg_setup set to default.





[09:40:09.841] INFO: 11 hot pixels found in step 10
[09:40:10.831] INFO: Collecting data for 5 seconds...
[09:40:15.847] INFO: Done with hot pixel readout
[09:40:27.396] INFO: PixTest:: pg_setup set to default.




[09:40:27.397] INFO: 10 hot pixels found in step 11
[09:40:28.386] INFO: Collecting data for 5 seconds...
[09:40:33.403] INFO: Done with hot pixel readout
[09:40:44.953] INFO: PixTest:: pg_setup set to default.






[09:40:44.954] INFO: 11 hot pixels found in step 12
[09:40:45.944] INFO: Collecting data for 5 seconds...
[09:40:50.960] INFO: Done with hot pixel readout
[09:41:02.542] INFO: PixTest:: pg_setup set to default.






[09:41:02.544] INFO: 10 hot pixels found in step 13
[09:41:03.543] INFO: Collecting data for 5 seconds...
[09:41:08.560] INFO: Done with hot pixel readout
[09:41:20.089] INFO: PixTest:: pg_setup set to default.






[09:41:20.090] INFO: 7 hot pixels found in step 14
[09:41:20.124] INFO: 7 hot pixels could not be trimmed and have been masked.
[09:41:20.136] INFO: PixTest::trimHotPixels() done
[09:41:20.151] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C0.dat
[09:41:20.159] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C1.dat
[09:41:20.166] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C2.dat
[09:41:20.171] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C3.dat
[09:41:20.176] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C4.dat
[09:41:20.206] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C5.dat
[09:41:20.212] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C6.dat
[09:41:20.217] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C7.dat
[09:41:20.222] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C8.dat
[09:41:20.227] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C9.dat
[09:41:20.232] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C10.dat
[09:41:20.237] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C11.dat
[09:41:20.243] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C12.dat
[09:41:20.248] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C13.dat
[09:41:20.253] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C14.dat
[09:41:20.259] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C15.dat
[09:41:20.264] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//defaultMaskFile.dat
[09:41:20.281] INFO: enter test to run
[09:42:01.208] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[09:42:01.208] INFO: running: highrate
[09:42:01.213] INFO: ----------------------------------------------------------------------
[09:42:01.213] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[09:42:01.213] INFO: ----------------------------------------------------------------------
[09:42:01.213] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[09:42:01.213] INFO: edge/corner pixel THR is adjusted
[09:42:01.213] INFO: PixTestHighRate::trimHotPixels: step 0...
[09:42:02.172] INFO: Collecting data for 1 seconds...
[09:42:03.175] INFO: Done with hot pixel readout
[09:42:07.173] INFO: PixTest:: pg_setup set to default.
[09:42:07.174] INFO: 0 hot pixels found in step 0
[09:42:07.179] INFO: 0 hot pixels could not be trimmed and have been masked.
[09:42:07.269] INFO: PixTest::trimHotPixels() done
[09:42:07.269] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C0.dat
[09:42:07.277] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C1.dat
[09:42:07.282] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C2.dat
[09:42:07.288] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C3.dat
[09:42:07.293] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C4.dat
[09:42:07.298] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C5.dat
[09:42:07.303] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C6.dat
[09:42:07.308] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C7.dat
[09:42:07.313] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C8.dat
[09:42:07.319] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C9.dat
[09:42:07.324] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C10.dat
[09:42:07.329] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C11.dat
[09:42:07.334] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C12.dat
[09:42:07.339] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C13.dat
[09:42:07.345] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C14.dat
[09:42:07.350] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C15.dat
[09:42:07.355] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//defaultMaskFile.dat
[09:42:07.365] INFO: enter test to run
[09:42:40.976] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[09:42:40.976] INFO: running: xray
[09:42:40.977] INFO: ----------------------------------------------------------------------
[09:42:40.977] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[09:42:40.977] INFO: ----------------------------------------------------------------------
[09:42:41.962] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[09:42:53.619] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[09:43:22.152] INFO: Resuming triggers.
[09:43:33.811] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[09:44:03.465] INFO: Resuming triggers.
[09:44:15.126] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[09:44:45.131] INFO: Resuming triggers.
[09:44:56.786] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[09:45:26.795] INFO: Resuming triggers.
[09:45:38.456] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[09:46:08.496] INFO: Resuming triggers.
[09:46:20.158] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[09:46:49.993] INFO: Resuming triggers.
[09:47:01.657] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[09:47:30.953] INFO: Resuming triggers.
[09:47:42.617] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[09:48:11.687] INFO: Resuming triggers.
[09:48:18.779] INFO: data taking finished, elapsed time: 100 seconds.
[09:48:36.822] INFO: PixTest:: pg_setup set to default.
[09:48:36.826] INFO: PixTestXray::doPhRun() done
[09:48:37.058] INFO: enter test to run
[09:49:08.357] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[09:49:08.357] INFO: running: xray
[09:49:08.359] INFO: ----------------------------------------------------------------------
[09:49:08.359] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[09:49:08.359] INFO: ----------------------------------------------------------------------
[09:49:09.323] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[09:49:16.081] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[09:49:46.466] INFO: Resuming triggers.
[09:49:53.227] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[09:50:23.233] INFO: Resuming triggers.
[09:50:29.996] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[09:51:00.153] INFO: Resuming triggers.
[09:51:06.918] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[09:51:37.251] INFO: Resuming triggers.
[09:51:44.014] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[09:52:14.114] INFO: Resuming triggers.
[09:52:20.880] INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[09:52:50.944] INFO: Resuming triggers.
[09:52:57.706] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[09:53:27.356] INFO: Resuming triggers.
[09:53:34.121] INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[09:54:03.972] INFO: Resuming triggers.
[09:54:10.734] INFO: run duration 60 seconds, buffer almost full (81%), pausing triggers.
[09:54:40.734] INFO: Resuming triggers.
[09:54:47.500] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[09:55:17.717] INFO: Resuming triggers.
[09:55:24.479] INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[09:55:55.110] INFO: Resuming triggers.
[09:56:01.875] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[09:56:32.501] INFO: Resuming triggers.
[09:56:39.265] INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[09:57:10.365] INFO: Resuming triggers.
[09:57:17.125] INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[09:57:48.182] INFO: Resuming triggers.
[09:57:53.840] INFO: data taking finished, elapsed time: 100 seconds.
[09:58:20.301] INFO: PixTest:: pg_setup set to default.
[09:58:20.304] INFO: PixTestXray::doPhRun() done
[09:58:20.461] INFO: enter test to run
[09:59:59.121] INFO: test: HighRate no parameter change
[09:59:59.121] INFO: running: highrate
[09:59:59.137] INFO: ----------------------------------------------------------------------
[09:59:59.137] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[09:59:59.137] INFO: ----------------------------------------------------------------------
[09:59:59.292] INFO: Expecting 768 events.
[10:00:00.426] INFO: 768 events read in total (419ms).
[10:00:00.426] INFO: Test took 1269ms.
[10:00:01.230] INFO: Expecting 41600 events.
[10:00:04.293] INFO: 41600 events read in total (2536ms).
[10:00:04.295] INFO: Test took 3843ms.
[10:00:04.326] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:00:05.059] INFO: Expecting 41600 events.
[10:00:08.244] INFO: 41600 events read in total (2658ms).
[10:00:08.245] INFO: Test took 3903ms.
[10:00:08.277] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:00:09.008] INFO: Expecting 41600 events.
[10:00:12.237] INFO: 41600 events read in total (2702ms).
[10:00:12.238] INFO: Test took 3942ms.
[10:00:12.270] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:00:12.993] INFO: Expecting 41600 events.
[10:00:16.212] INFO: 41600 events read in total (2692ms).
[10:00:16.213] INFO: Test took 3924ms.
[10:00:16.246] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:00:16.973] INFO: Expecting 41600 events.
[10:00:20.199] INFO: 41600 events read in total (2699ms).
[10:00:20.200] INFO: Test took 3936ms.
[10:00:20.232] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:00:20.960] INFO: Expecting 41600 events.
[10:00:24.202] INFO: 41600 events read in total (2715ms).
[10:00:24.203] INFO: Test took 3952ms.
[10:00:24.236] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:00:24.961] INFO: Expecting 41600 events.
[10:00:28.187] INFO: 41600 events read in total (2699ms).
[10:00:28.188] INFO: Test took 3935ms.
[10:00:28.221] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:00:28.944] INFO: Expecting 41600 events.
[10:00:32.161] INFO: 41600 events read in total (2690ms).
[10:00:32.162] INFO: Test took 3923ms.
[10:00:32.195] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:00:32.922] INFO: Expecting 41600 events.
[10:00:36.144] INFO: 41600 events read in total (2695ms).
[10:00:36.145] INFO: Test took 3932ms.
[10:00:36.178] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:00:36.904] INFO: Expecting 41600 events.
[10:00:40.140] INFO: 41600 events read in total (2709ms).
[10:00:40.141] INFO: Test took 3946ms.
[10:00:40.173] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:00:40.900] INFO: Expecting 41600 events.
[10:00:44.124] INFO: 41600 events read in total (2697ms).
[10:00:44.125] INFO: Test took 3933ms.
[10:00:44.158] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:00:44.884] INFO: Expecting 41600 events.
[10:00:48.120] INFO: 41600 events read in total (2709ms).
[10:00:48.121] INFO: Test took 3945ms.
[10:00:48.154] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:00:48.882] INFO: Expecting 41600 events.
[10:00:52.115] INFO: 41600 events read in total (2707ms).
[10:00:52.116] INFO: Test took 3943ms.
[10:00:52.149] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:00:52.872] INFO: Expecting 41600 events.
[10:00:56.099] INFO: 41600 events read in total (2700ms).
[10:00:56.100] INFO: Test took 3934ms.
[10:00:56.133] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:00:56.859] INFO: Expecting 41600 events.
[10:01:00.097] INFO: 41600 events read in total (2711ms).
[10:01:00.098] INFO: Test took 3946ms.
[10:01:00.131] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:01:00.860] INFO: Expecting 41600 events.
[10:01:04.092] INFO: 41600 events read in total (2705ms).
[10:01:04.093] INFO: Test took 3944ms.
[10:01:04.125] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:01:04.854] INFO: Expecting 41600 events.
[10:01:08.078] INFO: 41600 events read in total (2697ms).
[10:01:08.079] INFO: Test took 3936ms.
[10:01:08.111] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:01:08.840] INFO: Expecting 41600 events.
[10:01:12.069] INFO: 41600 events read in total (2702ms).
[10:01:12.070] INFO: Test took 3940ms.
[10:01:12.103] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:01:12.826] INFO: Expecting 41600 events.
[10:01:15.973] INFO: 41600 events read in total (2620ms).
[10:01:15.974] INFO: Test took 3852ms.
[10:01:16.006] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:01:16.735] INFO: Expecting 41600 events.
[10:01:19.782] INFO: 41600 events read in total (2520ms).
[10:01:19.783] INFO: Test took 3758ms.
[10:01:19.815] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:01:20.182] INFO: enter test to run
[10:02:23.288] INFO: test: HighRate no parameter change
[10:02:23.288] INFO: running: highrate
[10:02:23.289] INFO: ----------------------------------------------------------------------
[10:02:23.289] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:02:23.289] INFO: ----------------------------------------------------------------------
[10:02:23.908] INFO: Expecting 208000 events.
[10:02:35.720] INFO: 208000 events read in total (11285ms).
[10:02:35.723] INFO: Test took 12425ms.
[10:02:35.863] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:02:36.114] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 3 0 0 0 0 0 0 0
[10:02:36.115] INFO: number of red-efficiency pixels: 70 46 97 123 173 124 134 77 138 131 112 100 125 59 26 30
[10:02:36.115] INFO: number of X-ray hits detected: 62579 39450 65281 101661 112098 115180 111676 74230 70494 91147 95333 80793 85906 52476 19997 25359
[10:02:36.115] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:02:36.115] INFO: number of Vcal hits detected: 207928 207954 207899 207875 207821 207874 207863 207923 207703 207861 207887 207900 207870 207941 207972 207969
[10:02:36.115] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 100.0 99.9 100.0 100.0 100.0
[10:02:36.115] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 100.0 99.9 100.0 100.0 100.0
[10:02:36.115] INFO: X-ray hit rate [MHz/cm2]: 18.3 11.6 19.1 29.8 32.9 33.8 32.7 21.8 20.7 26.7 27.9 23.7 25.2 15.4 5.9 7.4
[10:02:36.115] INFO: PixTestHighRate::doXPixelAlive() done
[10:02:36.166] INFO: PixTest:: pg_setup set to default.
[10:02:36.182] INFO: enter test to run
[10:03:34.192] INFO: test: HighRate no parameter change
[10:03:34.192] INFO: running: highrate
[10:03:34.193] INFO: ----------------------------------------------------------------------
[10:03:34.193] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:03:34.193] INFO: ----------------------------------------------------------------------
[10:03:34.811] INFO: Expecting 208000 events.
[10:03:48.433] INFO: 208000 events read in total (13095ms).
[10:03:48.438] INFO: Test took 14234ms.
[10:03:48.735] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:03:49.035] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 3 0 0 0 0 0 0 0
[10:03:49.035] INFO: number of red-efficiency pixels: 209 129 299 358 552 467 622 305 319 296 418 293 340 180 45 69
[10:03:49.035] INFO: number of X-ray hits detected: 135449 85801 139762 219814 241012 248130 240020 158104 149786 195260 204020 173459 183160 112713 42692 54425
[10:03:49.035] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:03:49.035] INFO: number of Vcal hits detected: 207772 207868 207656 207615 207393 207486 207303 207676 207507 207656 207550 207689 207633 207812 207950 207928
[10:03:49.035] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.7 99.8 99.7 99.9 99.8 99.8 99.8 99.9 99.8 99.9 100.0 100.0
[10:03:49.035] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.8 99.7 99.8 99.7 99.8 99.8 99.8 99.8 99.9 99.8 99.9 100.0 100.0
[10:03:49.035] INFO: X-ray hit rate [MHz/cm2]: 39.7 25.1 41.0 64.4 70.6 72.7 70.4 46.3 43.9 57.2 59.8 50.8 53.7 33.0 12.5 16.0
[10:03:49.035] INFO: PixTestHighRate::doXPixelAlive() done
[10:03:49.085] INFO: PixTest:: pg_setup set to default.
[10:03:49.099] INFO: enter test to run
[10:04:11.215] INFO: test: HighRate no parameter change
[10:04:11.216] INFO: running: highrate
[10:04:11.217] INFO: ----------------------------------------------------------------------
[10:04:11.217] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:04:11.217] INFO: ----------------------------------------------------------------------
[10:04:11.836] INFO: Expecting 208000 events.
[10:04:27.283] INFO: 208000 events read in total (14920ms).
[10:04:27.292] INFO: Test took 16066ms.
[10:04:27.728] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:04:28.079] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 3 0 0 0 0 0 0 0
[10:04:28.079] INFO: number of red-efficiency pixels: 506 238 652 803 1220 1068 1448 647 612 688 1029 699 795 385 91 97
[10:04:28.079] INFO: number of X-ray hits detected: 204302 128348 210787 329712 364277 373470 360341 239954 224051 295508 306852 261578 278037 170557 65139 81321
[10:04:28.079] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:04:28.079] INFO: number of Vcal hits detected: 207346 207736 207119 207059 206414 206596 206064 207164 207149 207127 206716 207190 207062 207558 207905 207902
[10:04:28.079] INFO: Vcal hit fiducial efficiency (%): 99.7 99.9 99.6 99.6 99.3 99.4 99.2 99.6 99.7 99.6 99.4 99.7 99.6 99.8 100.0 100.0
[10:04:28.079] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.6 99.5 99.2 99.3 99.1 99.6 99.6 99.6 99.4 99.6 99.5 99.8 100.0 100.0
[10:04:28.079] INFO: X-ray hit rate [MHz/cm2]: 59.9 37.6 61.8 96.6 106.8 109.5 105.6 70.3 65.7 86.6 89.9 76.7 81.5 50.0 19.1 23.8
[10:04:28.079] INFO: PixTestHighRate::doXPixelAlive() done
[10:04:28.127] INFO: PixTest:: pg_setup set to default.
[10:04:28.145] INFO: enter test to run
[10:04:38.487] INFO: test: exit no parameter change
[10:04:38.868] QUIET: Connection to board 33 closed.
[10:04:38.881] INFO: pXar: this is the end, my friend