[16:51:20.719] INFO: *** Welcome to pxar ***
[16:51:20.719] INFO: *** Today: 2016/07/18
[16:51:20.736] INFO: *** Version: v1.9.0-814-g7497
[16:51:20.736] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-4-41_FPIXTest-17C-FNAL-160713-1229_2016-07-13_12h29m_1468430967/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-4-41_FPIXTest-17C-FNAL-160713-1229_2016-07-13_12h29m_1468430967/000_FPIXTest_p17//dacParameters35_C15.dat
[16:51:20.786] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-4-41_FPIXTest-17C-FNAL-160713-1229_2016-07-13_12h29m_1468430967/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-4-41_FPIXTest-17C-FNAL-160713-1229_2016-07-13_12h29m_1468430967/000_FPIXTest_p17//tbmParameters_C0b.dat
[16:51:20.786] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-4-41_FPIXTest-17C-FNAL-160713-1229_2016-07-13_12h29m_1468430967/000_FPIXTest_p17//defaultMaskFile.dat
[16:51:20.786] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-4-41_FPIXTest-17C-FNAL-160713-1229_2016-07-13_12h29m_1468430967/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-4-41_FPIXTest-17C-FNAL-160713-1229_2016-07-13_12h29m_1468430967/000_FPIXTest_p17//trimParameters35_C15.dat
[16:51:20.918] INFO: clk: 4
[16:51:20.918] INFO: ctr: 4
[16:51:20.918] INFO: sda: 19
[16:51:20.918] INFO: tin: 9
[16:51:20.919] INFO: level: 15
[16:51:20.919] INFO: triggerdelay: 0
[16:51:20.919] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[16:51:20.919] INFO: Log level: INFO
[16:51:20.937] QUIET: Connection to board DTB_WREKRL opened.
[16:51:20.940] 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:
------------------------------------------------------
[16:51:20.943] INFO: RPC call hashes of host and DTB match: 398089610
[16:51:22.476] INFO: DUT info:
[16:51:22.476] INFO: The DUT currently contains the following objects:
[16:51:22.476] INFO: 2 TBM Cores tbm08c (2 ON)
[16:51:22.476] INFO: TBM Core alpha (0): 7 registers set
[16:51:22.476] INFO: TBM Core beta (1): 7 registers set
[16:51:22.476] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[16:51:22.476] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[16:51:22.476] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[16:51:22.476] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[16:51:22.476] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[16:51:22.476] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[16:51:22.476] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[16:51:22.476] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[16:51:22.476] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[16:51:22.477] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[16:51:22.477] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[16:51:22.477] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[16:51:22.477] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[16:51:22.477] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[16:51:22.477] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[16:51:22.477] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[16:51:22.477] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[16:51:22.880] INFO: enter 'restricted' command line mode
[16:51:22.880] INFO: enter test to run
[16:51:34.772] INFO: test: PixelAlive no parameter change
[16:51:34.772] INFO: running: pixelalive
[16:51:34.781] INFO: ----------------------------------------------------------------------
[16:51:34.781] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[16:51:34.781] INFO: ----------------------------------------------------------------------
[16:51:35.098] INFO: Expecting 41600 events.
[16:51:39.437] INFO: 41600 events read in total (3621ms).
[16:51:39.607] INFO: Test took 4823ms.
[16:51:39.616] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:51:39.878] INFO: PixTestAlive::aliveTest() done
[16:51:39.878] INFO: number of dead pixels (per ROC): 0 0 0 1 0 0 0 0 0 0 2 0 0 0 0 0
[16:51:39.910] INFO: enter test to run
[16:52:18.604] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[16:52:18.604] INFO: running: highrate
[16:52:18.604] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-4-41_FPIXTest-17C-FNAL-160713-1229_2016-07-13_12h29m_1468430967/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-4-41_FPIXTest-17C-FNAL-160713-1229_2016-07-13_12h29m_1468430967/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[16:52:18.874] INFO: ----------------------------------------------------------------------
[16:52:18.874] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[16:52:18.874] INFO: ----------------------------------------------------------------------
[16:52:18.874] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[16:52:18.874] INFO: edge/corner pixel THR is adjusted
[16:52:18.874] INFO: PixTestHighRate::trimHotPixels: step 0...
[16:52:19.834] INFO: Collecting data for 5 seconds...
[16:52:24.850] INFO: Done with hot pixel readout
[16:52:36.346] INFO: PixTest:: pg_setup set to default.

