[12:20:31.874] INFO: *** Welcome to pxar ***
[12:20:31.874] INFO: *** Today: 2016/07/21
[12:20:31.893] INFO: *** Version: v1.9.0-814-g7497
[12:20:31.893] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160629-0958_2016-06-29_12h25m_1467221111/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160629-0958_2016-06-29_12h25m_1467221111/000_FPIXTest_p17//dacParameters35_C15.dat
[12:20:31.894] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160629-0958_2016-06-29_12h25m_1467221111/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160629-0958_2016-06-29_12h25m_1467221111/000_FPIXTest_p17//tbmParameters_C0b.dat
[12:20:31.894] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160629-0958_2016-06-29_12h25m_1467221111/000_FPIXTest_p17//defaultMaskFile.dat
[12:20:31.894] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160629-0958_2016-06-29_12h25m_1467221111/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160629-0958_2016-06-29_12h25m_1467221111/000_FPIXTest_p17//trimParameters35_C15.dat
[12:20:31.965] INFO: clk: 4
[12:20:31.965] INFO: ctr: 4
[12:20:31.965] INFO: sda: 19
[12:20:31.965] INFO: tin: 9
[12:20:31.965] INFO: level: 15
[12:20:31.966] INFO: triggerdelay: 0
[12:20:31.966] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[12:20:31.966] INFO: Log level: INFO
[12:20:31.984] QUIET: Connection to board DTB_WREKRL opened.
[12:20:31.987] 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:20:31.990] INFO: RPC call hashes of host and DTB match: 398089610
[12:20:33.524] INFO: DUT info:
[12:20:33.524] INFO: The DUT currently contains the following objects:
[12:20:33.524] INFO: 2 TBM Cores tbm08c (2 ON)
[12:20:33.524] INFO: TBM Core alpha (0): 7 registers set
[12:20:33.524] INFO: TBM Core beta (1): 7 registers set
[12:20:33.524] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[12:20:33.524] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[12:20:33.524] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[12:20:33.524] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[12:20:33.524] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[12:20:33.524] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[12:20:33.524] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[12:20:33.524] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[12:20:33.524] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[12:20:33.524] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[12:20:33.524] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[12:20:33.525] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[12:20:33.525] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[12:20:33.525] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[12:20:33.525] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[12:20:33.525] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[12:20:33.525] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[12:20:33.928] INFO: enter 'restricted' command line mode
[12:20:33.928] INFO: enter test to run
[12:20:42.020] INFO: test: PixelAlive no parameter change
[12:20:42.020] INFO: running: pixelalive
[12:20:42.029] INFO: ----------------------------------------------------------------------
[12:20:42.029] 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:20:42.029] INFO: ----------------------------------------------------------------------
[12:20:42.346] INFO: Expecting 41600 events.
[12:20:46.691] INFO: 41600 events read in total (3626ms).
[12:20:46.856] INFO: Test took 4824ms.
[12:20:46.866] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:20:47.132] INFO: PixTestAlive::aliveTest() done
[12:20:47.132] INFO: number of dead pixels (per ROC): 0 1 0 1 0 0 0 0 0 0 1 0 0 1 2 0
[12:20:47.161] INFO: enter test to run
[12:21:22.700] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[12:21:22.700] INFO: running: highrate
[12:21:22.700] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160629-0958_2016-06-29_12h25m_1467221111/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160629-0958_2016-06-29_12h25m_1467221111/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[12:21:22.925] INFO: ----------------------------------------------------------------------
[12:21:22.925] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[12:21:22.925] INFO: ----------------------------------------------------------------------
[12:21:22.925] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[12:21:22.925] INFO: edge/corner pixel THR is adjusted
[12:21:22.925] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:21:23.886] INFO: Collecting data for 5 seconds...
[12:21:28.904] INFO: Done with hot pixel readout
[12:21:41.080] INFO: PixTest:: pg_setup set to default.
[12:21:41.081] INFO: 56 hot pixels found in step 0
[12:21:42.075] INFO: Collecting data for 5 seconds...
[12:21:47.092] INFO: Done with hot pixel readout
[12:21:58.985] INFO: PixTest:: pg_setup set to default.
[12:21:58.986] INFO: 33 hot pixels found in step 1
[12:21:59.984] INFO: Collecting data for 5 seconds...
[12:22:04.000] INFO: Done with hot pixel readout
[12:22:16.853] INFO: PixTest:: pg_setup set to default.

