[11:54:42.068] INFO: *** Welcome to pxar ***
[11:54:42.068] INFO: *** Today: 2016/05/23
[11:54:42.089] INFO: *** Version: v1.9.0-796-gef167-dirty
[11:54:42.089] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Y-T-NH_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-T-NH_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//dacParameters35_C15.dat
[11:54:42.090] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Y-T-NH_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-T-NH_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//tbmParameters_C0b.dat
[11:54:42.091] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Y-T-NH_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//defaultMaskFile.dat
[11:54:42.091] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Y-T-NH_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-T-NH_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C15.dat
[11:54:42.161] INFO: clk: 4
[11:54:42.161] INFO: ctr: 4
[11:54:42.161] INFO: sda: 19
[11:54:42.161] INFO: tin: 9
[11:54:42.161] INFO: level: 15
[11:54:42.161] INFO: triggerdelay: 0
[11:54:42.161] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[11:54:42.161] INFO: Log level: INFO
[11:54:42.179] QUIET: Connection to board DTB_WREK4U opened.
[11:54:42.183] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 32
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREK4U
MAC address: 40D855118020
Hostname: pixelDTB032
Comment:
------------------------------------------------------
[11:54:42.186] INFO: RPC call hashes of host and DTB match: 398089610
[11:54:43.734] INFO: DUT info:
[11:54:43.734] INFO: The DUT currently contains the following objects:
[11:54:43.734] INFO: 2 TBM Cores tbm08c (2 ON)
[11:54:43.734] INFO: TBM Core alpha (0): 7 registers set
[11:54:43.734] INFO: TBM Core beta (1): 7 registers set
[11:54:43.734] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[11:54:43.734] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[11:54:43.734] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[11:54:43.734] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[11:54:43.734] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[11:54:43.734] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[11:54:43.734] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[11:54:43.734] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[11:54:43.734] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[11:54:43.734] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[11:54:43.734] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[11:54:43.734] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[11:54:43.734] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[11:54:43.734] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[11:54:43.734] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[11:54:43.735] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[11:54:43.735] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[11:54:44.183] INFO: enter 'restricted' command line mode
[11:54:44.183] INFO: enter test to run
[11:54:53.794] INFO: test: PixelAlive no parameter change
[11:54:53.794] INFO: running: pixelalive
[11:54:53.843] INFO: ----------------------------------------------------------------------
[11:54:53.843] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[11:54:53.843] INFO: ----------------------------------------------------------------------
[11:54:54.168] INFO: Expecting 41600 events.
[11:54:58.514] INFO: 41600 events read in total (3627ms).
[11:54:58.681] INFO: Test took 4835ms.
[11:54:58.694] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:54:58.973] INFO: PixTestAlive::aliveTest() done
[11:54:58.973] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 1 1 0 0 0 0 0 0 0
[11:54:59.066] INFO: enter test to run
[11:55:51.618] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[11:55:51.618] INFO: running: highrate
[11:55:51.618] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Y-T-NH_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-T-NH_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[11:55:51.841] INFO: ----------------------------------------------------------------------
[11:55:51.841] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[11:55:51.841] INFO: ----------------------------------------------------------------------
[11:55:51.841] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[11:55:51.842] INFO: edge/corner pixel THR is adjusted
[11:55:51.842] INFO: PixTestHighRate::trimHotPixels: step 0...
[11:55:52.800] INFO: Collecting data for 5 seconds...
[11:55:57.817] INFO: Done with hot pixel readout
[11:56:10.103] INFO: PixTest:: pg_setup set to default.


[11:56:10.104] INFO: 128 hot pixels found in step 0
[11:56:11.100] INFO: Collecting data for 5 seconds...
[11:56:16.117] INFO: Done with hot pixel readout
[11:56:28.607] INFO: PixTest:: pg_setup set to default.




[11:56:28.609] INFO: 109 hot pixels found in step 1
[11:56:29.611] INFO: Collecting data for 5 seconds...
[11:56:34.627] INFO: Done with hot pixel readout
[11:56:47.059] INFO: PixTest:: pg_setup set to default.




