[14:51:50.881] INFO: *** Welcome to pxar ***
[14:51:50.881] INFO: *** Today: 2016/06/29
[14:51:51.522] INFO: *** Version: v1.9.0-814-g7497
[14:51:51.522] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-3-14_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-3-14_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//dacParameters35_C15.dat
[14:51:51.600] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-3-14_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-3-14_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//tbmParameters_C0b.dat
[14:51:51.618] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-3-14_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//defaultMaskFile.dat
[14:51:51.618] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-3-14_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-3-14_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C15.dat
[14:51:51.733] INFO: clk: 4
[14:51:51.733] INFO: ctr: 4
[14:51:51.733] INFO: sda: 19
[14:51:51.733] INFO: tin: 9
[14:51:51.733] INFO: level: 15
[14:51:51.733] INFO: triggerdelay: 0
[14:51:51.733] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[14:51:51.733] INFO: Log level: INFO
[14:51:51.751] QUIET: Connection to board DTB_WREKRL opened.
[14:51:51.755] 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:
------------------------------------------------------
[14:51:51.757] INFO: RPC call hashes of host and DTB match: 398089610
[14:51:53.286] INFO: DUT info:
[14:51:53.286] INFO: The DUT currently contains the following objects:
[14:51:53.286] INFO: 2 TBM Cores tbm08c (2 ON)
[14:51:53.286] INFO: TBM Core alpha (0): 7 registers set
[14:51:53.286] INFO: TBM Core beta (1): 7 registers set
[14:51:53.286] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[14:51:53.286] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[14:51:53.286] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[14:51:53.286] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[14:51:53.286] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[14:51:53.286] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[14:51:53.286] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[14:51:53.286] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[14:51:53.286] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[14:51:53.287] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[14:51:53.287] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[14:51:53.287] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[14:51:53.287] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[14:51:53.287] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[14:51:53.287] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[14:51:53.287] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[14:51:53.287] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[14:51:53.690] INFO: enter 'restricted' command line mode
[14:51:53.690] INFO: enter test to run
[14:51:53.691] INFO: test: y no parameter change
[14:51:53.691] INFO: running: y
[14:51:53.691] INFO: command ->y<- not known, ignored
[14:51:53.691] INFO: enter test to run
[14:51:55.342] INFO: test: PixelAlive no parameter change
[14:51:55.342] INFO: running: pixelalive
[14:51:55.346] INFO: enter test to run
[14:51:58.510] INFO: test: PixelAlive no parameter change
[14:51:58.510] INFO: running: pixelalive
[14:51:58.515] INFO: ----------------------------------------------------------------------
[14:51:58.515] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[14:51:58.515] INFO: ----------------------------------------------------------------------
[14:51:58.835] INFO: Expecting 41600 events.
[14:52:03.218] INFO: 41600 events read in total (3665ms).
[14:52:03.384] INFO: Test took 4865ms.
[14:52:03.397] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:52:03.662] INFO: PixTestAlive::aliveTest() done
[14:52:03.662] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1 0
[14:52:03.692] INFO: enter test to run
[14:52:20.094] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[14:52:20.094] INFO: running: highrate
[14:52:20.110] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-3-14_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-3-14_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[14:52:20.370] INFO: ----------------------------------------------------------------------
[14:52:20.370] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[14:52:20.370] INFO: ----------------------------------------------------------------------
[14:52:20.370] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[14:52:20.370] INFO: edge/corner pixel THR is adjusted
[14:52:20.370] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:52:21.348] INFO: Collecting data for 5 seconds...
[14:52:26.364] INFO: Done with hot pixel readout
[14:52:37.934] INFO: PixTest:: pg_setup set to default.
[14:52:37.935] INFO: 10 hot pixels found in step 0
[14:52:38.942] INFO: Collecting data for 5 seconds...
[14:52:43.959] INFO: Done with hot pixel readout
[14:52:55.760] INFO: PixTest:: pg_setup set to default.
[14:52:55.761] INFO: 14 hot pixels found in step 1
[14:52:56.747] INFO: Collecting data for 5 seconds...
[14:53:01.764] INFO: Done with hot pixel readout
[14:53:12.922] INFO: PixTest:: pg_setup set to default.
[14:53:12.923] INFO: 10 hot pixels found in step 2
[14:53:13.909] INFO: Collecting data for 5 seconds...
[14:53:18.928] INFO: Done with hot pixel readout
[14:53:30.479] INFO: PixTest:: pg_setup set to default.
[14:53:30.480] INFO: 9 hot pixels found in step 3
[14:53:31.466] INFO: Collecting data for 5 seconds...
[14:53:36.487] INFO: Done with hot pixel readout
[14:53:47.945] INFO: PixTest:: pg_setup set to default.
[14:53:47.946] INFO: 8 hot pixels found in step 4
[14:53:48.932] INFO: Collecting data for 5 seconds...
[14:53:53.951] INFO: Done with hot pixel readout
[14:54:05.211] INFO: PixTest:: pg_setup set to default.
[14:54:05.212] INFO: 3 hot pixels found in step 5
[14:54:06.197] INFO: Collecting data for 5 seconds...
[14:54:11.217] INFO: Done with hot pixel readout
[14:54:22.728] INFO: PixTest:: pg_setup set to default.
[14:54:22.729] INFO: 6 hot pixels found in step 6
[14:54:23.715] INFO: Collecting data for 5 seconds...
[14:54:28.733] INFO: Done with hot pixel readout
[14:54:40.190] INFO: PixTest:: pg_setup set to default.
[14:54:40.191] INFO: 3 hot pixels found in step 7
[14:54:41.177] INFO: Collecting data for 5 seconds...
[14:54:46.193] INFO: Done with hot pixel readout
[14:54:58.034] INFO: PixTest:: pg_setup set to default.
[14:54:58.035] INFO: 0 hot pixels found in step 8
[14:54:58.067] INFO: 0 hot pixels could not be trimmed and have been masked.
[14:54:58.070] INFO: PixTest::trimHotPixels() done
[14:54:58.073] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-14_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C0.dat
[14:54:58.079] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-14_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C1.dat
[14:54:58.084] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-14_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C2.dat
[14:54:58.090] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-14_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C3.dat
[14:54:58.096] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-14_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C4.dat
[14:54:58.101] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-14_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C5.dat
[14:54:58.107] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-14_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C6.dat
[14:54:58.112] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-14_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C7.dat
[14:54:58.118] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-14_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C8.dat
[14:54:58.123] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-14_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C9.dat
[14:54:58.128] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-14_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C10.dat
[14:54:58.134] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-14_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C11.dat
[14:54:58.139] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-14_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C12.dat
[14:54:58.144] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-14_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C13.dat
[14:54:58.150] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-14_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C14.dat
[14:54:58.155] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-14_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C15.dat
[14:54:58.160] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-3-14_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//defaultMaskFile.dat
[14:54:58.171] INFO: enter test to run
[14:58:34.963] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[14:58:34.963] INFO: running: highrate
[14:58:34.968] INFO: ----------------------------------------------------------------------
[14:58:34.968] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[14:58:34.968] INFO: ----------------------------------------------------------------------
[14:58:34.968] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[14:58:34.968] INFO: edge/corner pixel THR is adjusted
[14:58:34.968] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:58:35.930] INFO: Collecting data for 1 seconds...
[14:58:36.934] INFO: Done with hot pixel readout
[14:58:40.773] INFO: PixTest:: pg_setup set to default.
[14:58:40.774] INFO: 0 hot pixels found in step 0
[14:58:40.780] INFO: 0 hot pixels could not be trimmed and have been masked.
[14:58:40.880] INFO: PixTest::trimHotPixels() done
[14:58:40.880] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-14_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C0.dat
[14:58:40.889] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-14_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C1.dat
[14:58:40.894] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-14_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C2.dat
[14:58:40.899] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-14_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C3.dat
[14:58:40.905] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-14_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C4.dat
[14:58:40.910] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-14_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C5.dat
[14:58:40.915] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-14_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C6.dat
[14:58:40.921] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-14_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C7.dat
[14:58:40.926] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-14_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C8.dat
[14:58:40.931] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-14_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C9.dat
[14:58:40.936] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-14_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C10.dat
[14:58:40.942] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-14_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C11.dat
[14:58:40.947] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-14_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C12.dat
[14:58:40.952] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-14_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C13.dat
[14:58:40.958] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-14_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C14.dat
[14:58:40.963] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-14_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C15.dat
[14:58:40.968] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-3-14_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//defaultMaskFile.dat
[14:58:40.977] INFO: enter test to run
[15:01:46.866] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[15:01:46.866] INFO: running: xray
[15:01:46.867] INFO: ----------------------------------------------------------------------
[15:01:46.867] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:01:46.867] INFO: ----------------------------------------------------------------------
[15:01:47.830] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:01:59.535] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[15:02:28.943] INFO: Resuming triggers.
[15:02:40.646] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[15:03:09.588] INFO: Resuming triggers.
[15:03:21.288] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[15:03:50.549] INFO: Resuming triggers.
[15:04:02.248] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[15:04:31.574] INFO: Resuming triggers.
[15:04:43.275] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[15:05:12.797] INFO: Resuming triggers.
[15:05:24.497] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[15:05:54.208] INFO: Resuming triggers.
[15:06:05.913] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[15:06:35.852] INFO: Resuming triggers.
[15:06:47.556] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[15:07:16.671] INFO: Resuming triggers.
[15:07:23.400] INFO: data taking finished, elapsed time: 100 seconds.
[15:07:41.178] INFO: PixTest:: pg_setup set to default.
[15:07:41.181] INFO: PixTestXray::doPhRun() done
[15:07:41.348] INFO: enter test to run
[15:12:20.326] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[15:12:20.326] INFO: running: xray
[15:12:20.327] INFO: ----------------------------------------------------------------------
[15:12:20.327] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:12:20.327] INFO: ----------------------------------------------------------------------
[15:12:21.290] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:12:28.395] INFO: run duration 7 seconds, buffer almost full (81%), pausing triggers.
[15:12:58.665] INFO: Resuming triggers.
[15:13:05.770] INFO: run duration 14 seconds, buffer almost full (81%), pausing triggers.
[15:13:35.670] INFO: Resuming triggers.
[15:13:42.779] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[15:14:13.015] INFO: Resuming triggers.
[15:14:20.121] INFO: run duration 28 seconds, buffer almost full (81%), pausing triggers.
[15:14:50.357] INFO: Resuming triggers.
[15:14:57.466] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[15:15:27.651] INFO: Resuming triggers.
[15:15:34.755] INFO: run duration 42 seconds, buffer almost full (81%), pausing triggers.
[15:16:04.867] INFO: Resuming triggers.
[15:16:11.969] INFO: run duration 49 seconds, buffer almost full (81%), pausing triggers.
[15:16:42.668] INFO: Resuming triggers.
[15:16:49.770] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[15:17:20.508] INFO: Resuming triggers.
[15:17:27.611] INFO: run duration 63 seconds, buffer almost full (81%), pausing triggers.
[15:17:58.209] INFO: Resuming triggers.
[15:18:05.318] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[15:18:36.146] INFO: Resuming triggers.
[15:18:43.251] INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.
[15:19:14.765] INFO: Resuming triggers.
[15:19:21.866] INFO: run duration 84 seconds, buffer almost full (81%), pausing triggers.
[15:19:53.307] INFO: Resuming triggers.
[15:20:00.411] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[15:20:30.640] INFO: Resuming triggers.
[15:20:37.744] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[15:21:07.931] INFO: Resuming triggers.
[15:21:08.810] INFO: data taking finished, elapsed time: 100 seconds.
[15:21:12.892] INFO: PixTest:: pg_setup set to default.
[15:21:12.895] INFO: PixTestXray::doPhRun() done
[15:21:13.044] INFO: enter test to run
[15:32:10.398] INFO: test: HighRate no parameter change
[15:32:10.398] INFO: running: highrate
[15:32:10.415] INFO: ----------------------------------------------------------------------
[15:32:10.415] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[15:32:10.415] INFO: ----------------------------------------------------------------------
[15:32:10.570] INFO: Expecting 768 events.
[15:32:11.706] INFO: 768 events read in total (420ms).
[15:32:11.707] INFO: Test took 1270ms.
[15:32:12.509] INFO: Expecting 41600 events.
[15:32:15.575] INFO: 41600 events read in total (2539ms).
[15:32:15.576] INFO: Test took 3846ms.
[15:32:15.607] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:32:16.338] INFO: Expecting 41600 events.
[15:32:19.507] INFO: 41600 events read in total (2643ms).
[15:32:19.508] INFO: Test took 3885ms.
[15:32:19.540] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:32:20.265] INFO: Expecting 41600 events.
[15:32:23.481] INFO: 41600 events read in total (2689ms).
[15:32:23.482] INFO: Test took 3924ms.
[15:32:23.513] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:32:24.240] INFO: Expecting 41600 events.
[15:32:27.475] INFO: 41600 events read in total (2708ms).
[15:32:27.476] INFO: Test took 3946ms.
[15:32:27.508] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:32:28.231] INFO: Expecting 41600 events.
[15:32:31.438] INFO: 41600 events read in total (2680ms).
[15:32:31.439] INFO: Test took 3913ms.
[15:32:31.471] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:32:32.198] INFO: Expecting 41600 events.
[15:32:35.409] INFO: 41600 events read in total (2684ms).
[15:32:35.410] INFO: Test took 3921ms.
[15:32:35.442] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:32:36.168] INFO: Expecting 41600 events.
[15:32:39.383] INFO: 41600 events read in total (2688ms).
[15:32:39.384] INFO: Test took 3924ms.
[15:32:39.415] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:32:40.146] INFO: Expecting 41600 events.
[15:32:43.376] INFO: 41600 events read in total (2704ms).
[15:32:43.377] INFO: Test took 3944ms.
[15:32:43.410] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:32:44.133] INFO: Expecting 41600 events.
[15:32:47.352] INFO: 41600 events read in total (2692ms).
[15:32:47.353] INFO: Test took 3927ms.
[15:32:47.386] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:32:48.113] INFO: Expecting 41600 events.
[15:32:51.319] INFO: 41600 events read in total (2680ms).
[15:32:51.320] INFO: Test took 3915ms.
[15:32:51.352] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:32:52.076] INFO: Expecting 41600 events.
[15:32:55.304] INFO: 41600 events read in total (2701ms).
[15:32:55.304] INFO: Test took 3933ms.
[15:32:55.337] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:32:56.061] INFO: Expecting 41600 events.
[15:32:59.288] INFO: 41600 events read in total (2700ms).
[15:32:59.289] INFO: Test took 3935ms.
[15:32:59.321] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:00.045] INFO: Expecting 41600 events.
[15:33:03.263] INFO: 41600 events read in total (2691ms).
[15:33:03.264] INFO: Test took 3924ms.
[15:33:03.297] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:04.024] INFO: Expecting 41600 events.
[15:33:07.246] INFO: 41600 events read in total (2695ms).
[15:33:07.247] INFO: Test took 3932ms.
[15:33:07.278] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:08.006] INFO: Expecting 41600 events.
[15:33:11.232] INFO: 41600 events read in total (2699ms).
[15:33:11.233] INFO: Test took 3936ms.
[15:33:11.264] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:11.993] INFO: Expecting 41600 events.
[15:33:15.213] INFO: 41600 events read in total (2693ms).
[15:33:15.214] INFO: Test took 3931ms.
[15:33:15.247] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:15.973] INFO: Expecting 41600 events.
[15:33:19.200] INFO: 41600 events read in total (2701ms).
[15:33:19.201] INFO: Test took 3936ms.
[15:33:19.233] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:19.962] INFO: Expecting 41600 events.
[15:33:23.184] INFO: 41600 events read in total (2695ms).
[15:33:23.185] INFO: Test took 3935ms.
[15:33:23.217] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:23.946] INFO: Expecting 41600 events.
[15:33:27.153] INFO: 41600 events read in total (2680ms).
[15:33:27.154] INFO: Test took 3919ms.
[15:33:27.186] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:27.911] INFO: Expecting 41600 events.
[15:33:30.990] INFO: 41600 events read in total (2552ms).
[15:33:30.991] INFO: Test took 3786ms.
[15:33:31.022] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:31.391] INFO: enter test to run
[15:38:23.835] INFO: test: HighRate no parameter change
[15:38:23.835] INFO: running: highrate
[15:38:23.836] INFO: ----------------------------------------------------------------------
[15:38:23.836] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:38:23.837] INFO: ----------------------------------------------------------------------
[15:38:24.453] INFO: Expecting 208000 events.
[15:38:36.210] INFO: 208000 events read in total (11230ms).
[15:38:36.213] INFO: Test took 12364ms.
[15:38:36.344] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:38:36.595] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1 0
[15:38:36.595] INFO: number of red-efficiency pixels: 75 52 68 108 94 107 99 75 86 118 102 100 104 62 43 28
[15:38:36.595] INFO: number of X-ray hits detected: 61575 38451 57089 88347 89433 92663 95599 72019 79547 103824 100914 84161 88021 53581 22094 26283
[15:38:36.595] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:38:36.595] INFO: number of Vcal hits detected: 207925 207947 207931 207891 207903 207892 207901 207925 207913 207877 207897 207897 207892 207937 207908 207971
[15:38:36.595] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0 99.9 100.0 100.0 99.9 100.0 100.0 100.0
[15:38:36.595] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 100.0 99.9 100.0 100.0 100.0 99.9 100.0 100.0 99.9 100.0 100.0 100.0
[15:38:36.595] INFO: X-ray hit rate [MHz/cm2]: 18.0 11.3 16.7 25.9 26.2 27.2 28.0 21.1 23.3 30.4 29.6 24.7 25.8 15.7 6.5 7.7
[15:38:36.595] INFO: PixTestHighRate::doXPixelAlive() done
[15:38:36.647] INFO: PixTest:: pg_setup set to default.
[15:38:36.663] INFO: enter test to run
[15:39:33.339] INFO: test: HighRate no parameter change
[15:39:33.339] INFO: running: highrate
[15:39:33.340] INFO: ----------------------------------------------------------------------
[15:39:33.340] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:39:33.340] INFO: ----------------------------------------------------------------------
[15:39:33.958] INFO: Expecting 208000 events.
[15:39:47.233] INFO: 208000 events read in total (12748ms).
[15:39:47.238] INFO: Test took 13885ms.
[15:39:47.513] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:39:47.808] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1 0
[15:39:47.808] INFO: number of red-efficiency pixels: 219 108 246 349 255 294 290 197 218 351 345 320 327 220 53 64
[15:39:47.808] INFO: number of X-ray hits detected: 125010 78199 115136 181184 183626 189006 192888 146574 161717 210801 205747 171938 178633 108530 44590 53931
[15:39:47.808] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:39:47.808] INFO: number of Vcal hits detected: 207771 207887 207747 207632 207737 207694 207690 207792 207772 207618 207638 207653 207655 207768 207898 207932
[15:39:47.808] INFO: Vcal hit fiducial efficiency (%): 99.9 100.0 99.9 99.8 99.9 99.9 99.9 99.9 99.9 99.8 99.8 99.9 99.8 99.9 100.0 100.0
[15:39:47.808] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.9 99.9 99.9 99.9 99.9 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[15:39:47.808] INFO: X-ray hit rate [MHz/cm2]: 36.6 22.9 33.7 53.1 53.8 55.4 56.5 43.0 47.4 61.8 60.3 50.4 52.4 31.8 13.1 15.8
[15:39:47.808] INFO: PixTestHighRate::doXPixelAlive() done
[15:39:47.856] INFO: PixTest:: pg_setup set to default.
[15:39:47.873] INFO: enter test to run
[15:40:16.083] INFO: test: HighRate no parameter change
[15:40:16.083] INFO: running: highrate
[15:40:16.084] INFO: ----------------------------------------------------------------------
[15:40:16.084] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:40:16.084] INFO: ----------------------------------------------------------------------
[15:40:16.707] INFO: Expecting 208000 events.
[15:40:31.549] INFO: 208000 events read in total (14315ms).
[15:40:31.555] INFO: Test took 15459ms.
[15:40:31.965] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:40:32.306] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1 0
[15:40:32.306] INFO: number of red-efficiency pixels: 455 217 439 713 529 741 688 440 458 811 682 678 731 424 101 101
[15:40:32.306] INFO: number of X-ray hits detected: 186734 118612 173888 270569 275015 284416 290760 220316 243304 316022 309147 258155 268949 163559 67808 80889
[15:40:32.306] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:40:32.306] INFO: number of Vcal hits detected: 207456 207759 207475 207159 207410 207126 207228 207514 207495 207025 207202 207188 207162 207486 207841 207899
[15:40:32.306] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.8 99.6 99.7 99.6 99.7 99.8 99.8 99.6 99.6 99.7 99.6 99.8 100.0 100.0
[15:40:32.306] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.7 99.6 99.7 99.6 99.6 99.8 99.8 99.5 99.6 99.6 99.6 99.8 99.9 100.0
[15:40:32.306] INFO: X-ray hit rate [MHz/cm2]: 54.7 34.8 51.0 79.3 80.6 83.4 85.2 64.6 71.3 92.6 90.6 75.7 78.8 47.9 19.9 23.7
[15:40:32.306] INFO: PixTestHighRate::doXPixelAlive() done
[15:40:32.352] INFO: PixTest:: pg_setup set to default.
[15:40:32.363] INFO: enter test to run
[15:40:39.242] INFO: test: exit no parameter change
[15:40:39.496] QUIET: Connection to board 33 closed.
[15:40:39.507] INFO: pXar: this is the end, my friend