[16:37:32.388] INFO: *** Welcome to pxar ***
[16:37:32.388] INFO: *** Today: 2016/06/01
[16:37:32.405] INFO: *** Version: v1.9.0-796-gef167-dirty
[16:37:32.405] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Y-D-NU_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-D-NU_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//dacParameters35_C15.dat
[16:37:32.426] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Y-D-NU_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-D-NU_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//tbmParameters_C0b.dat
[16:37:32.427] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Y-D-NU_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//defaultMaskFile.dat
[16:37:32.431] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Y-D-NU_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-D-NU_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C15.dat
[16:37:32.504] INFO: clk: 4
[16:37:32.504] INFO: ctr: 4
[16:37:32.504] INFO: sda: 19
[16:37:32.504] INFO: tin: 9
[16:37:32.504] INFO: level: 15
[16:37:32.504] INFO: triggerdelay: 0
[16:37:32.504] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[16:37:32.504] INFO: Log level: INFO
[16:37:32.522] QUIET: Connection to board DTB_WREK4U opened.
[16:37:32.525] 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:
------------------------------------------------------
[16:37:32.528] INFO: RPC call hashes of host and DTB match: 398089610
[16:37:34.053] INFO: DUT info:
[16:37:34.053] INFO: The DUT currently contains the following objects:
[16:37:34.053] INFO: 2 TBM Cores tbm08c (2 ON)
[16:37:34.053] INFO: TBM Core alpha (0): 7 registers set
[16:37:34.053] INFO: TBM Core beta (1): 7 registers set
[16:37:34.054] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[16:37:34.054] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[16:37:34.054] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[16:37:34.054] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[16:37:34.054] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[16:37:34.054] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[16:37:34.054] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[16:37:34.054] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[16:37:34.054] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[16:37:34.054] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[16:37:34.054] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[16:37:34.054] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[16:37:34.054] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[16:37:34.054] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[16:37:34.054] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[16:37:34.054] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[16:37:34.054] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[16:37:34.458] INFO: enter 'restricted' command line mode
[16:37:34.458] INFO: enter test to run
[16:37:37.097] INFO: test: PixelAlive no parameter change
[16:37:37.097] INFO: running: pixelalive
[16:37:37.106] INFO: ----------------------------------------------------------------------
[16:37:37.106] 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:37:37.106] INFO: ----------------------------------------------------------------------
[16:37:37.428] INFO: Expecting 41600 events.
[16:37:41.748] INFO: 41600 events read in total (3601ms).
[16:37:41.917] INFO: Test took 4808ms.
[16:37:41.928] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:37:42.190] INFO: PixTestAlive::aliveTest() done
[16:37:42.191] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 2 0 0 0 0 0 0 0 0 0
[16:37:42.224] INFO: enter test to run
[16:37:59.273] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[16:37:59.273] INFO: running: highrate
[16:37:59.273] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Y-D-NU_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-D-NU_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[16:37:59.490] INFO: ----------------------------------------------------------------------
[16:37:59.490] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[16:37:59.490] INFO: ----------------------------------------------------------------------
[16:37:59.490] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[16:37:59.490] INFO: edge/corner pixel THR is adjusted
[16:37:59.490] INFO: PixTestHighRate::trimHotPixels: step 0...
[16:38:00.450] INFO: Collecting data for 5 seconds...
[16:38:05.465] INFO: Done with hot pixel readout
[16:38:17.984] INFO: PixTest:: pg_setup set to default.

[16:38:17.985] INFO: 64 hot pixels found in step 0
[16:38:19.006] INFO: Collecting data for 5 seconds...
[16:38:24.023] INFO: Done with hot pixel readout
[16:38:36.534] INFO: PixTest:: pg_setup set to default.




[16:38:36.535] INFO: 56 hot pixels found in step 1
[16:38:37.529] INFO: Collecting data for 5 seconds...
[16:38:42.545] INFO: Done with hot pixel readout
[16:38:55.107] INFO: PixTest:: pg_setup set to default.



