[13:10:23.357] INFO: *** Welcome to pxar ***
[13:10:23.357] INFO: *** Today: 2016/06/10
[13:10:23.389] INFO: *** Version: v1.9.0-814-g7497
[13:10:23.389] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-O-2-13_FPIXTest-17C-FNAL-160608-1151_2016-06-08_11h51m_1465404672/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-O-2-13_FPIXTest-17C-FNAL-160608-1151_2016-06-08_11h51m_1465404672/000_FPIXTest_p17//dacParameters35_C15.dat
[13:10:23.460] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-O-2-13_FPIXTest-17C-FNAL-160608-1151_2016-06-08_11h51m_1465404672/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-O-2-13_FPIXTest-17C-FNAL-160608-1151_2016-06-08_11h51m_1465404672/000_FPIXTest_p17//tbmParameters_C0b.dat
[13:10:23.460] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-O-2-13_FPIXTest-17C-FNAL-160608-1151_2016-06-08_11h51m_1465404672/000_FPIXTest_p17//defaultMaskFile.dat
[13:10:23.468] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-O-2-13_FPIXTest-17C-FNAL-160608-1151_2016-06-08_11h51m_1465404672/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-O-2-13_FPIXTest-17C-FNAL-160608-1151_2016-06-08_11h51m_1465404672/000_FPIXTest_p17//trimParameters35_C15.dat
[13:10:23.588] INFO: clk: 4
[13:10:23.589] INFO: ctr: 4
[13:10:23.589] INFO: sda: 19
[13:10:23.589] INFO: tin: 9
[13:10:23.589] INFO: level: 15
[13:10:23.589] INFO: triggerdelay: 0
[13:10:23.589] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[13:10:23.589] INFO: Log level: INFO
[13:10:23.606] QUIET: Connection to board DTB_WREKRL opened.
[13:10:23.610] 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:
------------------------------------------------------
[13:10:23.613] INFO: RPC call hashes of host and DTB match: 398089610
[13:10:25.135] INFO: DUT info:
[13:10:25.135] INFO: The DUT currently contains the following objects:
[13:10:25.135] INFO: 2 TBM Cores tbm08c (2 ON)
[13:10:25.135] INFO: TBM Core alpha (0): 7 registers set
[13:10:25.135] INFO: TBM Core beta (1): 7 registers set
[13:10:25.135] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[13:10:25.135] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[13:10:25.135] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[13:10:25.135] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[13:10:25.135] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[13:10:25.136] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[13:10:25.136] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[13:10:25.136] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[13:10:25.136] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[13:10:25.136] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[13:10:25.136] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[13:10:25.136] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[13:10:25.136] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[13:10:25.136] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[13:10:25.136] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[13:10:25.136] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[13:10:25.136] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[13:10:25.540] INFO: enter 'restricted' command line mode
[13:10:25.540] INFO: enter test to run
[13:10:33.709] INFO: test: PixelAlive no parameter change
[13:10:33.710] INFO: running: pixelalive
[13:10:33.719] INFO: ----------------------------------------------------------------------
[13:10:33.719] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[13:10:33.719] INFO: ----------------------------------------------------------------------
[13:10:34.044] INFO: Expecting 41600 events.
[13:10:38.370] INFO: 41600 events read in total (3608ms).
[13:10:38.531] INFO: Test took 4808ms.
[13:10:38.543] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:10:38.817] INFO: PixTestAlive::aliveTest() done
[13:10:38.817] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[13:10:38.849] INFO: enter test to run
[13:11:09.421] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[13:11:09.422] INFO: running: highrate
[13:11:09.422] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-O-2-13_FPIXTest-17C-FNAL-160608-1151_2016-06-08_11h51m_1465404672/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-O-2-13_FPIXTest-17C-FNAL-160608-1151_2016-06-08_11h51m_1465404672/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[13:11:09.730] INFO: ----------------------------------------------------------------------
[13:11:09.730] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[13:11:09.730] INFO: ----------------------------------------------------------------------
[13:11:09.730] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[13:11:09.730] INFO: edge/corner pixel THR is adjusted
[13:11:09.730] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:11:10.689] INFO: Collecting data for 5 seconds...
[13:11:15.707] INFO: Done with hot pixel readout
[13:11:27.636] INFO: PixTest:: pg_setup set to default.
[13:11:27.637] INFO: 7 hot pixels found in step 0
[13:11:28.657] INFO: Collecting data for 5 seconds...
[13:11:33.674] INFO: Done with hot pixel readout
[13:11:45.704] INFO: PixTest:: pg_setup set to default.
[13:11:45.704] INFO: 3 hot pixels found in step 1
[13:11:46.697] INFO: Collecting data for 5 seconds...
[13:11:51.715] INFO: Done with hot pixel readout
[13:12:03.585] INFO: PixTest:: pg_setup set to default.
[13:12:03.586] INFO: 1 hot pixels found in step 2
[13:12:04.578] INFO: Collecting data for 5 seconds...
[13:12:09.594] INFO: Done with hot pixel readout
[13:12:21.678] INFO: PixTest:: pg_setup set to default.
[13:12:21.679] INFO: 1 hot pixels found in step 3
[13:12:22.670] INFO: Collecting data for 5 seconds...
[13:12:27.687] INFO: Done with hot pixel readout
[13:12:39.772] INFO: PixTest:: pg_setup set to default.
[13:12:39.773] INFO: 2 hot pixels found in step 4
[13:12:40.766] INFO: Collecting data for 5 seconds...
[13:12:45.782] INFO: Done with hot pixel readout
[13:12:57.813] INFO: PixTest:: pg_setup set to default.
[13:12:57.814] INFO: 1 hot pixels found in step 5
[13:12:58.807] INFO: Collecting data for 5 seconds...
[13:13:03.824] INFO: Done with hot pixel readout
[13:13:15.905] INFO: PixTest:: pg_setup set to default.
[13:13:15.906] INFO: 1 hot pixels found in step 6
[13:13:16.898] INFO: Collecting data for 5 seconds...
[13:13:21.915] INFO: Done with hot pixel readout
[13:13:33.989] INFO: PixTest:: pg_setup set to default.

