[12:38:25.686] INFO: *** Welcome to pxar ***
[12:38:25.686] INFO: *** Today: 2016/05/12
[12:38:25.711] INFO: *** Version: v1.9.0-796-gef167-dirty
[12:38:25.711] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Y-H-NY_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-H-NY_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//dacParameters35_C15.dat
[12:38:25.735] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Y-H-NY_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-H-NY_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//tbmParameters_C0b.dat
[12:38:25.735] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Y-H-NY_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//defaultMaskFile.dat
[12:38:25.735] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Y-H-NY_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-H-NY_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C15.dat
[12:38:25.859] INFO: clk: 4
[12:38:25.859] INFO: ctr: 4
[12:38:25.859] INFO: sda: 19
[12:38:25.859] INFO: tin: 9
[12:38:25.859] INFO: level: 15
[12:38:25.859] INFO: triggerdelay: 0
[12:38:25.859] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[12:38:25.859] INFO: Log level: INFO
[12:38:25.878] QUIET: Connection to board DTB_WREKRL opened.
[12:38:25.881] 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:
------------------------------------------------------
[12:38:25.884] INFO: RPC call hashes of host and DTB match: 398089610
[12:38:27.411] INFO: DUT info:
[12:38:27.411] INFO: The DUT currently contains the following objects:
[12:38:27.411] INFO: 2 TBM Cores tbm08c (2 ON)
[12:38:27.411] INFO: TBM Core alpha (0): 7 registers set
[12:38:27.411] INFO: TBM Core beta (1): 7 registers set
[12:38:27.411] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[12:38:27.411] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[12:38:27.411] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[12:38:27.412] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[12:38:27.412] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[12:38:27.412] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[12:38:27.412] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[12:38:27.412] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[12:38:27.412] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[12:38:27.412] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[12:38:27.412] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[12:38:27.412] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[12:38:27.412] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[12:38:27.412] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[12:38:27.412] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[12:38:27.412] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[12:38:27.412] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[12:38:27.815] INFO: enter 'restricted' command line mode
[12:38:27.815] INFO: enter test to run
[12:38:43.446] INFO: test: PixelAlive no parameter change
[12:38:43.446] INFO: running: pixelalive
[12:38:43.456] INFO: ----------------------------------------------------------------------
[12:38:43.456] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[12:38:43.456] INFO: ----------------------------------------------------------------------
[12:38:43.780] INFO: Expecting 41600 events.
[12:38:48.134] INFO: 41600 events read in total (3635ms).
[12:38:48.300] INFO: Test took 4842ms.
[12:38:48.313] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:38:48.574] INFO: PixTestAlive::aliveTest() done
[12:38:48.574] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[12:38:48.609] INFO: enter test to run
[12:39:18.014] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[12:39:18.014] INFO: running: highrate
[12:39:18.014] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Y-H-NY_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-H-NY_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[12:39:18.231] INFO: ----------------------------------------------------------------------
[12:39:18.231] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[12:39:18.231] INFO: ----------------------------------------------------------------------
[12:39:18.231] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[12:39:18.231] INFO: edge/corner pixel THR is adjusted
[12:39:18.231] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:39:19.190] INFO: Collecting data for 5 seconds...
[12:39:24.207] INFO: Done with hot pixel readout
[12:39:36.799] INFO: PixTest:: pg_setup set to default.


[12:39:36.800] INFO: 65 hot pixels found in step 0
[12:39:37.794] INFO: Collecting data for 5 seconds...
[12:39:42.810] INFO: Done with hot pixel readout
[12:39:55.309] INFO: PixTest:: pg_setup set to default.



[12:39:55.310] INFO: 66 hot pixels found in step 1
[12:39:56.308] INFO: Collecting data for 5 seconds...
[12:40:01.324] INFO: Done with hot pixel readout
[12:40:13.854] INFO: PixTest:: pg_setup set to default.


[12:40:13.855] INFO: 63 hot pixels found in step 2
[12:40:14.852] INFO: Collecting data for 5 seconds...
[12:40:19.868] INFO: Done with hot pixel readout
[12:40:32.613] INFO: PixTest:: pg_setup set to default.