[16:52:36.347] INFO: 29 hot pixels found in step 0
[16:52:37.362] INFO: Collecting data for 5 seconds...
[16:52:42.378] INFO: Done with hot pixel readout
[16:52:53.930] INFO: PixTest:: pg_setup set to default.
[16:52:53.931] INFO: 40 hot pixels found in step 1
[16:52:54.921] INFO: Collecting data for 5 seconds...
[16:52:59.937] INFO: Done with hot pixel readout
[16:53:11.406] INFO: PixTest:: pg_setup set to default.
[16:53:11.407] INFO: 25 hot pixels found in step 2
[16:53:12.396] INFO: Collecting data for 5 seconds...
[16:53:17.413] INFO: Done with hot pixel readout
[16:53:28.961] INFO: PixTest:: pg_setup set to default.
[16:53:28.962] INFO: 26 hot pixels found in step 3
[16:53:29.951] INFO: Collecting data for 5 seconds...
[16:53:34.968] INFO: Done with hot pixel readout
[16:53:46.497] INFO: PixTest:: pg_setup set to default.
[16:53:46.497] INFO: 23 hot pixels found in step 4
[16:53:47.487] INFO: Collecting data for 5 seconds...
[16:53:52.503] INFO: Done with hot pixel readout
[16:54:04.326] INFO: PixTest:: pg_setup set to default.


[16:54:04.327] INFO: 17 hot pixels found in step 5
[16:54:05.316] INFO: Collecting data for 5 seconds...
[16:54:10.333] INFO: Done with hot pixel readout
[16:54:22.265] INFO: PixTest:: pg_setup set to default.


[16:54:22.266] INFO: 23 hot pixels found in step 6
[16:54:23.255] INFO: Collecting data for 5 seconds...
[16:54:28.271] INFO: Done with hot pixel readout
[16:54:40.099] INFO: PixTest:: pg_setup set to default.

[16:54:40.100] INFO: 23 hot pixels found in step 7
[16:54:41.089] INFO: Collecting data for 5 seconds...
[16:54:46.106] INFO: Done with hot pixel readout
[16:54:57.664] INFO: PixTest:: pg_setup set to default.


[16:54:57.665] INFO: 16 hot pixels found in step 8
[16:54:58.653] INFO: Collecting data for 5 seconds...
[16:55:03.669] INFO: Done with hot pixel readout
[16:55:15.473] INFO: PixTest:: pg_setup set to default.





[16:55:15.474] INFO: 21 hot pixels found in step 9
[16:55:16.463] INFO: Collecting data for 5 seconds...
[16:55:21.480] INFO: Done with hot pixel readout
[16:55:33.266] INFO: PixTest:: pg_setup set to default.


[16:55:33.267] INFO: 13 hot pixels found in step 10
[16:55:34.257] INFO: Collecting data for 5 seconds...
[16:55:39.273] INFO: Done with hot pixel readout
[16:55:51.100] INFO: PixTest:: pg_setup set to default.



[16:55:51.101] INFO: 14 hot pixels found in step 11
[16:55:52.091] INFO: Collecting data for 5 seconds...
[16:55:57.109] INFO: Done with hot pixel readout
[16:56:08.649] INFO: PixTest:: pg_setup set to default.




[16:56:08.650] INFO: 14 hot pixels found in step 12
[16:56:09.640] INFO: Collecting data for 5 seconds...
[16:56:14.654] INFO: Done with hot pixel readout
[16:56:26.143] INFO: PixTest:: pg_setup set to default.



[16:56:26.144] INFO: 16 hot pixels found in step 13
[16:56:27.133] INFO: Collecting data for 5 seconds...
[16:56:32.150] INFO: Done with hot pixel readout
[16:56:43.688] INFO: PixTest:: pg_setup set to default.