[13:13:33.990] INFO: 4 hot pixels found in step 7
[13:13:34.982] INFO: Collecting data for 5 seconds...
[13:13:39.999] INFO: Done with hot pixel readout
[13:13:52.047] INFO: PixTest:: pg_setup set to default.
[13:13:52.048] INFO: 4 hot pixels found in step 8
[13:13:53.041] INFO: Collecting data for 5 seconds...
[13:13:58.058] INFO: Done with hot pixel readout
[13:14:10.097] INFO: PixTest:: pg_setup set to default.
[13:14:10.098] INFO: 1 hot pixels found in step 9
[13:14:11.092] INFO: Collecting data for 5 seconds...
[13:14:16.109] INFO: Done with hot pixel readout
[13:14:28.022] INFO: PixTest:: pg_setup set to default.
[13:14:28.023] INFO: 2 hot pixels found in step 10
[13:14:29.018] INFO: Collecting data for 5 seconds...
[13:14:34.039] INFO: Done with hot pixel readout
[13:14:45.742] INFO: PixTest:: pg_setup set to default.
[13:14:45.743] INFO: 1 hot pixels found in step 11
[13:14:46.737] INFO: Collecting data for 5 seconds...
[13:14:51.754] INFO: Done with hot pixel readout
[13:15:03.615] INFO: PixTest:: pg_setup set to default.