[12:40:32.614] INFO: 56 hot pixels found in step 3
[12:40:33.611] INFO: Collecting data for 5 seconds...
[12:40:38.629] INFO: Done with hot pixel readout
[12:40:51.179] INFO: PixTest:: pg_setup set to default.






[12:40:51.181] INFO: 58 hot pixels found in step 4
[12:40:52.178] INFO: Collecting data for 5 seconds...
[12:40:57.196] INFO: Done with hot pixel readout
[12:41:09.609] INFO: PixTest:: pg_setup set to default.


[12:41:09.610] INFO: 49 hot pixels found in step 5
[12:41:10.607] INFO: Collecting data for 5 seconds...
[12:41:15.624] INFO: Done with hot pixel readout
[12:41:27.991] INFO: PixTest:: pg_setup set to default.





[12:41:27.993] INFO: 53 hot pixels found in step 6
[12:41:28.991] INFO: Collecting data for 5 seconds...
[12:41:34.009] INFO: Done with hot pixel readout
[12:41:46.345] INFO: PixTest:: pg_setup set to default.




[12:41:46.346] INFO: 41 hot pixels found in step 7
[12:41:47.344] INFO: Collecting data for 5 seconds...
[12:41:52.362] INFO: Done with hot pixel readout
[12:42:04.971] INFO: PixTest:: pg_setup set to default.





[12:42:04.972] INFO: 38 hot pixels found in step 8
[12:42:05.971] INFO: Collecting data for 5 seconds...
[12:42:10.993] INFO: Done with hot pixel readout
[12:42:23.384] INFO: PixTest:: pg_setup set to default.








[12:42:23.385] INFO: 47 hot pixels found in step 9
[12:42:24.384] INFO: Collecting data for 5 seconds...
[12:42:29.403] INFO: Done with hot pixel readout
[12:42:41.959] INFO: PixTest:: pg_setup set to default.








[12:42:41.960] INFO: 48 hot pixels found in step 10
[12:42:42.957] INFO: Collecting data for 5 seconds...
[12:42:47.974] INFO: Done with hot pixel readout
[12:43:00.776] INFO: PixTest:: pg_setup set to default.







[12:43:00.777] INFO: 46 hot pixels found in step 11
[12:43:01.777] INFO: Collecting data for 5 seconds...
[12:43:06.796] INFO: Done with hot pixel readout
[12:43:19.297] INFO: PixTest:: pg_setup set to default.








[12:43:19.298] INFO: 39 hot pixels found in step 12
[12:43:20.296] INFO: Collecting data for 5 seconds...
[12:43:25.315] INFO: Done with hot pixel readout
[12:43:37.709] INFO: PixTest:: pg_setup set to default.






[12:43:37.710] INFO: 39 hot pixels found in step 13
[12:43:38.708] INFO: Collecting data for 5 seconds...
[12:43:43.724] INFO: Done with hot pixel readout
[12:43:56.208] INFO: PixTest:: pg_setup set to default.