[11:56:47.060] INFO: 110 hot pixels found in step 2
[11:56:48.058] INFO: Collecting data for 5 seconds...
[11:56:53.073] INFO: Done with hot pixel readout
[11:57:05.538] INFO: PixTest:: pg_setup set to default.





[11:57:05.539] INFO: 96 hot pixels found in step 3
[11:57:06.538] INFO: Collecting data for 5 seconds...
[11:57:11.553] INFO: Done with hot pixel readout
[11:57:23.876] INFO: PixTest:: pg_setup set to default.






[11:57:23.877] INFO: 103 hot pixels found in step 4
[11:57:24.876] INFO: Collecting data for 5 seconds...
[11:57:29.891] INFO: Done with hot pixel readout
[11:57:42.269] INFO: PixTest:: pg_setup set to default.




[11:57:42.270] INFO: 94 hot pixels found in step 5
[11:57:43.268] INFO: Collecting data for 5 seconds...
[11:57:48.283] INFO: Done with hot pixel readout
[11:58:00.608] INFO: PixTest:: pg_setup set to default.








[11:58:00.609] INFO: 92 hot pixels found in step 6
[11:58:01.608] INFO: Collecting data for 5 seconds...
[11:58:06.623] INFO: Done with hot pixel readout
[11:58:18.514] INFO: PixTest:: pg_setup set to default.







[11:58:18.515] INFO: 77 hot pixels found in step 7
[11:58:19.516] INFO: Collecting data for 5 seconds...
[11:58:24.531] INFO: Done with hot pixel readout
[11:58:36.798] INFO: PixTest:: pg_setup set to default.











[11:58:36.800] INFO: 77 hot pixels found in step 8
[11:58:37.800] INFO: Collecting data for 5 seconds...
[11:58:42.817] INFO: Done with hot pixel readout
[11:58:54.502] INFO: PixTest:: pg_setup set to default.






[11:58:54.503] INFO: 80 hot pixels found in step 9
[11:58:55.505] INFO: Collecting data for 5 seconds...
[11:59:00.521] INFO: Done with hot pixel readout
[11:59:11.930] INFO: PixTest:: pg_setup set to default.








[11:59:11.931] INFO: 68 hot pixels found in step 10
[11:59:12.931] INFO: Collecting data for 5 seconds...
[11:59:17.948] INFO: Done with hot pixel readout
[11:59:29.702] INFO: PixTest:: pg_setup set to default.








[11:59:29.703] INFO: 57 hot pixels found in step 11
[11:59:30.703] INFO: Collecting data for 5 seconds...
[11:59:35.719] INFO: Done with hot pixel readout
[11:59:47.827] INFO: PixTest:: pg_setup set to default.












[11:59:47.828] INFO: 72 hot pixels found in step 12
[11:59:48.828] INFO: Collecting data for 5 seconds...
[11:59:53.844] INFO: Done with hot pixel readout
[12:00:05.000] INFO: PixTest:: pg_setup set to default.






[12:00:05.001] INFO: 63 hot pixels found in step 13
[12:00:06.003] INFO: Collecting data for 5 seconds...
[12:00:12.020] INFO: Done with hot pixel readout
[12:00:24.321] INFO: PixTest:: pg_setup set to default.