[16:38:55.108] INFO: 68 hot pixels found in step 2
[16:38:56.102] INFO: Collecting data for 5 seconds...
[16:39:01.117] INFO: Done with hot pixel readout
[16:39:13.608] INFO: PixTest:: pg_setup set to default.
[16:39:13.609] INFO: 62 hot pixels found in step 3
[16:39:14.602] INFO: Collecting data for 5 seconds...
[16:39:19.618] INFO: Done with hot pixel readout
[16:39:32.120] INFO: PixTest:: pg_setup set to default.




[16:39:32.121] INFO: 44 hot pixels found in step 4
[16:39:33.115] INFO: Collecting data for 5 seconds...
[16:39:38.130] INFO: Done with hot pixel readout
[16:39:50.662] INFO: PixTest:: pg_setup set to default.




[16:39:50.664] INFO: 55 hot pixels found in step 5
[16:39:51.664] INFO: Collecting data for 5 seconds...
[16:39:56.679] INFO: Done with hot pixel readout
[16:40:09.211] INFO: PixTest:: pg_setup set to default.


[16:40:09.212] INFO: 52 hot pixels found in step 6
[16:40:10.205] INFO: Collecting data for 5 seconds...
[16:40:15.220] INFO: Done with hot pixel readout
[16:40:27.693] INFO: PixTest:: pg_setup set to default.






[16:40:27.694] INFO: 46 hot pixels found in step 7
[16:40:28.687] INFO: Collecting data for 5 seconds...
[16:40:33.703] INFO: Done with hot pixel readout
[16:40:46.200] INFO: PixTest:: pg_setup set to default.




[16:40:46.201] INFO: 40 hot pixels found in step 8
[16:40:47.194] INFO: Collecting data for 5 seconds...
[16:40:52.209] INFO: Done with hot pixel readout
[16:41:04.749] INFO: PixTest:: pg_setup set to default.







[16:41:04.751] INFO: 37 hot pixels found in step 9
[16:41:05.752] INFO: Collecting data for 5 seconds...
[16:41:10.767] INFO: Done with hot pixel readout
[16:41:23.313] INFO: PixTest:: pg_setup set to default.



[16:41:23.314] INFO: 23 hot pixels found in step 10
[16:41:24.308] INFO: Collecting data for 5 seconds...
[16:41:29.323] INFO: Done with hot pixel readout
[16:41:41.839] INFO: PixTest:: pg_setup set to default.





[16:41:41.840] INFO: 37 hot pixels found in step 11
[16:41:42.834] INFO: Collecting data for 5 seconds...
[16:41:47.850] INFO: Done with hot pixel readout
[16:42:00.366] INFO: PixTest:: pg_setup set to default.





[16:42:00.367] INFO: 35 hot pixels found in step 12
[16:42:01.361] INFO: Collecting data for 5 seconds...
[16:42:06.375] INFO: Done with hot pixel readout
[16:42:18.848] INFO: PixTest:: pg_setup set to default.






[16:42:18.849] INFO: 38 hot pixels found in step 13
[16:42:19.843] INFO: Collecting data for 5 seconds...
[16:42:24.859] INFO: Done with hot pixel readout
[16:42:37.449] INFO: PixTest:: pg_setup set to default.