[16:56:43.689] INFO: 12 hot pixels found in step 14
[16:56:43.722] INFO: 12 hot pixels could not be trimmed and have been masked.
[16:56:43.726] INFO: PixTest::trimHotPixels() done
[16:56:43.732] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-41_FPIXTest-17C-FNAL-160713-1229_2016-07-13_12h29m_1468430967/000_FPIXTest_p17//trimParameters35_C0.dat
[16:56:43.737] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-41_FPIXTest-17C-FNAL-160713-1229_2016-07-13_12h29m_1468430967/000_FPIXTest_p17//trimParameters35_C1.dat
[16:56:43.743] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-41_FPIXTest-17C-FNAL-160713-1229_2016-07-13_12h29m_1468430967/000_FPIXTest_p17//trimParameters35_C2.dat
[16:56:43.748] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-41_FPIXTest-17C-FNAL-160713-1229_2016-07-13_12h29m_1468430967/000_FPIXTest_p17//trimParameters35_C3.dat
[16:56:43.754] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-41_FPIXTest-17C-FNAL-160713-1229_2016-07-13_12h29m_1468430967/000_FPIXTest_p17//trimParameters35_C4.dat
[16:56:43.759] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-41_FPIXTest-17C-FNAL-160713-1229_2016-07-13_12h29m_1468430967/000_FPIXTest_p17//trimParameters35_C5.dat
[16:56:43.765] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-41_FPIXTest-17C-FNAL-160713-1229_2016-07-13_12h29m_1468430967/000_FPIXTest_p17//trimParameters35_C6.dat
[16:56:43.770] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-41_FPIXTest-17C-FNAL-160713-1229_2016-07-13_12h29m_1468430967/000_FPIXTest_p17//trimParameters35_C7.dat
[16:56:43.775] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-41_FPIXTest-17C-FNAL-160713-1229_2016-07-13_12h29m_1468430967/000_FPIXTest_p17//trimParameters35_C8.dat
[16:56:43.781] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-41_FPIXTest-17C-FNAL-160713-1229_2016-07-13_12h29m_1468430967/000_FPIXTest_p17//trimParameters35_C9.dat
[16:56:43.786] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-41_FPIXTest-17C-FNAL-160713-1229_2016-07-13_12h29m_1468430967/000_FPIXTest_p17//trimParameters35_C10.dat
[16:56:43.792] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-41_FPIXTest-17C-FNAL-160713-1229_2016-07-13_12h29m_1468430967/000_FPIXTest_p17//trimParameters35_C11.dat
[16:56:43.797] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-41_FPIXTest-17C-FNAL-160713-1229_2016-07-13_12h29m_1468430967/000_FPIXTest_p17//trimParameters35_C12.dat
[16:56:43.802] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-41_FPIXTest-17C-FNAL-160713-1229_2016-07-13_12h29m_1468430967/000_FPIXTest_p17//trimParameters35_C13.dat
[16:56:43.808] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-41_FPIXTest-17C-FNAL-160713-1229_2016-07-13_12h29m_1468430967/000_FPIXTest_p17//trimParameters35_C14.dat
[16:56:43.813] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-41_FPIXTest-17C-FNAL-160713-1229_2016-07-13_12h29m_1468430967/000_FPIXTest_p17//trimParameters35_C15.dat
[16:56:43.818] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-4-41_FPIXTest-17C-FNAL-160713-1229_2016-07-13_12h29m_1468430967/000_FPIXTest_p17//defaultMaskFile.dat
[16:56:43.828] INFO: enter test to run
[16:58:05.393] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[16:58:05.393] INFO: running: highrate
[16:58:05.398] INFO: ----------------------------------------------------------------------
[16:58:05.398] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[16:58:05.398] INFO: ----------------------------------------------------------------------
[16:58:05.398] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[16:58:05.398] INFO: edge/corner pixel THR is adjusted
[16:58:05.398] INFO: PixTestHighRate::trimHotPixels: step 0...
[16:58:06.356] INFO: Collecting data for 1 seconds...
[16:58:07.360] INFO: Done with hot pixel readout
[16:58:11.405] INFO: PixTest:: pg_setup set to default.
[16:58:11.406] INFO: 0 hot pixels found in step 0
[16:58:11.411] INFO: 0 hot pixels could not be trimmed and have been masked.
[16:58:11.498] INFO: PixTest::trimHotPixels() done
[16:58:11.499] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-41_FPIXTest-17C-FNAL-160713-1229_2016-07-13_12h29m_1468430967/000_FPIXTest_p17//trimParameters35_C0.dat
[16:58:11.506] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-41_FPIXTest-17C-FNAL-160713-1229_2016-07-13_12h29m_1468430967/000_FPIXTest_p17//trimParameters35_C1.dat
[16:58:11.514] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-41_FPIXTest-17C-FNAL-160713-1229_2016-07-13_12h29m_1468430967/000_FPIXTest_p17//trimParameters35_C2.dat
[16:58:11.519] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-41_FPIXTest-17C-FNAL-160713-1229_2016-07-13_12h29m_1468430967/000_FPIXTest_p17//trimParameters35_C3.dat
[16:58:11.524] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-41_FPIXTest-17C-FNAL-160713-1229_2016-07-13_12h29m_1468430967/000_FPIXTest_p17//trimParameters35_C4.dat
[16:58:11.529] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-41_FPIXTest-17C-FNAL-160713-1229_2016-07-13_12h29m_1468430967/000_FPIXTest_p17//trimParameters35_C5.dat
[16:58:11.535] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-41_FPIXTest-17C-FNAL-160713-1229_2016-07-13_12h29m_1468430967/000_FPIXTest_p17//trimParameters35_C6.dat
[16:58:11.540] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-41_FPIXTest-17C-FNAL-160713-1229_2016-07-13_12h29m_1468430967/000_FPIXTest_p17//trimParameters35_C7.dat
[16:58:11.545] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-41_FPIXTest-17C-FNAL-160713-1229_2016-07-13_12h29m_1468430967/000_FPIXTest_p17//trimParameters35_C8.dat
[16:58:11.550] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-41_FPIXTest-17C-FNAL-160713-1229_2016-07-13_12h29m_1468430967/000_FPIXTest_p17//trimParameters35_C9.dat
[16:58:11.556] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-41_FPIXTest-17C-FNAL-160713-1229_2016-07-13_12h29m_1468430967/000_FPIXTest_p17//trimParameters35_C10.dat
[16:58:11.561] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-41_FPIXTest-17C-FNAL-160713-1229_2016-07-13_12h29m_1468430967/000_FPIXTest_p17//trimParameters35_C11.dat
[16:58:11.566] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-41_FPIXTest-17C-FNAL-160713-1229_2016-07-13_12h29m_1468430967/000_FPIXTest_p17//trimParameters35_C12.dat
[16:58:11.571] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-41_FPIXTest-17C-FNAL-160713-1229_2016-07-13_12h29m_1468430967/000_FPIXTest_p17//trimParameters35_C13.dat
[16:58:11.576] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-41_FPIXTest-17C-FNAL-160713-1229_2016-07-13_12h29m_1468430967/000_FPIXTest_p17//trimParameters35_C14.dat
[16:58:11.582] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-41_FPIXTest-17C-FNAL-160713-1229_2016-07-13_12h29m_1468430967/000_FPIXTest_p17//trimParameters35_C15.dat
[16:58:11.587] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-4-41_FPIXTest-17C-FNAL-160713-1229_2016-07-13_12h29m_1468430967/000_FPIXTest_p17//defaultMaskFile.dat
[16:58:11.602] INFO: enter test to run
[17:00:25.472] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[17:00:25.472] INFO: running: xray
[17:00:25.474] INFO: ----------------------------------------------------------------------
[17:00:25.474] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[17:00:25.474] INFO: ----------------------------------------------------------------------
[17:00:26.438] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[17:00:37.608] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[17:01:06.340] INFO: Resuming triggers.
[17:01:17.511] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[17:01:47.864] INFO: Resuming triggers.
[17:01:59.036] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[17:02:29.035] INFO: Resuming triggers.
[17:02:40.209] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[17:03:10.117] INFO: Resuming triggers.
[17:03:21.292] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[17:03:50.668] INFO: Resuming triggers.
[17:04:01.838] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[17:04:31.293] INFO: Resuming triggers.
[17:04:42.465] INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.
[17:05:11.889] INFO: Resuming triggers.
[17:05:23.065] INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[17:05:52.568] INFO: Resuming triggers.
[17:06:03.538] INFO: data taking finished, elapsed time: 100 seconds.
[17:06:32.674] INFO: PixTest:: pg_setup set to default.
[17:06:32.677] INFO: PixTestXray::doPhRun() done
[17:06:32.815] INFO: enter test to run
[17:07:40.725] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[17:07:40.725] INFO: running: xray
[17:07:40.726] INFO: ----------------------------------------------------------------------
[17:07:40.727] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[17:07:40.727] INFO: ----------------------------------------------------------------------
[17:07:41.698] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[17:07:48.288] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[17:08:18.318] INFO: Resuming triggers.
[17:08:24.911] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[17:08:54.973] INFO: Resuming triggers.
[17:09:01.566] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[17:09:31.555] INFO: Resuming triggers.
[17:09:38.151] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[17:10:08.261] INFO: Resuming triggers.
[17:10:14.857] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[17:10:44.111] INFO: Resuming triggers.
[17:10:50.705] INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[17:11:20.396] INFO: Resuming triggers.
[17:11:26.990] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[17:11:56.547] INFO: Resuming triggers.
[17:12:03.143] INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[17:12:33.528] INFO: Resuming triggers.
[17:12:40.124] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[17:13:10.514] INFO: Resuming triggers.
[17:13:17.110] INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[17:13:47.839] INFO: Resuming triggers.
[17:13:54.434] INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[17:14:24.684] INFO: Resuming triggers.
[17:14:31.284] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[17:15:01.745] INFO: Resuming triggers.
[17:15:08.346] INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[17:15:37.747] INFO: Resuming triggers.
[17:15:44.343] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[17:16:13.967] INFO: Resuming triggers.
[17:16:20.567] INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[17:16:50.076] INFO: Resuming triggers.
[17:16:51.479] INFO: data taking finished, elapsed time: 100 seconds.
[17:16:58.226] INFO: PixTest:: pg_setup set to default.
[17:16:58.229] INFO: PixTestXray::doPhRun() done
[17:16:58.380] INFO: enter test to run
[17:17:18.290] INFO: test: HighRate no parameter change
[17:17:18.290] INFO: running: highrate
[17:17:18.291] INFO: ----------------------------------------------------------------------
[17:17:18.291] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[17:17:18.291] INFO: ----------------------------------------------------------------------
[17:17:18.431] INFO: Expecting 768 events.
[17:17:19.563] INFO: 768 events read in total (417ms).
[17:17:19.564] INFO: Test took 1267ms.
[17:17:20.367] INFO: Expecting 41600 events.
[17:17:23.431] INFO: 41600 events read in total (2537ms).
[17:17:23.432] INFO: Test took 3861ms.
[17:17:23.465] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:17:24.192] INFO: Expecting 41600 events.
[17:17:27.391] INFO: 41600 events read in total (2673ms).
[17:17:27.393] INFO: Test took 3910ms.
[17:17:27.431] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:17:28.144] INFO: Expecting 41600 events.
[17:17:31.391] INFO: 41600 events read in total (2720ms).
[17:17:31.392] INFO: Test took 3943ms.
[17:17:31.427] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:17:32.147] INFO: Expecting 41600 events.
[17:17:35.248] INFO: 41600 events read in total (2574ms).
[17:17:35.249] INFO: Test took 3804ms.
[17:17:35.285] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:17:36.007] INFO: Expecting 41600 events.
[17:17:39.243] INFO: 41600 events read in total (2709ms).
[17:17:39.244] INFO: Test took 3941ms.
[17:17:39.280] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:17:39.001] INFO: Expecting 41600 events.
[17:17:43.237] INFO: 41600 events read in total (2709ms).
[17:17:43.238] INFO: Test took 3939ms.
[17:17:43.272] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:17:43.994] INFO: Expecting 41600 events.
[17:17:47.231] INFO: 41600 events read in total (2710ms).
[17:17:47.232] INFO: Test took 3941ms.
[17:17:47.267] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:17:47.989] INFO: Expecting 41600 events.
[17:17:51.063] INFO: 41600 events read in total (2547ms).
[17:17:51.064] INFO: Test took 3779ms.
[17:17:51.098] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:17:51.822] INFO: Expecting 41600 events.
[17:17:55.056] INFO: 41600 events read in total (2707ms).
[17:17:55.057] INFO: Test took 3940ms.
[17:17:55.092] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:17:55.814] INFO: Expecting 41600 events.
[17:17:58.919] INFO: 41600 events read in total (2578ms).
[17:17:58.920] INFO: Test took 3810ms.
[17:17:58.956] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:17:59.675] INFO: Expecting 41600 events.
[17:18:02.915] INFO: 41600 events read in total (2713ms).
[17:18:02.916] INFO: Test took 3942ms.
[17:18:02.950] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:18:03.671] INFO: Expecting 41600 events.
[17:18:06.913] INFO: 41600 events read in total (2715ms).
[17:18:06.914] INFO: Test took 3946ms.
[17:18:06.948] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:18:07.669] INFO: Expecting 41600 events.
[17:18:10.838] INFO: 41600 events read in total (2643ms).
[17:18:10.839] INFO: Test took 3872ms.
[17:18:10.874] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:18:11.598] INFO: Expecting 41600 events.
[17:18:14.845] INFO: 41600 events read in total (2720ms).
[17:18:14.846] INFO: Test took 3954ms.
[17:18:14.880] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:18:15.603] INFO: Expecting 41600 events.
[17:18:18.677] INFO: 41600 events read in total (2547ms).
[17:18:18.678] INFO: Test took 3780ms.
[17:18:18.714] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:18:19.440] INFO: Expecting 41600 events.
[17:18:22.650] INFO: 41600 events read in total (2683ms).
[17:18:22.651] INFO: Test took 3919ms.
[17:18:22.685] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:18:23.411] INFO: Expecting 41600 events.
[17:18:26.674] INFO: 41600 events read in total (2736ms).
[17:18:26.675] INFO: Test took 3971ms.
[17:18:26.710] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:18:27.430] INFO: Expecting 41600 events.
[17:18:30.587] INFO: 41600 events read in total (2630ms).
[17:18:30.588] INFO: Test took 3861ms.
[17:18:30.623] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:18:31.345] INFO: Expecting 41600 events.
[17:18:34.562] INFO: 41600 events read in total (2690ms).
[17:18:34.563] INFO: Test took 3921ms.
[17:18:34.597] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:18:35.323] INFO: Expecting 41600 events.
[17:18:38.336] INFO: 41600 events read in total (2486ms).
[17:18:38.337] INFO: Test took 3721ms.
[17:18:38.370] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:18:38.727] INFO: enter test to run
[17:19:53.089] INFO: test: HighRate no parameter change
[17:19:53.089] INFO: running: highrate
[17:19:53.090] INFO: ----------------------------------------------------------------------
[17:19:53.090] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[17:19:53.090] INFO: ----------------------------------------------------------------------
[17:19:53.707] INFO: Expecting 208000 events.
[17:20:05.570] INFO: 208000 events read in total (11336ms).
[17:20:05.573] INFO: Test took 12473ms.
[17:20:05.719] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:20:05.973] INFO: number of dead pixels (per ROC): 0 0 0 1 0 0 0 0 0 0 1 0 0 0 0 0
[17:20:05.973] INFO: number of red-efficiency pixels: 103 50 81 139 144 126 146 94 90 146 128 126 123 74 21 44
[17:20:05.973] INFO: number of X-ray hits detected: 66628 41740 69558 107744 114412 115907 116260 79458 78610 107633 106611 86286 91717 55535 19934 22763
[17:20:05.973] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[17:20:05.973] INFO: number of Vcal hits detected: 207895 207949 207904 207807 207854 207871 207850 207905 207904 207852 207821 207873 207872 207925 207979 207956
[17:20:05.973] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[17:20:05.973] INFO: Vcal hit overall efficiency (%): 99.9 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[17:20:05.973] INFO: X-ray hit rate [MHz/cm2]: 19.5 12.2 20.4 31.6 33.5 34.0 34.1 23.3 23.0 31.5 31.2 25.3 26.9 16.3 5.8 6.7
[17:20:05.973] INFO: PixTestHighRate::doXPixelAlive() done
[17:20:06.023] INFO: PixTest:: pg_setup set to default.
[17:20:06.039] INFO: enter test to run
[17:20:22.800] INFO: test: HighRate no parameter change
[17:20:22.800] INFO: running: highrate
[17:20:22.801] INFO: ----------------------------------------------------------------------
[17:20:22.801] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[17:20:22.802] INFO: ----------------------------------------------------------------------
[17:20:23.418] INFO: Expecting 208000 events.
[17:20:36.838] INFO: 208000 events read in total (12893ms).
[17:20:36.844] INFO: Test took 14033ms.
[17:20:37.147] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:20:37.450] INFO: number of dead pixels (per ROC): 0 0 0 1 0 0 0 0 0 0 1 0 0 0 0 0
[17:20:37.450] INFO: number of red-efficiency pixels: 245 132 239 519 584 439 554 346 336 505 439 375 359 216 45 66
[17:20:37.450] INFO: number of X-ray hits detected: 140226 87051 145398 225763 240336 243682 243178 167585 165860 224612 223313 181974 192020 117091 41423 48118
[17:20:37.450] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[17:20:37.450] INFO: number of Vcal hits detected: 207733 207862 207704 207380 207341 207524 207396 207616 207642 207439 207483 207598 207621 207765 207955 207933
[17:20:37.450] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.7 99.7 99.8 99.7 99.8 99.8 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[17:20:37.450] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.7 99.7 99.8 99.7 99.8 99.8 99.7 99.8 99.8 99.8 99.9 100.0 100.0
[17:20:37.450] INFO: X-ray hit rate [MHz/cm2]: 41.1 25.5 42.6 66.2 70.4 71.4 71.3 49.1 48.6 65.8 65.5 53.3 56.3 34.3 12.1 14.1
[17:20:37.450] INFO: PixTestHighRate::doXPixelAlive() done
[17:20:37.501] INFO: PixTest:: pg_setup set to default.
[17:20:37.517] INFO: enter test to run
[17:20:52.752] INFO: test: HighRate no parameter change
[17:20:52.752] INFO: running: highrate
[17:20:52.753] INFO: ----------------------------------------------------------------------
[17:20:52.753] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[17:20:52.753] INFO: ----------------------------------------------------------------------
[17:20:53.371] INFO: Expecting 208000 events.
[17:21:08.667] INFO: 208000 events read in total (14769ms).
[17:21:08.675] INFO: Test took 15913ms.
[17:21:09.119] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:21:09.473] INFO: number of dead pixels (per ROC): 0 0 0 1 0 0 0 0 0 0 1 0 0 0 0 0
[17:21:09.473] INFO: number of red-efficiency pixels: 562 269 558 1247 1318 976 1237 794 702 1167 938 802 857 425 92 94
[17:21:09.473] INFO: number of X-ray hits detected: 207150 129618 216035 334009 355333 359422 361344 248464 245974 332994 330890 269889 284320 173663 62069 71223
[17:21:09.473] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[17:21:09.474] INFO: number of Vcal hits detected: 207261 207712 207294 206360 206243 206761 206397 206999 207161 206514 206821 207018 206973 207502 207904 207905
[17:21:09.474] INFO: Vcal hit fiducial efficiency (%): 99.7 99.9 99.7 99.3 99.2 99.5 99.3 99.6 99.6 99.4 99.5 99.6 99.6 99.8 100.0 100.0
[17:21:09.474] INFO: Vcal hit overall efficiency (%): 99.6 99.9 99.7 99.2 99.2 99.4 99.2 99.5 99.6 99.3 99.4 99.5 99.5 99.8 100.0 100.0
[17:21:09.474] INFO: X-ray hit rate [MHz/cm2]: 60.7 38.0 63.3 97.9 104.2 105.3 105.9 72.8 72.1 97.6 97.0 79.1 83.3 50.9 18.2 20.9
[17:21:09.474] INFO: PixTestHighRate::doXPixelAlive() done
[17:21:09.524] INFO: PixTest:: pg_setup set to default.
[17:21:09.544] INFO: enter test to run
[17:21:10.816] INFO: test: exit no parameter change
[17:21:11.169] QUIET: Connection to board 33 closed.
[17:21:11.170] INFO: pXar: this is the end, my friend