[12:00:24.322] INFO: 58 hot pixels found in step 14
[12:00:24.367] INFO: 58 hot pixels could not be trimmed and have been masked.
[12:00:24.370] INFO: PixTest::trimHotPixels() done
[12:00:24.370] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NH_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C0.dat
[12:00:24.376] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NH_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C1.dat
[12:00:24.382] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NH_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C2.dat
[12:00:24.388] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NH_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C3.dat
[12:00:24.393] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NH_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C4.dat
[12:00:24.399] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NH_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C5.dat
[12:00:24.404] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NH_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C6.dat
[12:00:24.410] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NH_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C7.dat
[12:00:24.415] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NH_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C8.dat
[12:00:24.420] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NH_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C9.dat
[12:00:24.426] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NH_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C10.dat
[12:00:24.431] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NH_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C11.dat
[12:00:24.437] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NH_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C12.dat
[12:00:24.442] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NH_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C13.dat
[12:00:24.447] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NH_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C14.dat
[12:00:24.453] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NH_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C15.dat
[12:00:24.459] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Y-T-NH_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//defaultMaskFile.dat
[12:00:24.470] INFO: enter test to run
[12:00:44.535] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[12:00:44.535] INFO: running: highrate
[12:00:44.540] INFO: ----------------------------------------------------------------------
[12:00:44.540] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[12:00:44.540] INFO: ----------------------------------------------------------------------
[12:00:44.540] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[12:00:44.540] INFO: edge/corner pixel THR is adjusted
[12:00:44.540] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:00:45.497] INFO: Collecting data for 1 seconds...
[12:00:46.501] INFO: Done with hot pixel readout
[12:00:51.072] INFO: PixTest:: pg_setup set to default.
[12:00:51.073] INFO: 0 hot pixels found in step 0
[12:00:51.079] INFO: 0 hot pixels could not be trimmed and have been masked.
[12:00:51.146] INFO: PixTest::trimHotPixels() done
[12:00:51.146] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NH_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C0.dat
[12:00:51.153] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NH_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C1.dat
[12:00:51.160] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NH_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C2.dat
[12:00:51.165] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NH_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C3.dat
[12:00:51.171] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NH_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C4.dat
[12:00:51.176] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NH_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C5.dat
[12:00:51.182] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NH_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C6.dat
[12:00:51.188] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NH_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C7.dat
[12:00:51.193] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NH_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C8.dat
[12:00:51.199] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NH_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C9.dat
[12:00:51.204] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NH_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C10.dat
[12:00:51.210] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NH_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C11.dat
[12:00:51.215] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NH_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C12.dat
[12:00:51.221] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NH_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C13.dat
[12:00:51.226] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NH_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C14.dat
[12:00:51.232] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-T-NH_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C15.dat
[12:00:51.238] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Y-T-NH_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//defaultMaskFile.dat
[12:00:51.247] INFO: enter test to run
[12:01:14.103] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[12:01:14.103] INFO: running: xray
[12:01:14.105] INFO: ----------------------------------------------------------------------
[12:01:14.105] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:01:14.105] INFO: ----------------------------------------------------------------------
[12:01:15.085] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:01:25.488] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[12:01:55.600] INFO: Resuming triggers.
[12:02:06.008] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[12:02:35.589] INFO: Resuming triggers.
[12:02:45.990] INFO: run duration 31 seconds, buffer almost full (81%), pausing triggers.
[12:03:15.544] INFO: Resuming triggers.
[12:03:25.943] INFO: run duration 41 seconds, buffer almost full (81%), pausing triggers.
[12:03:55.546] INFO: Resuming triggers.
[12:04:05.943] INFO: run duration 51 seconds, buffer almost full (81%), pausing triggers.
[12:04:35.561] INFO: Resuming triggers.
[12:04:45.959] INFO: run duration 62 seconds, buffer almost full (81%), pausing triggers.
[12:05:15.539] INFO: Resuming triggers.
[12:05:25.943] INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[12:05:55.486] INFO: Resuming triggers.
[12:06:05.886] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[12:06:35.467] INFO: Resuming triggers.
[12:06:45.870] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[12:07:15.488] INFO: Resuming triggers.
[12:07:22.205] INFO: data taking finished, elapsed time: 100 seconds.
[12:07:41.568] INFO: PixTest:: pg_setup set to default.
[12:07:41.572] INFO: PixTestXray::doPhRun() done
[12:07:41.764] INFO: enter test to run
[12:08:24.348] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[12:08:24.348] INFO: running: xray
[12:08:24.349] INFO: ----------------------------------------------------------------------
[12:08:24.349] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:08:24.349] INFO: ----------------------------------------------------------------------
[12:08:25.314] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:08:31.025] INFO: run duration 5 seconds, buffer almost full (81%), pausing triggers.
[12:09:01.211] INFO: Resuming triggers.
[12:09:06.923] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[12:09:37.101] INFO: Resuming triggers.
[12:09:42.816] INFO: run duration 17 seconds, buffer almost full (81%), pausing triggers.
[12:10:13.587] INFO: Resuming triggers.
[12:10:19.296] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[12:10:48.761] INFO: Resuming triggers.
[12:10:54.471] INFO: run duration 28 seconds, buffer almost full (81%), pausing triggers.
[12:11:24.273] INFO: Resuming triggers.
[12:11:29.987] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[12:11:59.786] INFO: Resuming triggers.
[12:12:05.500] INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[12:12:35.047] INFO: Resuming triggers.
[12:12:40.756] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[12:13:10.377] INFO: Resuming triggers.
[12:13:16.083] INFO: run duration 51 seconds, buffer almost full (81%), pausing triggers.
[12:13:45.826] INFO: Resuming triggers.
[12:13:51.535] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[12:14:21.240] INFO: Resuming triggers.
[12:14:26.952] INFO: run duration 62 seconds, buffer almost full (81%), pausing triggers.
[12:14:56.593] INFO: Resuming triggers.
[12:15:02.297] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[12:15:31.951] INFO: Resuming triggers.
[12:15:37.657] INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[12:16:07.200] INFO: Resuming triggers.
[12:16:12.909] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[12:16:41.899] INFO: Resuming triggers.
[12:16:47.609] INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[12:17:17.263] INFO: Resuming triggers.
[12:17:22.970] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[12:17:52.709] INFO: Resuming triggers.
[12:17:58.415] INFO: run duration 96 seconds, buffer almost full (81%), pausing triggers.
[12:18:28.137] INFO: Resuming triggers.
[12:18:31.397] INFO: data taking finished, elapsed time: 100 seconds.
[12:18:48.532] INFO: PixTest:: pg_setup set to default.
[12:18:48.536] INFO: PixTestXray::doPhRun() done
[12:18:48.685] INFO: enter test to run
[12:19:11.247] INFO: test: HighRate no parameter change
[12:19:11.247] INFO: running: highrate
[12:19:11.257] INFO: ----------------------------------------------------------------------
[12:19:11.257] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[12:19:11.257] INFO: ----------------------------------------------------------------------
[12:19:11.413] INFO: Expecting 768 events.
[12:19:12.543] INFO: 768 events read in total (415ms).
[12:19:12.543] INFO: Test took 1264ms.
[12:19:13.346] INFO: Expecting 41600 events.
[12:19:16.538] INFO: 41600 events read in total (2665ms).
[12:19:16.540] INFO: Test took 3976ms.
[12:19:16.581] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:19:17.291] INFO: Expecting 41600 events.
[12:19:20.551] INFO: 41600 events read in total (2733ms).
[12:19:20.552] INFO: Test took 3950ms.
[12:19:20.593] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:19:21.306] INFO: Expecting 41600 events.
[12:19:24.484] INFO: 41600 events read in total (2651ms).
[12:19:24.485] INFO: Test took 3872ms.
[12:19:24.526] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:19:25.233] INFO: Expecting 41600 events.
[12:19:28.386] INFO: 41600 events read in total (2626ms).
[12:19:28.387] INFO: Test took 3839ms.
[12:19:28.428] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:19:29.139] INFO: Expecting 41600 events.
[12:19:32.430] INFO: 41600 events read in total (2764ms).
[12:19:32.431] INFO: Test took 3982ms.
[12:19:32.473] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:19:33.180] INFO: Expecting 41600 events.
[12:19:36.474] INFO: 41600 events read in total (2767ms).
[12:19:36.475] INFO: Test took 3982ms.
[12:19:36.518] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:19:37.225] INFO: Expecting 41600 events.
[12:19:40.529] INFO: 41600 events read in total (2777ms).
[12:19:40.530] INFO: Test took 3991ms.
[12:19:40.572] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:19:41.280] INFO: Expecting 41600 events.
[12:19:44.587] INFO: 41600 events read in total (2780ms).
[12:19:44.589] INFO: Test took 3997ms.
[12:19:44.630] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:19:45.341] INFO: Expecting 41600 events.
[12:19:48.221] INFO: 41600 events read in total (2353ms).
[12:19:48.222] INFO: Test took 3571ms.
[12:19:48.264] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:19:48.976] INFO: Expecting 41600 events.
[12:19:52.294] INFO: 41600 events read in total (2791ms).
[12:19:52.295] INFO: Test took 4010ms.
[12:19:52.337] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:19:53.047] INFO: Expecting 41600 events.
[12:19:56.347] INFO: 41600 events read in total (2773ms).
[12:19:56.348] INFO: Test took 3990ms.
[12:19:56.390] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:19:57.099] INFO: Expecting 41600 events.
[12:20:00.402] INFO: 41600 events read in total (2776ms).
[12:20:00.403] INFO: Test took 3992ms.
[12:20:00.445] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:20:01.156] INFO: Expecting 41600 events.
[12:20:04.421] INFO: 41600 events read in total (2738ms).
[12:20:04.422] INFO: Test took 3955ms.
[12:20:04.464] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:20:05.171] INFO: Expecting 41600 events.
[12:20:08.287] INFO: 41600 events read in total (2589ms).
[12:20:08.288] INFO: Test took 3802ms.
[12:20:08.329] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:20:09.040] INFO: Expecting 41600 events.
[12:20:12.364] INFO: 41600 events read in total (2797ms).
[12:20:12.365] INFO: Test took 4014ms.
[12:20:12.406] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:20:13.112] INFO: Expecting 41600 events.
[12:20:16.437] INFO: 41600 events read in total (2798ms).
[12:20:16.438] INFO: Test took 4012ms.
[12:20:16.480] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:20:17.192] INFO: Expecting 41600 events.
[12:20:20.481] INFO: 41600 events read in total (2762ms).
[12:20:20.482] INFO: Test took 3980ms.
[12:20:20.523] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:20:21.235] INFO: Expecting 41600 events.
[12:20:24.597] INFO: 41600 events read in total (2763ms).
[12:20:24.598] INFO: Test took 4054ms.
[12:20:24.640] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:20:25.352] INFO: Expecting 41600 events.
[12:20:28.628] INFO: 41600 events read in total (2750ms).
[12:20:28.629] INFO: Test took 3969ms.
[12:20:28.670] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:20:29.383] INFO: Expecting 41600 events.
[12:20:32.476] INFO: 41600 events read in total (2566ms).
[12:20:32.477] INFO: Test took 3787ms.
[12:20:32.518] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:20:32.877] INFO: enter test to run
[12:20:50.695] INFO: test: HighRate no parameter change
[12:20:50.695] INFO: running: highrate
[12:20:50.696] INFO: ----------------------------------------------------------------------
[12:20:50.696] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:20:50.696] INFO: ----------------------------------------------------------------------
[12:20:51.317] INFO: Expecting 208000 events.
[12:21:03.235] INFO: 208000 events read in total (11391ms).
[12:21:03.239] INFO: Test took 12534ms.
[12:21:03.420] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:21:03.684] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 1 1 0 0 0 0 0 0 0
[12:21:03.684] INFO: number of red-efficiency pixels: 82 61 102 190 249 201 239 158 109 211 169 136 136 79 33 37
[12:21:03.684] INFO: number of X-ray hits detected: 80641 57815 86982 141196 153290 146679 154928 106039 95074 127600 125049 107118 108297 65774 27746 29985
[12:21:03.684] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:21:03.684] INFO: number of Vcal hits detected: 207917 207938 207894 207803 207740 207792 207748 207784 207842 207783 207826 207861 207861 207919 207967 207963
[12:21:03.684] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[12:21:03.685] INFO: Vcal hit overall efficiency (%): 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[12:21:03.685] INFO: X-ray hit rate [MHz/cm2]: 23.6 16.9 25.5 41.4 44.9 43.0 45.4 31.1 27.9 37.4 36.7 31.4 31.7 19.3 8.1 8.8
[12:21:03.685] INFO: PixTestHighRate::doXPixelAlive() done
[12:21:03.732] INFO: PixTest:: pg_setup set to default.
[12:21:03.747] INFO: enter test to run
[12:21:40.390] INFO: test: HighRate no parameter change
[12:21:40.390] INFO: running: highrate
[12:21:40.391] INFO: ----------------------------------------------------------------------
[12:21:40.391] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:21:40.391] INFO: ----------------------------------------------------------------------
[12:21:40.004] INFO: Expecting 208000 events.
[12:21:55.202] INFO: 208000 events read in total (13671ms).
[12:21:55.209] INFO: Test took 14810ms.
[12:21:55.585] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:21:55.916] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 1 1 0 0 0 0 0 0 0
[12:21:55.916] INFO: number of red-efficiency pixels: 231 225 357 694 1050 804 958 564 325 744 651 451 454 228 66 78
[12:21:55.916] INFO: number of X-ray hits detected: 166266 119309 179274 291894 314018 302215 318745 218110 195105 263397 257840 219117 223602 134959 57459 62403
[12:21:55.916] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:21:55.916] INFO: number of Vcal hits detected: 207747 207758 207595 207190 206742 207099 206853 207285 207602 207162 207260 207511 207503 207760 207930 207919
[12:21:55.916] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.8 99.7 99.4 99.6 99.5 99.7 99.8 99.6 99.7 99.8 99.8 99.9 100.0 100.0
[12:21:55.916] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.6 99.4 99.6 99.4 99.7 99.8 99.6 99.6 99.8 99.8 99.9 100.0 100.0
[12:21:55.916] INFO: X-ray hit rate [MHz/cm2]: 48.7 35.0 52.5 85.6 92.0 88.6 93.4 63.9 57.2 77.2 75.6 64.2 65.5 39.6 16.8 18.3
[12:21:55.916] INFO: PixTestHighRate::doXPixelAlive() done
[12:21:55.964] INFO: PixTest:: pg_setup set to default.
[12:21:55.980] INFO: enter test to run
[12:22:27.030] INFO: test: HighRate no parameter change
[12:22:27.030] INFO: running: highrate
[12:22:27.031] INFO: ----------------------------------------------------------------------
[12:22:27.031] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:22:27.031] INFO: ----------------------------------------------------------------------
[12:22:27.649] INFO: Expecting 208000 events.
[12:22:44.481] INFO: 208000 events read in total (16306ms).
[12:22:44.490] INFO: Test took 17451ms.
[12:22:45.078] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:22:45.472] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 1 1 0 0 0 0 0 0 0
[12:22:45.472] INFO: number of red-efficiency pixels: 527 461 794 1659 2227 1852 2273 1297 678 1650 1545 1021 1139 527 130 126
[12:22:45.472] INFO: number of X-ray hits detected: 249807 178361 267653 436997 471335 450942 477917 327955 293531 395367 387095 329464 336338 203866 87052 93952
[12:22:45.472] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:22:45.472] INFO: number of Vcal hits detected: 207346 207457 206842 205529 204258 205247 204013 205988 207148 205634 205853 206680 206537 207356 207864 207871
[12:22:45.472] INFO: Vcal hit fiducial efficiency (%): 99.7 99.8 99.5 98.9 98.4 98.8 98.3 99.2 99.6 99.0 99.1 99.4 99.4 99.7 99.9 99.9
[12:22:45.472] INFO: Vcal hit overall efficiency (%): 99.7 99.7 99.4 98.8 98.2 98.7 98.1 99.0 99.6 98.9 99.0 99.4 99.3 99.7 99.9 99.9
[12:22:45.472] INFO: X-ray hit rate [MHz/cm2]: 73.2 52.3 78.5 128.1 138.2 132.2 140.1 96.1 86.0 115.9 113.5 96.6 98.6 59.8 25.5 27.5
[12:22:45.472] INFO: PixTestHighRate::doXPixelAlive() done
[12:22:45.522] INFO: PixTest:: pg_setup set to default.
[12:22:45.544] INFO: enter test to run
[12:22:51.814] INFO: test: exit no parameter change
[12:22:52.209] QUIET: Connection to board 32 closed.
[12:22:52.220] INFO: pXar: this is the end, my friend