[12:43:56.210] INFO: 33 hot pixels found in step 14
[12:43:56.251] INFO: 33 hot pixels could not be trimmed and have been masked.
[12:43:56.254] INFO: PixTest::trimHotPixels() done
[12:43:56.254] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NY_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C0.dat
[12:43:56.266] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NY_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C1.dat
[12:43:56.273] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NY_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C2.dat
[12:43:56.278] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NY_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C3.dat
[12:43:56.284] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NY_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C4.dat
[12:43:56.289] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NY_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C5.dat
[12:43:56.294] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NY_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C6.dat
[12:43:56.300] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NY_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C7.dat
[12:43:56.305] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NY_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C8.dat
[12:43:56.311] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NY_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C9.dat
[12:43:56.316] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NY_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C10.dat
[12:43:56.321] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NY_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C11.dat
[12:43:56.327] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NY_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C12.dat
[12:43:56.332] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NY_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C13.dat
[12:43:56.338] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NY_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C14.dat
[12:43:56.343] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NY_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C15.dat
[12:43:56.348] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Y-H-NY_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//defaultMaskFile.dat
[12:43:56.359] INFO: enter test to run
[12:44:27.924] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[12:44:27.924] INFO: running: highrate
[12:44:27.929] INFO: ----------------------------------------------------------------------
[12:44:27.929] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[12:44:27.929] INFO: ----------------------------------------------------------------------
[12:44:27.929] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[12:44:27.929] INFO: edge/corner pixel THR is adjusted
[12:44:27.929] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:44:28.887] INFO: Collecting data for 1 seconds...
[12:44:29.890] INFO: Done with hot pixel readout
[12:44:34.280] INFO: PixTest:: pg_setup set to default.
[12:44:34.281] INFO: 0 hot pixels found in step 0
[12:44:34.286] INFO: 0 hot pixels could not be trimmed and have been masked.
[12:44:34.346] INFO: PixTest::trimHotPixels() done
[12:44:34.346] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NY_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C0.dat
[12:44:34.358] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NY_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C1.dat
[12:44:34.363] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NY_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C2.dat
[12:44:34.369] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NY_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C3.dat
[12:44:34.374] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NY_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C4.dat
[12:44:34.380] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NY_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C5.dat
[12:44:34.385] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NY_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C6.dat
[12:44:34.391] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NY_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C7.dat
[12:44:34.396] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NY_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C8.dat
[12:44:34.402] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NY_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C9.dat
[12:44:34.407] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NY_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C10.dat
[12:44:34.413] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NY_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C11.dat
[12:44:34.418] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NY_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C12.dat
[12:44:34.424] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NY_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C13.dat
[12:44:34.429] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NY_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C14.dat
[12:44:34.435] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-H-NY_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//trimParameters35_C15.dat
[12:44:34.440] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Y-H-NY_FPIXTest-17C-FNAL-160506-1238_2016-05-06_12h38m_1462556301/000_FPIXTest_p17//defaultMaskFile.dat
[12:44:34.450] INFO: enter test to run
[12:45:01.420] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[12:45:01.420] INFO: running: xray
[12:45:01.421] INFO: ----------------------------------------------------------------------
[12:45:01.421] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:45:01.421] INFO: ----------------------------------------------------------------------
[12:45:02.385] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:45:13.091] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[12:45:42.584] INFO: Resuming triggers.
[12:45:53.295] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[12:46:22.973] INFO: Resuming triggers.
[12:46:33.686] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[12:47:03.280] INFO: Resuming triggers.
[12:47:13.993] INFO: run duration 42 seconds, buffer almost full (81%), pausing triggers.
[12:47:43.606] INFO: Resuming triggers.
[12:47:54.319] INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[12:48:23.882] INFO: Resuming triggers.
[12:48:34.593] INFO: run duration 64 seconds, buffer almost full (81%), pausing triggers.
[12:49:04.169] INFO: Resuming triggers.
[12:49:14.882] INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[12:49:44.523] INFO: Resuming triggers.
[12:49:55.237] INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[12:50:24.778] INFO: Resuming triggers.
[12:50:35.492] INFO: run duration 96 seconds, buffer almost full (81%), pausing triggers.
[12:51:05.147] INFO: Resuming triggers.
[12:51:09.062] INFO: data taking finished, elapsed time: 100 seconds.
[12:51:20.188] INFO: PixTest:: pg_setup set to default.
[12:51:20.191] INFO: PixTestXray::doPhRun() done
[12:51:20.352] INFO: enter test to run
[12:52:19.784] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[12:52:19.784] INFO: running: xray
[12:52:19.786] INFO: ----------------------------------------------------------------------
[12:52:19.786] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:52:19.786] INFO: ----------------------------------------------------------------------
[12:52:20.747] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:52:26.560] INFO: run duration 5 seconds, buffer almost full (81%), pausing triggers.
[12:52:56.683] INFO: Resuming triggers.
[12:53:02.495] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[12:53:33.946] INFO: Resuming triggers.
[12:53:39.761] INFO: run duration 17 seconds, buffer almost full (81%), pausing triggers.
[12:54:11.287] INFO: Resuming triggers.
[12:54:17.100] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[12:54:47.593] INFO: Resuming triggers.
[12:54:53.407] INFO: run duration 28 seconds, buffer almost full (81%), pausing triggers.
[12:55:23.542] INFO: Resuming triggers.
[12:55:29.355] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[12:55:59.467] INFO: Resuming triggers.
[12:56:05.279] INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[12:56:35.403] INFO: Resuming triggers.
[12:56:41.218] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[12:57:11.429] INFO: Resuming triggers.
[12:57:17.242] INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[12:57:47.395] INFO: Resuming triggers.
[12:57:53.211] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[12:58:23.465] INFO: Resuming triggers.
[12:58:29.283] INFO: run duration 63 seconds, buffer almost full (81%), pausing triggers.
[12:58:59.553] INFO: Resuming triggers.
[12:59:05.371] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[12:59:35.442] INFO: Resuming triggers.
[12:59:41.259] INFO: run duration 75 seconds, buffer almost full (81%), pausing triggers.
[13:00:11.469] INFO: Resuming triggers.
[13:00:17.288] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[13:00:47.493] INFO: Resuming triggers.
[13:00:53.311] INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[13:01:23.522] INFO: Resuming triggers.
[13:01:29.340] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[13:01:59.562] INFO: Resuming triggers.
[13:02:05.381] INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[13:02:35.591] INFO: Resuming triggers.
[13:02:37.065] INFO: data taking finished, elapsed time: 100 seconds.
[13:02:45.024] INFO: PixTest:: pg_setup set to default.
[13:02:45.027] INFO: PixTestXray::doPhRun() done
[13:02:45.177] INFO: enter test to run
[13:03:19.995] INFO: test: HighRate no parameter change
[13:03:19.995] INFO: running: highrate
[13:03:20.013] INFO: ----------------------------------------------------------------------
[13:03:20.014] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[13:03:20.014] INFO: ----------------------------------------------------------------------
[13:03:20.169] INFO: Expecting 768 events.
[13:03:21.299] INFO: 768 events read in total (414ms).
[13:03:21.300] INFO: Test took 1265ms.
[13:03:22.103] INFO: Expecting 41600 events.
[13:03:25.288] INFO: 41600 events read in total (2658ms).
[13:03:25.289] INFO: Test took 3958ms.
[13:03:25.330] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:03:26.047] INFO: Expecting 41600 events.
[13:03:29.322] INFO: 41600 events read in total (2749ms).
[13:03:29.323] INFO: Test took 3974ms.
[13:03:29.366] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:03:30.074] INFO: Expecting 41600 events.
[13:03:33.384] INFO: 41600 events read in total (2783ms).
[13:03:33.385] INFO: Test took 3998ms.
[13:03:33.437] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:03:34.111] INFO: Expecting 41600 events.
[13:03:37.435] INFO: 41600 events read in total (2797ms).
[13:03:37.436] INFO: Test took 3969ms.
[13:03:37.478] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:03:38.188] INFO: Expecting 41600 events.
[13:03:41.502] INFO: 41600 events read in total (2787ms).
[13:03:41.503] INFO: Test took 4005ms.
[13:03:41.544] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:03:42.250] INFO: Expecting 41600 events.
[13:03:45.569] INFO: 41600 events read in total (2792ms).
[13:03:45.570] INFO: Test took 4005ms.
[13:03:45.612] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:03:46.321] INFO: Expecting 41600 events.
[13:03:49.644] INFO: 41600 events read in total (2796ms).
[13:03:49.645] INFO: Test took 4013ms.
[13:03:49.687] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:03:50.393] INFO: Expecting 41600 events.
[13:03:53.729] INFO: 41600 events read in total (2810ms).
[13:03:53.730] INFO: Test took 4022ms.
[13:03:53.771] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:03:54.477] INFO: Expecting 41600 events.
[13:03:57.777] INFO: 41600 events read in total (2773ms).
[13:03:57.778] INFO: Test took 3986ms.
[13:03:57.823] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:03:58.526] INFO: Expecting 41600 events.
[13:04:01.755] INFO: 41600 events read in total (2702ms).
[13:04:01.756] INFO: Test took 3912ms.
[13:04:01.798] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:04:02.510] INFO: Expecting 41600 events.
[13:04:05.876] INFO: 41600 events read in total (2839ms).
[13:04:05.877] INFO: Test took 4059ms.
[13:04:05.917] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:04:06.623] INFO: Expecting 41600 events.
[13:04:09.942] INFO: 41600 events read in total (2792ms).
[13:04:09.943] INFO: Test took 4005ms.
[13:04:09.985] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:04:10.693] INFO: Expecting 41600 events.
[13:04:14.085] INFO: 41600 events read in total (2865ms).
[13:04:14.086] INFO: Test took 4081ms.
[13:04:14.128] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:04:14.830] INFO: Expecting 41600 events.
[13:04:18.194] INFO: 41600 events read in total (2838ms).
[13:04:18.195] INFO: Test took 4046ms.
[13:04:18.237] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:04:18.942] INFO: Expecting 41600 events.
[13:04:22.205] INFO: 41600 events read in total (2736ms).
[13:04:22.206] INFO: Test took 3949ms.
[13:04:22.248] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:04:22.956] INFO: Expecting 41600 events.
[13:04:26.409] INFO: 41600 events read in total (2926ms).
[13:04:26.410] INFO: Test took 4141ms.
[13:04:26.452] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:04:27.163] INFO: Expecting 41600 events.
[13:04:30.458] INFO: 41600 events read in total (2768ms).
[13:04:30.460] INFO: Test took 3988ms.
[13:04:30.501] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:04:31.203] INFO: Expecting 41600 events.
[13:04:34.599] INFO: 41600 events read in total (2869ms).
[13:04:34.601] INFO: Test took 4080ms.
[13:04:34.642] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:04:35.348] INFO: Expecting 41600 events.
[13:04:38.658] INFO: 41600 events read in total (2783ms).
[13:04:38.659] INFO: Test took 3997ms.
[13:04:38.701] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:04:39.411] INFO: Expecting 41600 events.
[13:04:42.594] INFO: 41600 events read in total (2656ms).
[13:04:42.595] INFO: Test took 3874ms.
[13:04:42.635] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:04:42.986] INFO: enter test to run
[13:05:02.979] INFO: test: HighRate no parameter change
[13:05:02.979] INFO: running: highrate
[13:05:02.980] INFO: ----------------------------------------------------------------------
[13:05:02.980] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:05:02.980] INFO: ----------------------------------------------------------------------
[13:05:03.594] INFO: Expecting 208000 events.
[13:05:16.212] INFO: 208000 events read in total (12091ms).
[13:05:16.216] INFO: Test took 13228ms.
[13:05:16.401] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:05:16.665] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[13:05:16.665] INFO: number of red-efficiency pixels: 91 65 109 156 196 171 169 132 106 147 156 112 116 95 33 32
[13:05:16.665] INFO: number of X-ray hits detected: 79183 53476 88105 133754 144615 147844 144859 103507 89317 112635 112216 98941 103265 66172 30438 33637
[13:05:16.665] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:05:16.665] INFO: number of Vcal hits detected: 207906 207934 207886 207837 207801 207823 207825 207865 207893 207848 207836 207880 207880 207905 207965 207968
[13:05:16.665] 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
[13:05:16.665] 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
[13:05:16.665] INFO: X-ray hit rate [MHz/cm2]: 23.2 15.7 25.8 39.2 42.4 43.3 42.5 30.3 26.2 33.0 32.9 29.0 30.3 19.4 8.9 9.9
[13:05:16.666] INFO: PixTestHighRate::doXPixelAlive() done
[13:05:16.710] INFO: PixTest:: pg_setup set to default.
[13:05:16.725] INFO: enter test to run
[13:05:40.426] INFO: test: HighRate no parameter change
[13:05:40.427] INFO: running: highrate
[13:05:40.428] INFO: ----------------------------------------------------------------------
[13:05:40.428] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:05:40.428] INFO: ----------------------------------------------------------------------
[13:05:41.050] INFO: Expecting 208000 events.
[13:05:55.771] INFO: 208000 events read in total (14194ms).
[13:05:55.777] INFO: Test took 15341ms.
[13:05:56.147] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:05:56.469] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[13:05:56.469] INFO: number of red-efficiency pixels: 258 187 493 591 753 666 646 423 395 579 540 405 464 314 75 76
[13:05:56.469] INFO: number of X-ray hits detected: 163284 111549 183199 278206 298226 304588 301583 215806 184560 235072 230560 205083 214192 137716 63881 70771
[13:05:56.469] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:05:56.469] INFO: number of Vcal hits detected: 207716 207803 207397 207350 207135 207235 207285 207538 207579 207369 207411 207580 207491 207649 207923 207923
[13:05:56.469] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.7 99.7 99.6 99.7 99.7 99.8 99.8 99.7 99.7 99.8 99.8 99.8 100.0 100.0
[13:05:56.469] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.7 99.7 99.6 99.6 99.7 99.8 99.8 99.7 99.7 99.8 99.8 99.8 100.0 100.0
[13:05:56.469] INFO: X-ray hit rate [MHz/cm2]: 47.9 32.7 53.7 81.5 87.4 89.3 88.4 63.3 54.1 68.9 67.6 60.1 62.8 40.4 18.7 20.7
[13:05:56.469] INFO: PixTestHighRate::doXPixelAlive() done
[13:05:56.514] INFO: PixTest:: pg_setup set to default.
[13:05:56.533] INFO: enter test to run
[13:06:20.066] INFO: test: HighRate no parameter change
[13:06:20.066] INFO: running: highrate
[13:06:20.067] INFO: ----------------------------------------------------------------------
[13:06:20.067] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:06:20.067] INFO: ----------------------------------------------------------------------
[13:06:20.683] INFO: Expecting 208000 events.
[13:06:37.624] INFO: 208000 events read in total (16414ms).
[13:06:37.632] INFO: Test took 17554ms.
[13:06:38.183] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:06:38.565] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[13:06:38.565] INFO: number of red-efficiency pixels: 606 408 1068 1340 1814 1590 1505 945 839 1393 1300 993 1077 729 166 118
[13:06:38.565] INFO: number of X-ray hits detected: 247531 168163 275237 418810 450961 461234 453581 325656 279725 354430 350441 310970 323442 208549 96770 106754
[13:06:38.565] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:06:38.565] INFO: number of Vcal hits detected: 207240 207536 206224 206201 205240 205719 205911 206733 206994 206184 206334 206756 206637 206993 207819 207878
[13:06:38.565] INFO: Vcal hit fiducial efficiency (%): 99.7 99.8 99.3 99.2 98.8 99.0 99.1 99.5 99.6 99.2 99.3 99.5 99.4 99.6 99.9 99.9
[13:06:38.565] INFO: Vcal hit overall efficiency (%): 99.6 99.8 99.1 99.1 98.7 98.9 99.0 99.4 99.5 99.1 99.2 99.4 99.3 99.5 99.9 99.9
[13:06:38.565] INFO: X-ray hit rate [MHz/cm2]: 72.6 49.3 80.7 122.8 132.2 135.2 132.9 95.5 82.0 103.9 102.7 91.1 94.8 61.1 28.4 31.3
[13:06:38.565] INFO: PixTestHighRate::doXPixelAlive() done
[13:06:38.614] INFO: PixTest:: pg_setup set to default.
[13:06:38.632] INFO: enter test to run
[13:07:06.850] INFO: test: exit no parameter change
[13:07:07.206] QUIET: Connection to board 33 closed.
[13:07:07.218] INFO: pXar: this is the end, my friend