[12:22:16.854] INFO: 8 hot pixels found in step 2
[12:22:17.847] INFO: Collecting data for 5 seconds...
[12:22:22.867] INFO: Done with hot pixel readout
[12:22:34.965] INFO: PixTest:: pg_setup set to default.
[12:22:34.966] INFO: 6 hot pixels found in step 3
[12:22:35.961] INFO: Collecting data for 5 seconds...
[12:22:40.980] INFO: Done with hot pixel readout
[12:22:52.739] INFO: PixTest:: pg_setup set to default.
[12:22:52.740] INFO: 3 hot pixels found in step 4
[12:22:53.735] INFO: Collecting data for 5 seconds...
[12:22:58.755] INFO: Done with hot pixel readout
[12:23:10.639] INFO: PixTest:: pg_setup set to default.

[12:23:10.640] INFO: 2 hot pixels found in step 5
[12:23:11.634] INFO: Collecting data for 5 seconds...
[12:23:16.653] INFO: Done with hot pixel readout
[12:23:28.439] INFO: PixTest:: pg_setup set to default.
[12:23:28.440] INFO: 2 hot pixels found in step 6
[12:23:29.436] INFO: Collecting data for 5 seconds...
[12:23:34.453] INFO: Done with hot pixel readout
[12:23:46.251] INFO: PixTest:: pg_setup set to default.
[12:23:46.252] INFO: 2 hot pixels found in step 7
[12:23:47.246] INFO: Collecting data for 5 seconds...
[12:23:52.264] INFO: Done with hot pixel readout
[12:24:03.692] INFO: PixTest:: pg_setup set to default.
[12:24:03.693] INFO: 4 hot pixels found in step 8
[12:24:04.687] INFO: Collecting data for 5 seconds...
[12:24:09.707] INFO: Done with hot pixel readout
[12:24:21.202] INFO: PixTest:: pg_setup set to default.
[12:24:21.203] INFO: 6 hot pixels found in step 9
[12:24:22.198] INFO: Collecting data for 5 seconds...
[12:24:27.215] INFO: Done with hot pixel readout
[12:24:39.181] INFO: PixTest:: pg_setup set to default.
[12:24:39.182] INFO: 5 hot pixels found in step 10
[12:24:40.176] INFO: Collecting data for 5 seconds...
[12:24:45.197] INFO: Done with hot pixel readout
[12:24:57.331] INFO: PixTest:: pg_setup set to default.
[12:24:57.332] INFO: 5 hot pixels found in step 11
[12:24:58.326] INFO: Collecting data for 5 seconds...
[12:25:03.346] INFO: Done with hot pixel readout
[12:25:15.470] INFO: PixTest:: pg_setup set to default.
[12:25:15.471] INFO: 3 hot pixels found in step 12
[12:25:16.465] INFO: Collecting data for 5 seconds...
[12:25:21.483] INFO: Done with hot pixel readout
[12:25:33.370] INFO: PixTest:: pg_setup set to default.
[12:25:33.371] INFO: 6 hot pixels found in step 13
[12:25:34.365] INFO: Collecting data for 5 seconds...
[12:25:39.385] INFO: Done with hot pixel readout
[12:25:51.451] INFO: PixTest:: pg_setup set to default.
[12:25:51.452] INFO: 4 hot pixels found in step 14
[12:25:51.490] INFO: 4 hot pixels could not be trimmed and have been masked.
[12:25:51.494] INFO: PixTest::trimHotPixels() done
[12:25:51.510] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160629-0958_2016-06-29_12h25m_1467221111/000_FPIXTest_p17//trimParameters35_C0.dat
[12:25:51.517] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160629-0958_2016-06-29_12h25m_1467221111/000_FPIXTest_p17//trimParameters35_C1.dat
[12:25:51.523] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160629-0958_2016-06-29_12h25m_1467221111/000_FPIXTest_p17//trimParameters35_C2.dat
[12:25:51.528] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160629-0958_2016-06-29_12h25m_1467221111/000_FPIXTest_p17//trimParameters35_C3.dat
[12:25:51.534] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160629-0958_2016-06-29_12h25m_1467221111/000_FPIXTest_p17//trimParameters35_C4.dat
[12:25:51.539] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160629-0958_2016-06-29_12h25m_1467221111/000_FPIXTest_p17//trimParameters35_C5.dat
[12:25:51.545] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160629-0958_2016-06-29_12h25m_1467221111/000_FPIXTest_p17//trimParameters35_C6.dat
[12:25:51.550] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160629-0958_2016-06-29_12h25m_1467221111/000_FPIXTest_p17//trimParameters35_C7.dat
[12:25:51.556] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160629-0958_2016-06-29_12h25m_1467221111/000_FPIXTest_p17//trimParameters35_C8.dat
[12:25:51.561] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160629-0958_2016-06-29_12h25m_1467221111/000_FPIXTest_p17//trimParameters35_C9.dat
[12:25:51.567] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160629-0958_2016-06-29_12h25m_1467221111/000_FPIXTest_p17//trimParameters35_C10.dat
[12:25:51.572] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160629-0958_2016-06-29_12h25m_1467221111/000_FPIXTest_p17//trimParameters35_C11.dat
[12:25:51.578] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160629-0958_2016-06-29_12h25m_1467221111/000_FPIXTest_p17//trimParameters35_C12.dat
[12:25:51.583] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160629-0958_2016-06-29_12h25m_1467221111/000_FPIXTest_p17//trimParameters35_C13.dat
[12:25:51.589] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160629-0958_2016-06-29_12h25m_1467221111/000_FPIXTest_p17//trimParameters35_C14.dat
[12:25:51.594] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160629-0958_2016-06-29_12h25m_1467221111/000_FPIXTest_p17//trimParameters35_C15.dat
[12:25:51.599] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160629-0958_2016-06-29_12h25m_1467221111/000_FPIXTest_p17//defaultMaskFile.dat
[12:25:51.612] INFO: enter test to run
[12:27:15.338] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[12:27:15.338] INFO: running: highrate
[12:27:15.342] INFO: ----------------------------------------------------------------------
[12:27:15.342] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[12:27:15.343] INFO: ----------------------------------------------------------------------
[12:27:15.343] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[12:27:15.343] INFO: edge/corner pixel THR is adjusted
[12:27:15.343] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:27:16.300] INFO: Collecting data for 1 seconds...
[12:27:17.304] INFO: Done with hot pixel readout
[12:27:21.378] INFO: PixTest:: pg_setup set to default.
[12:27:21.379] INFO: 0 hot pixels found in step 0
[12:27:21.386] INFO: 0 hot pixels could not be trimmed and have been masked.
[12:27:21.474] INFO: PixTest::trimHotPixels() done
[12:27:21.474] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160629-0958_2016-06-29_12h25m_1467221111/000_FPIXTest_p17//trimParameters35_C0.dat
[12:27:21.484] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160629-0958_2016-06-29_12h25m_1467221111/000_FPIXTest_p17//trimParameters35_C1.dat
[12:27:21.489] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160629-0958_2016-06-29_12h25m_1467221111/000_FPIXTest_p17//trimParameters35_C2.dat
[12:27:21.495] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160629-0958_2016-06-29_12h25m_1467221111/000_FPIXTest_p17//trimParameters35_C3.dat
[12:27:21.500] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160629-0958_2016-06-29_12h25m_1467221111/000_FPIXTest_p17//trimParameters35_C4.dat
[12:27:21.505] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160629-0958_2016-06-29_12h25m_1467221111/000_FPIXTest_p17//trimParameters35_C5.dat
[12:27:21.511] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160629-0958_2016-06-29_12h25m_1467221111/000_FPIXTest_p17//trimParameters35_C6.dat
[12:27:21.516] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160629-0958_2016-06-29_12h25m_1467221111/000_FPIXTest_p17//trimParameters35_C7.dat
[12:27:21.521] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160629-0958_2016-06-29_12h25m_1467221111/000_FPIXTest_p17//trimParameters35_C8.dat
[12:27:21.526] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160629-0958_2016-06-29_12h25m_1467221111/000_FPIXTest_p17//trimParameters35_C9.dat
[12:27:21.532] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160629-0958_2016-06-29_12h25m_1467221111/000_FPIXTest_p17//trimParameters35_C10.dat
[12:27:21.537] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160629-0958_2016-06-29_12h25m_1467221111/000_FPIXTest_p17//trimParameters35_C11.dat
[12:27:21.542] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160629-0958_2016-06-29_12h25m_1467221111/000_FPIXTest_p17//trimParameters35_C12.dat
[12:27:21.548] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160629-0958_2016-06-29_12h25m_1467221111/000_FPIXTest_p17//trimParameters35_C13.dat
[12:27:21.553] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160629-0958_2016-06-29_12h25m_1467221111/000_FPIXTest_p17//trimParameters35_C14.dat
[12:27:21.558] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160629-0958_2016-06-29_12h25m_1467221111/000_FPIXTest_p17//trimParameters35_C15.dat
[12:27:21.564] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-2-06_FPIXTest-17C-FNAL-160629-0958_2016-06-29_12h25m_1467221111/000_FPIXTest_p17//defaultMaskFile.dat
[12:27:21.573] INFO: enter test to run
[12:27:51.625] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[12:27:51.625] INFO: running: xray
[12:27:51.627] INFO: ----------------------------------------------------------------------
[12:27:51.627] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:27:51.627] INFO: ----------------------------------------------------------------------
[12:27:52.592] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:28:03.921] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[12:28:33.397] INFO: Resuming triggers.
[12:28:44.721] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[12:29:14.063] INFO: Resuming triggers.
[12:29:25.390] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[12:29:54.794] INFO: Resuming triggers.
[12:30:06.126] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[12:30:35.474] INFO: Resuming triggers.
[12:30:46.802] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[12:31:15.965] INFO: Resuming triggers.
[12:31:27.293] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[12:31:56.732] INFO: Resuming triggers.
[12:32:08.065] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[12:32:37.441] INFO: Resuming triggers.
[12:32:48.774] INFO: run duration 90 seconds, buffer almost full (81%), pausing triggers.
[12:33:18.169] INFO: Resuming triggers.
[12:33:27.864] INFO: data taking finished, elapsed time: 100 seconds.
[12:33:53.002] INFO: PixTest:: pg_setup set to default.
[12:33:53.005] INFO: PixTestXray::doPhRun() done
[12:33:53.143] INFO: enter test to run
[12:34:36.847] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[12:34:36.847] INFO: running: xray
[12:34:36.848] INFO: ----------------------------------------------------------------------
[12:34:36.848] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:34:36.848] INFO: ----------------------------------------------------------------------
[12:34:37.828] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:34:44.468] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[12:35:15.463] INFO: Resuming triggers.
[12:35:22.104] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[12:35:52.786] INFO: Resuming triggers.
[12:35:59.423] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[12:36:29.496] INFO: Resuming triggers.
[12:36:36.139] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[12:37:07.640] INFO: Resuming triggers.
[12:37:14.283] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[12:37:45.597] INFO: Resuming triggers.
[12:37:52.238] INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[12:38:22.870] INFO: Resuming triggers.
[12:38:29.512] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[12:38:59.688] INFO: Resuming triggers.
[12:39:06.331] INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[12:39:36.430] INFO: Resuming triggers.
[12:39:43.074] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[12:40:13.221] INFO: Resuming triggers.
[12:40:19.863] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[12:40:50.020] INFO: Resuming triggers.
[12:40:56.664] INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[12:41:26.731] INFO: Resuming triggers.
[12:41:33.374] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[12:42:03.459] INFO: Resuming triggers.
[12:42:10.097] INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[12:42:40.182] INFO: Resuming triggers.
[12:42:46.824] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[12:43:16.886] INFO: Resuming triggers.
[12:43:23.521] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[12:43:53.622] INFO: Resuming triggers.
[12:43:54.358] INFO: data taking finished, elapsed time: 100 seconds.
[12:43:58.064] INFO: PixTest:: pg_setup set to default.
[12:43:58.067] INFO: PixTestXray::doPhRun() done
[12:43:58.217] INFO: enter test to run
[12:44:31.635] INFO: test: HighRate no parameter change
[12:44:31.635] INFO: running: highrate
[12:44:31.636] INFO: ----------------------------------------------------------------------
[12:44:31.636] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[12:44:31.636] INFO: ----------------------------------------------------------------------
[12:44:31.777] INFO: Expecting 768 events.
[12:44:32.911] INFO: 768 events read in total (418ms).
[12:44:32.911] INFO: Test took 1269ms.
[12:44:33.714] INFO: Expecting 41600 events.
[12:44:36.824] INFO: 41600 events read in total (2583ms).
[12:44:36.825] INFO: Test took 3906ms.
[12:44:36.859] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:37.584] INFO: Expecting 41600 events.
[12:44:40.776] INFO: 41600 events read in total (2666ms).
[12:44:40.777] INFO: Test took 3900ms.
[12:44:40.811] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:41.535] INFO: Expecting 41600 events.
[12:44:44.761] INFO: 41600 events read in total (2699ms).
[12:44:44.762] INFO: Test took 3932ms.
[12:44:44.797] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:45.521] INFO: Expecting 41600 events.
[12:44:48.755] INFO: 41600 events read in total (2707ms).
[12:44:48.756] INFO: Test took 3942ms.
[12:44:48.790] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:49.511] INFO: Expecting 41600 events.
[12:44:52.767] INFO: 41600 events read in total (2729ms).
[12:44:52.768] INFO: Test took 3960ms.
[12:44:52.804] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:53.526] INFO: Expecting 41600 events.
[12:44:56.774] INFO: 41600 events read in total (2721ms).
[12:44:56.775] INFO: Test took 3953ms.
[12:44:56.810] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:57.534] INFO: Expecting 41600 events.
[12:45:00.780] INFO: 41600 events read in total (2719ms).
[12:45:00.781] INFO: Test took 3953ms.
[12:45:00.817] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:01.537] INFO: Expecting 41600 events.
[12:45:04.786] INFO: 41600 events read in total (2722ms).
[12:45:04.787] INFO: Test took 3953ms.
[12:45:04.822] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:05.541] INFO: Expecting 41600 events.
[12:45:08.786] INFO: 41600 events read in total (2718ms).
[12:45:08.787] INFO: Test took 3946ms.
[12:45:08.821] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:09.544] INFO: Expecting 41600 events.
[12:45:12.783] INFO: 41600 events read in total (2712ms).
[12:45:12.784] INFO: Test took 3944ms.
[12:45:12.820] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:13.544] INFO: Expecting 41600 events.
[12:45:16.789] INFO: 41600 events read in total (2718ms).
[12:45:16.790] INFO: Test took 3953ms.
[12:45:16.825] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:17.547] INFO: Expecting 41600 events.
[12:45:20.796] INFO: 41600 events read in total (2722ms).
[12:45:20.797] INFO: Test took 3953ms.
[12:45:20.831] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:21.553] INFO: Expecting 41600 events.
[12:45:24.791] INFO: 41600 events read in total (2711ms).
[12:45:24.792] INFO: Test took 3941ms.
[12:45:24.827] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:25.549] INFO: Expecting 41600 events.
[12:45:28.790] INFO: 41600 events read in total (2715ms).
[12:45:28.791] INFO: Test took 3946ms.
[12:45:28.826] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:29.549] INFO: Expecting 41600 events.
[12:45:32.800] INFO: 41600 events read in total (2724ms).
[12:45:32.801] INFO: Test took 3955ms.
[12:45:32.836] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:33.560] INFO: Expecting 41600 events.
[12:45:36.815] INFO: 41600 events read in total (2728ms).
[12:45:36.816] INFO: Test took 3962ms.
[12:45:36.852] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:37.571] INFO: Expecting 41600 events.
[12:45:40.826] INFO: 41600 events read in total (2728ms).
[12:45:40.827] INFO: Test took 3956ms.
[12:45:40.861] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:41.586] INFO: Expecting 41600 events.
[12:45:44.856] INFO: 41600 events read in total (2743ms).
[12:45:44.857] INFO: Test took 3976ms.
[12:45:44.892] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:45.615] INFO: Expecting 41600 events.
[12:45:48.841] INFO: 41600 events read in total (2699ms).
[12:45:48.842] INFO: Test took 3933ms.
[12:45:48.877] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:49.600] INFO: Expecting 41600 events.
[12:45:52.713] INFO: 41600 events read in total (2586ms).
[12:45:52.714] INFO: Test took 3819ms.
[12:45:52.748] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:53.110] INFO: enter test to run
[12:46:06.530] INFO: test: HighRate no parameter change
[12:46:06.530] INFO: running: highrate
[12:46:06.531] INFO: ----------------------------------------------------------------------
[12:46:06.531] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:46:06.532] INFO: ----------------------------------------------------------------------
[12:46:07.148] INFO: Expecting 208000 events.
[12:46:19.015] INFO: 208000 events read in total (11340ms).
[12:46:19.018] INFO: Test took 12478ms.
[12:46:19.163] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:19.416] INFO: number of dead pixels (per ROC): 0 1 0 1 0 0 0 0 0 0 1 0 0 2 2 0
[12:46:19.416] INFO: number of red-efficiency pixels: 66 45 92 137 125 155 169 94 104 106 133 115 108 79 30 37
[12:46:19.416] INFO: number of X-ray hits detected: 58146 40476 66598 103529 108509 117269 114309 79187 84194 113480 112369 89392 94650 58481 22089 23227
[12:46:19.417] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:46:19.417] INFO: number of Vcal hits detected: 207930 207900 207907 207805 207875 207841 207829 207905 207896 207894 207814 207884 207888 207821 207868 207963
[12:46:19.417] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[12:46:19.417] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 100.0
[12:46:19.417] INFO: X-ray hit rate [MHz/cm2]: 17.0 11.9 19.5 30.3 31.8 34.4 33.5 23.2 24.7 33.3 32.9 26.2 27.7 17.1 6.5 6.8
[12:46:19.417] INFO: PixTestHighRate::doXPixelAlive() done
[12:46:19.465] INFO: PixTest:: pg_setup set to default.
[12:46:19.480] INFO: enter test to run
[12:46:57.226] INFO: test: HighRate no parameter change
[12:46:57.226] INFO: running: highrate
[12:46:57.227] INFO: ----------------------------------------------------------------------
[12:46:57.227] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:46:57.227] INFO: ----------------------------------------------------------------------
[12:46:57.843] INFO: Expecting 208000 events.
[12:47:11.730] INFO: 208000 events read in total (13361ms).
[12:47:11.735] INFO: Test took 14499ms.
[12:47:12.051] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:47:12.356] INFO: number of dead pixels (per ROC): 0 1 0 1 0 0 0 0 0 0 1 0 0 2 2 0
[12:47:12.356] INFO: number of red-efficiency pixels: 164 119 291 436 385 509 552 239 272 407 422 316 346 208 59 47
[12:47:12.356] INFO: number of X-ray hits detected: 117887 82551 135209 209883 219572 236778 231123 161691 171105 229538 228424 181381 193573 118736 44415 47469
[12:47:12.356] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:47:12.356] INFO: number of Vcal hits detected: 207834 207825 207671 207481 207592 207444 207392 207735 207712 207570 207502 207654 207637 207681 207842 207953
[12:47:12.356] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.8 99.7 99.9 99.9 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[12:47:12.356] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.8 99.8 99.7 99.7 99.9 99.9 99.8 99.8 99.8 99.8 99.8 99.9 100.0
[12:47:12.356] INFO: X-ray hit rate [MHz/cm2]: 34.6 24.2 39.6 61.5 64.4 69.4 67.7 47.4 50.2 67.3 67.0 53.2 56.7 34.8 13.0 13.9
[12:47:12.356] INFO: PixTestHighRate::doXPixelAlive() done
[12:47:12.403] INFO: PixTest:: pg_setup set to default.
[12:47:12.422] INFO: enter test to run
[12:47:40.697] INFO: test: HighRate no parameter change
[12:47:40.698] INFO: running: highrate
[12:47:40.699] INFO: ----------------------------------------------------------------------
[12:47:40.699] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:47:40.699] INFO: ----------------------------------------------------------------------
[12:47:41.315] INFO: Expecting 208000 events.
[12:47:56.918] INFO: 208000 events read in total (15076ms).
[12:47:56.926] INFO: Test took 16217ms.
[12:47:57.383] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:47:57.744] INFO: number of dead pixels (per ROC): 0 1 0 1 0 0 0 0 0 0 1 0 0 2 2 0
[12:47:57.744] INFO: number of red-efficiency pixels: 330 264 641 943 832 1127 1279 525 540 906 883 654 805 439 98 84
[12:47:57.744] INFO: number of X-ray hits detected: 179324 123940 204465 315883 331738 357271 349648 244136 257936 345872 346048 275836 291173 180601 67076 71869
[12:47:57.744] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:47:57.744] INFO: number of Vcal hits detected: 207634 207658 207162 206810 207017 206592 206295 207372 207388 206928 206899 207235 207068 207395 207802 207915
[12:47:57.744] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.6 99.5 99.6 99.4 99.3 99.7 99.7 99.5 99.5 99.7 99.6 99.8 100.0 100.0
[12:47:57.744] INFO: Vcal hit overall efficiency (%): 99.8 99.8 99.6 99.4 99.5 99.3 99.2 99.7 99.7 99.5 99.5 99.6 99.6 99.7 99.9 100.0
[12:47:57.744] INFO: X-ray hit rate [MHz/cm2]: 52.6 36.3 59.9 92.6 97.2 104.7 102.5 71.6 75.6 101.4 101.4 80.8 85.3 52.9 19.7 21.1
[12:47:57.744] INFO: PixTestHighRate::doXPixelAlive() done
[12:47:57.790] INFO: PixTest:: pg_setup set to default.
[12:47:57.803] INFO: enter test to run
[12:48:23.761] INFO: test: exit no parameter change
[12:48:24.055] QUIET: Connection to board 33 closed.
[12:48:24.057] INFO: pXar: this is the end, my friend