[16:42:37.450] INFO: 29 hot pixels found in step 14
[16:42:37.488] INFO: 29 hot pixels could not be trimmed and have been masked.
[16:42:37.491] INFO: PixTest::trimHotPixels() done
[16:42:37.496] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NU_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C0.dat
[16:42:37.502] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NU_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C1.dat
[16:42:37.508] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NU_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C2.dat
[16:42:37.513] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NU_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C3.dat
[16:42:37.519] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NU_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C4.dat
[16:42:37.524] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NU_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C5.dat
[16:42:37.529] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NU_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C6.dat
[16:42:37.534] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NU_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C7.dat
[16:42:37.539] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NU_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C8.dat
[16:42:37.544] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NU_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C9.dat
[16:42:37.549] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NU_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C10.dat
[16:42:37.555] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NU_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C11.dat
[16:42:37.560] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NU_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C12.dat
[16:42:37.565] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NU_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C13.dat
[16:42:37.570] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NU_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C14.dat
[16:42:37.575] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NU_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C15.dat
[16:42:37.580] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Y-D-NU_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//defaultMaskFile.dat
[16:42:37.590] INFO: enter test to run
[16:42:55.206] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[16:42:55.206] INFO: running: highrate
[16:42:55.211] INFO: ----------------------------------------------------------------------
[16:42:55.211] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[16:42:55.211] INFO: ----------------------------------------------------------------------
[16:42:55.211] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[16:42:55.211] INFO: edge/corner pixel THR is adjusted
[16:42:55.211] INFO: PixTestHighRate::trimHotPixels: step 0...
[16:42:56.169] INFO: Collecting data for 1 seconds...
[16:42:57.173] INFO: Done with hot pixel readout
[16:43:01.610] INFO: PixTest:: pg_setup set to default.
[16:43:01.611] INFO: 0 hot pixels found in step 0
[16:43:01.616] INFO: 0 hot pixels could not be trimmed and have been masked.
[16:43:01.690] INFO: PixTest::trimHotPixels() done
[16:43:01.690] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NU_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C0.dat
[16:43:01.698] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NU_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C1.dat
[16:43:01.705] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NU_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C2.dat
[16:43:01.710] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NU_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C3.dat
[16:43:01.715] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NU_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C4.dat
[16:43:01.720] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NU_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C5.dat
[16:43:01.726] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NU_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C6.dat
[16:43:01.731] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NU_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C7.dat
[16:43:01.736] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NU_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C8.dat
[16:43:01.741] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NU_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C9.dat
[16:43:01.746] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NU_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C10.dat
[16:43:01.751] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NU_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C11.dat
[16:43:01.756] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NU_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C12.dat
[16:43:01.761] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NU_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C13.dat
[16:43:01.767] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NU_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C14.dat
[16:43:01.772] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-D-NU_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//trimParameters35_C15.dat
[16:43:01.777] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Y-D-NU_FPIXTest-17C-FNAL-160527-0934_2016-05-27_09h35m_1464359703/000_FPIXTest_p17//defaultMaskFile.dat
[16:43:01.789] INFO: enter test to run
[16:44:33.934] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[16:44:33.934] INFO: running: xray
[16:44:33.935] INFO: ----------------------------------------------------------------------
[16:44:33.935] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[16:44:33.935] INFO: ----------------------------------------------------------------------
[16:44:34.898] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[16:44:45.354] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[16:45:14.727] INFO: Resuming triggers.
[16:45:25.185] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[16:45:54.693] INFO: Resuming triggers.
[16:46:05.155] INFO: run duration 31 seconds, buffer almost full (81%), pausing triggers.
[16:46:34.454] INFO: Resuming triggers.
[16:46:44.914] INFO: run duration 41 seconds, buffer almost full (81%), pausing triggers.
[16:47:14.358] INFO: Resuming triggers.
[16:47:24.825] INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[16:47:54.131] INFO: Resuming triggers.
[16:48:04.597] INFO: run duration 62 seconds, buffer almost full (81%), pausing triggers.
[16:48:34.072] INFO: Resuming triggers.
[16:48:44.536] INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[16:49:13.994] INFO: Resuming triggers.
[16:49:24.455] INFO: run duration 83 seconds, buffer almost full (81%), pausing triggers.
[16:49:53.834] INFO: Resuming triggers.
[16:50:04.302] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[16:50:33.722] INFO: Resuming triggers.
[16:50:39.870] INFO: data taking finished, elapsed time: 100 seconds.
[16:50:57.420] INFO: PixTest:: pg_setup set to default.
[16:50:57.423] INFO: PixTestXray::doPhRun() done
[16:50:57.561] INFO: enter test to run
[16:52:21.994] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[16:52:21.994] INFO: running: xray
[16:52:21.995] INFO: ----------------------------------------------------------------------
[16:52:21.995] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[16:52:21.995] INFO: ----------------------------------------------------------------------
[16:52:22.960] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[16:52:28.783] INFO: run duration 5 seconds, buffer almost full (81%), pausing triggers.
[16:52:59.277] INFO: Resuming triggers.
[16:53:05.104] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[16:53:34.954] INFO: Resuming triggers.
[16:53:40.779] INFO: run duration 17 seconds, buffer almost full (81%), pausing triggers.
[16:54:09.836] INFO: Resuming triggers.
[16:54:15.661] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[16:54:46.619] INFO: Resuming triggers.
[16:54:52.446] INFO: run duration 29 seconds, buffer almost full (81%), pausing triggers.
[16:55:21.765] INFO: Resuming triggers.
[16:55:27.589] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[16:55:57.596] INFO: Resuming triggers.
[16:56:03.420] INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[16:56:33.308] INFO: Resuming triggers.
[16:56:39.133] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[16:57:09.164] INFO: Resuming triggers.
[16:57:14.993] INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[16:57:44.212] INFO: Resuming triggers.
[16:57:50.037] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[16:58:19.190] INFO: Resuming triggers.
[16:58:25.019] INFO: run duration 63 seconds, buffer almost full (81%), pausing triggers.
[16:58:54.991] INFO: Resuming triggers.
[16:59:00.815] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[16:59:30.818] INFO: Resuming triggers.
[16:59:36.641] INFO: run duration 75 seconds, buffer almost full (81%), pausing triggers.
[17:00:06.714] INFO: Resuming triggers.
[17:00:12.544] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[17:00:42.509] INFO: Resuming triggers.
[17:00:48.336] INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[17:01:18.095] INFO: Resuming triggers.
[17:01:23.924] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[17:01:53.876] INFO: Resuming triggers.
[17:01:59.703] INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[17:02:29.633] INFO: Resuming triggers.
[17:02:30.908] INFO: data taking finished, elapsed time: 100 seconds.
[17:02:37.777] INFO: PixTest:: pg_setup set to default.
[17:02:37.780] INFO: PixTestXray::doPhRun() done
[17:02:37.931] INFO: enter test to run
[17:03:50.925] INFO: test: HighRate no parameter change
[17:03:50.925] INFO: running: highrate
[17:03:50.926] INFO: ----------------------------------------------------------------------
[17:03:50.927] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[17:03:50.927] INFO: ----------------------------------------------------------------------
[17:03:51.068] INFO: Expecting 768 events.
[17:03:52.202] INFO: 768 events read in total (418ms).
[17:03:52.202] INFO: Test took 1268ms.
[17:03:53.005] INFO: Expecting 41600 events.
[17:03:56.096] INFO: 41600 events read in total (2564ms).
[17:03:56.097] INFO: Test took 3887ms.
[17:03:56.136] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:03:56.855] INFO: Expecting 41600 events.
[17:04:00.086] INFO: 41600 events read in total (2704ms).
[17:04:00.087] INFO: Test took 3931ms.
[17:04:00.128] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:04:00.844] INFO: Expecting 41600 events.
[17:04:04.127] INFO: 41600 events read in total (2757ms).
[17:04:04.128] INFO: Test took 3980ms.
[17:04:04.168] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:04:04.879] INFO: Expecting 41600 events.
[17:04:08.175] INFO: 41600 events read in total (2769ms).
[17:04:08.176] INFO: Test took 3987ms.
[17:04:08.217] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:04:08.931] INFO: Expecting 41600 events.
[17:04:12.239] INFO: 41600 events read in total (2781ms).
[17:04:12.240] INFO: Test took 4003ms.
[17:04:12.281] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:04:12.988] INFO: Expecting 41600 events.
[17:04:16.287] INFO: 41600 events read in total (2772ms).
[17:04:16.288] INFO: Test took 3987ms.
[17:04:16.330] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:04:17.038] INFO: Expecting 41600 events.
[17:04:20.327] INFO: 41600 events read in total (2762ms).
[17:04:20.328] INFO: Test took 3977ms.
[17:04:20.368] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:04:21.078] INFO: Expecting 41600 events.
[17:04:24.373] INFO: 41600 events read in total (2768ms).
[17:04:24.374] INFO: Test took 3986ms.
[17:04:24.414] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:04:25.127] INFO: Expecting 41600 events.
[17:04:28.402] INFO: 41600 events read in total (2749ms).
[17:04:28.403] INFO: Test took 3970ms.
[17:04:28.444] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:04:29.153] INFO: Expecting 41600 events.
[17:04:32.450] INFO: 41600 events read in total (2771ms).
[17:04:32.452] INFO: Test took 3986ms.
[17:04:32.493] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:04:33.205] INFO: Expecting 41600 events.
[17:04:36.495] INFO: 41600 events read in total (2764ms).
[17:04:36.496] INFO: Test took 3982ms.
[17:04:36.536] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:04:37.250] INFO: Expecting 41600 events.
[17:04:40.535] INFO: 41600 events read in total (2758ms).
[17:04:40.536] INFO: Test took 3979ms.
[17:04:40.578] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:04:41.288] INFO: Expecting 41600 events.
[17:04:44.581] INFO: 41600 events read in total (2767ms).
[17:04:44.582] INFO: Test took 3985ms.
[17:04:44.623] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:04:45.336] INFO: Expecting 41600 events.
[17:04:48.636] INFO: 41600 events read in total (2774ms).
[17:04:48.637] INFO: Test took 3994ms.
[17:04:48.679] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:04:49.386] INFO: Expecting 41600 events.
[17:04:52.695] INFO: 41600 events read in total (2782ms).
[17:04:52.696] INFO: Test took 3997ms.
[17:04:52.737] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:04:53.450] INFO: Expecting 41600 events.
[17:04:56.737] INFO: 41600 events read in total (2760ms).
[17:04:56.738] INFO: Test took 3979ms.
[17:04:56.779] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:04:57.491] INFO: Expecting 41600 events.
[17:05:00.796] INFO: 41600 events read in total (2778ms).
[17:05:00.797] INFO: Test took 3998ms.
[17:05:00.837] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:05:01.552] INFO: Expecting 41600 events.
[17:05:04.836] INFO: 41600 events read in total (2758ms).
[17:05:04.838] INFO: Test took 3979ms.
[17:05:04.879] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:05:05.588] INFO: Expecting 41600 events.
[17:05:08.905] INFO: 41600 events read in total (2790ms).
[17:05:08.906] INFO: Test took 4005ms.
[17:05:08.947] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:05:09.658] INFO: Expecting 41600 events.
[17:05:12.873] INFO: 41600 events read in total (2688ms).
[17:05:12.874] INFO: Test took 3907ms.
[17:05:12.914] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:05:13.257] INFO: enter test to run
[17:05:29.252] INFO: test: HighRate no parameter change
[17:05:29.252] INFO: running: highrate
[17:05:29.254] INFO: ----------------------------------------------------------------------
[17:05:29.254] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[17:05:29.254] INFO: ----------------------------------------------------------------------
[17:05:29.869] INFO: Expecting 208000 events.
[17:05:42.095] INFO: 208000 events read in total (11699ms).
[17:05:42.098] INFO: Test took 12836ms.
[17:05:42.276] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:05:42.539] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 2 0 0 0 0 0 0 0 0 0
[17:05:42.539] INFO: number of red-efficiency pixels: 95 71 98 138 149 192 183 124 153 193 146 152 144 119 39 33
[17:05:42.539] INFO: number of X-ray hits detected: 77420 54045 77596 120412 128137 136097 125084 96076 104559 138834 129418 118145 123896 73217 30203 33306
[17:05:42.539] 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:05:42.539] INFO: number of Vcal hits detected: 207902 207928 207900 207859 207849 207803 207715 207875 207845 207783 207851 207847 207853 207878 207960 207967
[17:05:42.539] INFO: Vcal hit fiducial efficiency (%): 100.0 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
[17:05:42.539] INFO: Vcal hit overall efficiency (%): 100.0 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
[17:05:42.539] INFO: X-ray hit rate [MHz/cm2]: 22.7 15.8 22.7 35.3 37.6 39.9 36.7 28.2 30.6 40.7 37.9 34.6 36.3 21.5 8.9 9.8
[17:05:42.539] INFO: PixTestHighRate::doXPixelAlive() done
[17:05:42.586] INFO: PixTest:: pg_setup set to default.
[17:05:42.600] INFO: enter test to run
[17:06:32.636] INFO: test: HighRate no parameter change
[17:06:32.636] INFO: running: highrate
[17:06:32.637] INFO: ----------------------------------------------------------------------
[17:06:32.637] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[17:06:32.637] INFO: ----------------------------------------------------------------------
[17:06:33.253] INFO: Expecting 208000 events.
[17:06:47.733] INFO: 208000 events read in total (13953ms).
[17:06:47.739] INFO: Test took 15092ms.
[17:06:48.101] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:06:48.426] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 2 0 0 0 0 0 0 0 0 0
[17:06:48.426] INFO: number of red-efficiency pixels: 309 201 371 463 671 792 626 465 463 674 520 464 592 388 83 78
[17:06:48.426] INFO: number of X-ray hits detected: 159454 112726 161327 249594 263429 281719 257355 199768 215842 287649 265926 243798 255762 152466 62844 69287
[17:06:48.427] 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:06:48.427] INFO: number of Vcal hits detected: 207667 207780 207581 207492 207235 207083 207198 207486 207492 207147 207424 207494 207351 207569 207913 207921
[17:06:48.427] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.8 99.8 99.7 99.6 99.7 99.8 99.8 99.6 99.7 99.8 99.7 99.8 100.0 100.0
[17:06:48.427] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.8 99.8 99.6 99.6 99.6 99.8 99.8 99.6 99.7 99.8 99.7 99.8 100.0 100.0
[17:06:48.427] INFO: X-ray hit rate [MHz/cm2]: 46.7 33.0 47.3 73.2 77.2 82.6 75.4 58.6 63.3 84.3 77.9 71.5 75.0 44.7 18.4 20.3
[17:06:48.427] INFO: PixTestHighRate::doXPixelAlive() done
[17:06:48.477] INFO: PixTest:: pg_setup set to default.
[17:06:48.492] INFO: enter test to run
[17:07:17.348] INFO: test: HighRate no parameter change
[17:07:17.348] INFO: running: highrate
[17:07:17.349] INFO: ----------------------------------------------------------------------
[17:07:17.349] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[17:07:17.349] INFO: ----------------------------------------------------------------------
[17:07:17.966] INFO: Expecting 208000 events.
[17:07:35.008] INFO: 208000 events read in total (16515ms).
[17:07:35.016] INFO: Test took 17657ms.
[17:07:35.564] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:07:35.951] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 2 0 0 0 0 0 0 0 0 0
[17:07:35.951] INFO: number of red-efficiency pixels: 646 393 830 1153 1504 1734 1455 1041 1032 1483 1179 1044 1292 864 146 175
[17:07:35.951] INFO: number of X-ray hits detected: 237679 167531 239952 371608 390095 417937 382172 295908 320805 426133 397102 363557 379036 226592 93370 103295
[17:07:35.951] 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:07:35.951] INFO: number of Vcal hits detected: 207183 207542 206794 206545 205941 205522 205942 206591 206631 205724 206509 206644 206285 206729 207848 207818
[17:07:35.951] INFO: Vcal hit fiducial efficiency (%): 99.7 99.8 99.5 99.4 99.1 98.9 99.1 99.4 99.4 99.0 99.4 99.4 99.3 99.4 99.9 99.9
[17:07:35.951] INFO: Vcal hit overall efficiency (%): 99.6 99.8 99.4 99.3 99.0 98.8 99.0 99.3 99.3 98.9 99.3 99.3 99.2 99.4 99.9 99.9
[17:07:35.951] INFO: X-ray hit rate [MHz/cm2]: 69.7 49.1 70.3 108.9 114.3 122.5 112.0 86.7 94.0 124.9 116.4 106.6 111.1 66.4 27.4 30.3
[17:07:35.951] INFO: PixTestHighRate::doXPixelAlive() done
[17:07:35.996] INFO: PixTest:: pg_setup set to default.
[17:07:36.013] INFO: enter test to run
[17:07:42.140] INFO: test: exit no parameter change
[17:07:42.475] QUIET: Connection to board 32 closed.
[17:07:42.476] INFO: pXar: this is the end, my friend