[13:15:03.616] INFO: 4 hot pixels found in step 12
[13:15:04.609] INFO: Collecting data for 5 seconds...
[13:15:09.628] INFO: Done with hot pixel readout
[13:15:21.865] INFO: PixTest:: pg_setup set to default.
[13:15:21.866] INFO: 3 hot pixels found in step 13
[13:15:22.859] INFO: Collecting data for 5 seconds...
[13:15:27.879] INFO: Done with hot pixel readout
[13:15:39.863] INFO: PixTest:: pg_setup set to default.
[13:15:39.864] INFO: 4 hot pixels found in step 14
[13:15:39.901] INFO: 4 hot pixels could not be trimmed and have been masked.
[13:15:39.904] INFO: PixTest::trimHotPixels() done
[13:15:39.905] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-13_FPIXTest-17C-FNAL-160608-1151_2016-06-08_11h51m_1465404672/000_FPIXTest_p17//trimParameters35_C0.dat
[13:15:39.910] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-13_FPIXTest-17C-FNAL-160608-1151_2016-06-08_11h51m_1465404672/000_FPIXTest_p17//trimParameters35_C1.dat
[13:15:39.916] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-13_FPIXTest-17C-FNAL-160608-1151_2016-06-08_11h51m_1465404672/000_FPIXTest_p17//trimParameters35_C2.dat
[13:15:39.921] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-13_FPIXTest-17C-FNAL-160608-1151_2016-06-08_11h51m_1465404672/000_FPIXTest_p17//trimParameters35_C3.dat
[13:15:39.927] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-13_FPIXTest-17C-FNAL-160608-1151_2016-06-08_11h51m_1465404672/000_FPIXTest_p17//trimParameters35_C4.dat
[13:15:39.932] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-13_FPIXTest-17C-FNAL-160608-1151_2016-06-08_11h51m_1465404672/000_FPIXTest_p17//trimParameters35_C5.dat
[13:15:39.937] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-13_FPIXTest-17C-FNAL-160608-1151_2016-06-08_11h51m_1465404672/000_FPIXTest_p17//trimParameters35_C6.dat
[13:15:39.943] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-13_FPIXTest-17C-FNAL-160608-1151_2016-06-08_11h51m_1465404672/000_FPIXTest_p17//trimParameters35_C7.dat
[13:15:39.948] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-13_FPIXTest-17C-FNAL-160608-1151_2016-06-08_11h51m_1465404672/000_FPIXTest_p17//trimParameters35_C8.dat
[13:15:39.953] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-13_FPIXTest-17C-FNAL-160608-1151_2016-06-08_11h51m_1465404672/000_FPIXTest_p17//trimParameters35_C9.dat
[13:15:39.959] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-13_FPIXTest-17C-FNAL-160608-1151_2016-06-08_11h51m_1465404672/000_FPIXTest_p17//trimParameters35_C10.dat
[13:15:39.964] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-13_FPIXTest-17C-FNAL-160608-1151_2016-06-08_11h51m_1465404672/000_FPIXTest_p17//trimParameters35_C11.dat
[13:15:39.970] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-13_FPIXTest-17C-FNAL-160608-1151_2016-06-08_11h51m_1465404672/000_FPIXTest_p17//trimParameters35_C12.dat
[13:15:39.975] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-13_FPIXTest-17C-FNAL-160608-1151_2016-06-08_11h51m_1465404672/000_FPIXTest_p17//trimParameters35_C13.dat
[13:15:39.980] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-13_FPIXTest-17C-FNAL-160608-1151_2016-06-08_11h51m_1465404672/000_FPIXTest_p17//trimParameters35_C14.dat
[13:15:39.986] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-13_FPIXTest-17C-FNAL-160608-1151_2016-06-08_11h51m_1465404672/000_FPIXTest_p17//trimParameters35_C15.dat
[13:15:40.006] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-O-2-13_FPIXTest-17C-FNAL-160608-1151_2016-06-08_11h51m_1465404672/000_FPIXTest_p17//defaultMaskFile.dat
[13:15:40.018] INFO: enter test to run
[13:16:04.107] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[13:16:04.107] INFO: running: highrate
[13:16:04.112] INFO: ----------------------------------------------------------------------
[13:16:04.112] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[13:16:04.112] INFO: ----------------------------------------------------------------------
[13:16:04.112] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[13:16:04.112] INFO: edge/corner pixel THR is adjusted
[13:16:04.112] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:16:05.069] INFO: Collecting data for 1 seconds...
[13:16:06.073] INFO: Done with hot pixel readout
[13:16:10.412] INFO: PixTest:: pg_setup set to default.
[13:16:10.413] INFO: 0 hot pixels found in step 0
[13:16:10.418] INFO: 0 hot pixels could not be trimmed and have been masked.
[13:16:10.500] INFO: PixTest::trimHotPixels() done
[13:16:10.500] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-13_FPIXTest-17C-FNAL-160608-1151_2016-06-08_11h51m_1465404672/000_FPIXTest_p17//trimParameters35_C0.dat
[13:16:10.511] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-13_FPIXTest-17C-FNAL-160608-1151_2016-06-08_11h51m_1465404672/000_FPIXTest_p17//trimParameters35_C1.dat
[13:16:10.516] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-13_FPIXTest-17C-FNAL-160608-1151_2016-06-08_11h51m_1465404672/000_FPIXTest_p17//trimParameters35_C2.dat
[13:16:10.521] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-13_FPIXTest-17C-FNAL-160608-1151_2016-06-08_11h51m_1465404672/000_FPIXTest_p17//trimParameters35_C3.dat
[13:16:10.527] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-13_FPIXTest-17C-FNAL-160608-1151_2016-06-08_11h51m_1465404672/000_FPIXTest_p17//trimParameters35_C4.dat
[13:16:10.532] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-13_FPIXTest-17C-FNAL-160608-1151_2016-06-08_11h51m_1465404672/000_FPIXTest_p17//trimParameters35_C5.dat
[13:16:10.537] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-13_FPIXTest-17C-FNAL-160608-1151_2016-06-08_11h51m_1465404672/000_FPIXTest_p17//trimParameters35_C6.dat
[13:16:10.543] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-13_FPIXTest-17C-FNAL-160608-1151_2016-06-08_11h51m_1465404672/000_FPIXTest_p17//trimParameters35_C7.dat
[13:16:10.548] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-13_FPIXTest-17C-FNAL-160608-1151_2016-06-08_11h51m_1465404672/000_FPIXTest_p17//trimParameters35_C8.dat
[13:16:10.553] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-13_FPIXTest-17C-FNAL-160608-1151_2016-06-08_11h51m_1465404672/000_FPIXTest_p17//trimParameters35_C9.dat
[13:16:10.559] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-13_FPIXTest-17C-FNAL-160608-1151_2016-06-08_11h51m_1465404672/000_FPIXTest_p17//trimParameters35_C10.dat
[13:16:10.564] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-13_FPIXTest-17C-FNAL-160608-1151_2016-06-08_11h51m_1465404672/000_FPIXTest_p17//trimParameters35_C11.dat
[13:16:10.570] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-13_FPIXTest-17C-FNAL-160608-1151_2016-06-08_11h51m_1465404672/000_FPIXTest_p17//trimParameters35_C12.dat
[13:16:10.575] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-13_FPIXTest-17C-FNAL-160608-1151_2016-06-08_11h51m_1465404672/000_FPIXTest_p17//trimParameters35_C13.dat
[13:16:10.580] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-13_FPIXTest-17C-FNAL-160608-1151_2016-06-08_11h51m_1465404672/000_FPIXTest_p17//trimParameters35_C14.dat
[13:16:10.586] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-13_FPIXTest-17C-FNAL-160608-1151_2016-06-08_11h51m_1465404672/000_FPIXTest_p17//trimParameters35_C15.dat
[13:16:10.591] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-O-2-13_FPIXTest-17C-FNAL-160608-1151_2016-06-08_11h51m_1465404672/000_FPIXTest_p17//defaultMaskFile.dat
[13:16:10.601] INFO: enter test to run
[13:16:35.179] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[13:16:35.179] INFO: running: xray
[13:16:35.180] INFO: ----------------------------------------------------------------------
[13:16:35.180] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:16:35.180] INFO: ----------------------------------------------------------------------
[13:16:36.143] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:16:47.174] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[13:17:17.382] INFO: Resuming triggers.
[13:17:28.415] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[13:17:57.861] INFO: Resuming triggers.
[13:18:08.893] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[13:18:38.480] INFO: Resuming triggers.
[13:18:49.511] INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[13:19:19.024] INFO: Resuming triggers.
[13:19:30.054] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[13:19:59.495] INFO: Resuming triggers.
[13:20:10.522] INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[13:20:40.021] INFO: Resuming triggers.
[13:20:51.055] INFO: run duration 76 seconds, buffer almost full (81%), pausing triggers.
[13:21:20.390] INFO: Resuming triggers.
[13:21:31.423] INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[13:22:00.998] INFO: Resuming triggers.
[13:22:12.025] INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[13:22:41.516] INFO: Resuming triggers.
[13:22:42.596] INFO: data taking finished, elapsed time: 100 seconds.
[13:22:45.884] INFO: PixTest:: pg_setup set to default.
[13:22:45.887] INFO: PixTestXray::doPhRun() done
[13:22:46.026] INFO: enter test to run
[13:23:06.592] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[13:23:06.592] INFO: running: xray
[13:23:06.593] INFO: ----------------------------------------------------------------------
[13:23:06.593] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:23:06.593] INFO: ----------------------------------------------------------------------
[13:23:07.567] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:23:13.818] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[13:23:43.931] INFO: Resuming triggers.
[13:23:50.186] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[13:24:20.223] INFO: Resuming triggers.
[13:24:26.476] INFO: run duration 18 seconds, buffer almost full (81%), pausing triggers.
[13:24:56.538] INFO: Resuming triggers.
[13:25:02.794] INFO: run duration 24 seconds, buffer almost full (81%), pausing triggers.
[13:25:33.024] INFO: Resuming triggers.
[13:25:39.277] INFO: run duration 31 seconds, buffer almost full (81%), pausing triggers.
[13:26:09.908] INFO: Resuming triggers.
[13:26:16.164] INFO: run duration 37 seconds, buffer almost full (81%), pausing triggers.
[13:26:46.999] INFO: Resuming triggers.
[13:26:53.255] INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[13:27:24.142] INFO: Resuming triggers.
[13:27:30.396] INFO: run duration 49 seconds, buffer almost full (81%), pausing triggers.
[13:28:01.694] INFO: Resuming triggers.
[13:28:07.948] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[13:28:39.377] INFO: Resuming triggers.
[13:28:45.632] INFO: run duration 62 seconds, buffer almost full (81%), pausing triggers.
[13:29:15.693] INFO: Resuming triggers.
[13:29:21.948] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[13:29:52.034] INFO: Resuming triggers.
[13:29:58.289] INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[13:30:28.256] INFO: Resuming triggers.
[13:30:34.507] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[13:31:04.622] INFO: Resuming triggers.
[13:31:10.873] INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[13:31:40.841] INFO: Resuming triggers.
[13:31:47.094] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[13:32:17.127] INFO: Resuming triggers.
[13:32:23.379] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[13:32:53.419] INFO: Resuming triggers.
[13:32:53.715] INFO: data taking finished, elapsed time: 100 seconds.
[13:32:55.515] INFO: PixTest:: pg_setup set to default.
[13:32:55.519] INFO: PixTestXray::doPhRun() done
[13:32:55.674] INFO: enter test to run
[13:33:24.972] INFO: test: HighRate no parameter change
[13:33:24.972] INFO: running: highrate
[13:33:24.973] INFO: ----------------------------------------------------------------------
[13:33:24.973] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[13:33:24.973] INFO: ----------------------------------------------------------------------
[13:33:25.115] INFO: Expecting 768 events.
[13:33:26.249] INFO: 768 events read in total (418ms).
[13:33:26.250] INFO: Test took 1269ms.
[13:33:27.053] INFO: Expecting 41600 events.
[13:33:30.172] INFO: 41600 events read in total (2592ms).
[13:33:30.173] INFO: Test took 3917ms.
[13:33:30.210] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:33:30.929] INFO: Expecting 41600 events.
[13:33:34.163] INFO: 41600 events read in total (2707ms).
[13:33:34.164] INFO: Test took 3934ms.
[13:33:34.203] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:33:34.922] INFO: Expecting 41600 events.
[13:33:38.193] INFO: 41600 events read in total (2744ms).
[13:33:38.194] INFO: Test took 3972ms.
[13:33:38.232] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:33:38.947] INFO: Expecting 41600 events.
[13:33:42.215] INFO: 41600 events read in total (2741ms).
[13:33:42.216] INFO: Test took 3964ms.
[13:33:42.254] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:33:42.970] INFO: Expecting 41600 events.
[13:33:46.237] INFO: 41600 events read in total (2740ms).
[13:33:46.238] INFO: Test took 3963ms.
[13:33:46.277] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:33:46.994] INFO: Expecting 41600 events.
[13:33:50.277] INFO: 41600 events read in total (2756ms).
[13:33:50.279] INFO: Test took 3982ms.
[13:33:50.323] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:33:51.028] INFO: Expecting 41600 events.
[13:33:54.322] INFO: 41600 events read in total (2767ms).
[13:33:54.323] INFO: Test took 3979ms.
[13:33:54.362] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:33:55.074] INFO: Expecting 41600 events.
[13:33:58.356] INFO: 41600 events read in total (2755ms).
[13:33:58.357] INFO: Test took 3976ms.
[13:33:58.396] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:33:59.114] INFO: Expecting 41600 events.
[13:34:02.399] INFO: 41600 events read in total (2758ms).
[13:34:02.400] INFO: Test took 3984ms.
[13:34:02.438] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:34:03.154] INFO: Expecting 41600 events.
[13:34:06.440] INFO: 41600 events read in total (2759ms).
[13:34:06.442] INFO: Test took 3983ms.
[13:34:06.480] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:34:07.193] INFO: Expecting 41600 events.
[13:34:10.496] INFO: 41600 events read in total (2776ms).
[13:34:10.497] INFO: Test took 3998ms.
[13:34:10.535] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:34:11.249] INFO: Expecting 41600 events.
[13:34:14.528] INFO: 41600 events read in total (2752ms).
[13:34:14.529] INFO: Test took 3973ms.
[13:34:14.568] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:34:15.282] INFO: Expecting 41600 events.
[13:34:18.564] INFO: 41600 events read in total (2755ms).
[13:34:18.565] INFO: Test took 3977ms.
[13:34:18.603] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:34:19.320] INFO: Expecting 41600 events.
[13:34:22.604] INFO: 41600 events read in total (2757ms).
[13:34:22.605] INFO: Test took 3984ms.
[13:34:22.643] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:34:23.357] INFO: Expecting 41600 events.
[13:34:26.637] INFO: 41600 events read in total (2754ms).
[13:34:26.638] INFO: Test took 3975ms.
[13:34:26.676] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:34:27.391] INFO: Expecting 41600 events.
[13:34:30.669] INFO: 41600 events read in total (2751ms).
[13:34:30.670] INFO: Test took 3973ms.
[13:34:30.708] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:34:31.424] INFO: Expecting 41600 events.
[13:34:34.724] INFO: 41600 events read in total (2774ms).
[13:34:34.725] INFO: Test took 3996ms.
[13:34:34.763] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:34:35.476] INFO: Expecting 41600 events.
[13:34:38.769] INFO: 41600 events read in total (2766ms).
[13:34:38.770] INFO: Test took 3986ms.
[13:34:38.809] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:34:39.523] INFO: Expecting 41600 events.
[13:34:42.789] INFO: 41600 events read in total (2740ms).
[13:34:42.790] INFO: Test took 3961ms.
[13:34:42.828] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:34:43.542] INFO: Expecting 41600 events.
[13:34:46.687] INFO: 41600 events read in total (2618ms).
[13:34:46.688] INFO: Test took 3841ms.
[13:34:46.725] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:34:47.083] INFO: enter test to run
[13:34:55.651] INFO: test: HighRate no parameter change
[13:34:55.651] INFO: running: highrate
[13:34:55.652] INFO: ----------------------------------------------------------------------
[13:34:55.652] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:34:55.652] INFO: ----------------------------------------------------------------------
[13:34:56.261] INFO: Expecting 208000 events.
[13:35:08.411] INFO: 208000 events read in total (11623ms).
[13:35:08.414] INFO: Test took 12754ms.
[13:35:08.582] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:35:08.843] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[13:35:08.843] INFO: number of red-efficiency pixels: 88 35 85 113 164 203 129 130 108 150 138 119 116 75 33 24
[13:35:08.843] INFO: number of X-ray hits detected: 68050 47143 76342 112296 121647 131837 128250 94052 90775 123421 121043 106372 105928 64259 25715 30137
[13:35:08.843] 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:35:08.843] INFO: number of Vcal hits detected: 207911 207964 207914 207886 207816 207791 207869 207867 207890 207846 207859 207878 207881 207925 207967 207976
[13:35:08.843] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[13:35:08.843] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[13:35:08.843] INFO: X-ray hit rate [MHz/cm2]: 19.9 13.8 22.4 32.9 35.7 38.6 37.6 27.6 26.6 36.2 35.5 31.2 31.0 18.8 7.5 8.8
[13:35:08.843] INFO: PixTestHighRate::doXPixelAlive() done
[13:35:08.893] INFO: PixTest:: pg_setup set to default.
[13:35:08.905] INFO: enter test to run
[13:37:05.834] INFO: test: HighRate no parameter change
[13:37:05.834] INFO: running: highrate
[13:37:05.835] INFO: ----------------------------------------------------------------------
[13:37:05.835] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:37:05.835] INFO: ----------------------------------------------------------------------
[13:37:06.455] INFO: Expecting 208000 events.
[13:37:19.963] INFO: 208000 events read in total (12981ms).
[13:37:19.969] INFO: Test took 14125ms.
[13:37:20.313] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:37:20.630] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[13:37:20.631] INFO: number of red-efficiency pixels: 225 121 289 327 448 713 517 407 298 446 438 364 346 267 85 88
[13:37:20.631] INFO: number of X-ray hits detected: 137709 94039 153891 226408 246285 266472 258692 189994 183952 246997 242953 214795 213118 129440 51521 61868
[13:37:20.631] 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:37:20.631] INFO: number of Vcal hits detected: 207755 207871 207692 207652 207464 207209 207436 207556 207691 207520 207527 207615 207627 207712 207913 207910
[13:37:20.631] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.6 99.8 99.8 99.9 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[13:37:20.631] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.7 99.6 99.7 99.8 99.9 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[13:37:20.631] INFO: X-ray hit rate [MHz/cm2]: 40.4 27.6 45.1 66.4 72.2 78.1 75.8 55.7 53.9 72.4 71.2 63.0 62.5 37.9 15.1 18.1
[13:37:20.631] INFO: PixTestHighRate::doXPixelAlive() done
[13:37:20.676] INFO: PixTest:: pg_setup set to default.
[13:37:20.691] INFO: enter test to run
[13:37:37.034] INFO: test: HighRate no parameter change
[13:37:37.034] INFO: running: highrate
[13:37:37.034] INFO: ----------------------------------------------------------------------
[13:37:37.034] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:37:37.035] INFO: ----------------------------------------------------------------------
[13:37:37.648] INFO: Expecting 208000 events.
[13:37:53.153] INFO: 208000 events read in total (14979ms).
[13:37:53.161] INFO: Test took 16119ms.
[13:37:53.680] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:37:54.053] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[13:37:54.053] INFO: number of red-efficiency pixels: 523 272 599 871 1044 1649 1191 950 762 1073 1035 929 853 618 100 130
[13:37:54.053] INFO: number of X-ray hits detected: 208223 142858 233915 343848 372604 404185 394400 289104 279764 377087 369645 326759 323131 197762 78507 94398
[13:37:54.053] 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:37:54.053] INFO: number of Vcal hits detected: 207390 207710 207249 206961 206601 205590 206460 206744 207059 206699 206696 206866 206980 207183 207896 207869
[13:37:54.053] INFO: Vcal hit fiducial efficiency (%): 99.7 99.9 99.7 99.5 99.4 98.9 99.3 99.4 99.6 99.4 99.4 99.5 99.6 99.7 100.0 99.9
[13:37:54.053] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.6 99.5 99.3 98.8 99.3 99.4 99.5 99.4 99.4 99.5 99.5 99.6 100.0 99.9
[13:37:54.053] INFO: X-ray hit rate [MHz/cm2]: 61.0 41.9 68.6 100.8 109.2 118.5 115.6 84.7 82.0 110.5 108.3 95.8 94.7 58.0 23.0 27.7
[13:37:54.053] INFO: PixTestHighRate::doXPixelAlive() done
[13:37:54.099] INFO: PixTest:: pg_setup set to default.
[13:37:54.120] INFO: enter test to run
[13:37:56.785] INFO: test: exit no parameter change
[13:37:57.086] QUIET: Connection to board 33 closed.
[13:37:57.086] INFO: pXar: this is the end, my friend