[15:36:33.942] INFO: *** Welcome to pxar ***
[15:36:33.942] INFO: *** Today: 2016/06/24
[15:36:33.958] INFO: *** Version: v1.9.0-814-g7497
[15:36:33.959] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//dacParameters35_C15.dat
[15:36:34.387] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//tbmParameters_C0b.dat
[15:36:34.387] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//defaultMaskFile.dat
[15:36:34.387] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C15.dat
[15:36:34.462] INFO: clk: 4
[15:36:34.462] INFO: ctr: 4
[15:36:34.462] INFO: sda: 19
[15:36:34.462] INFO: tin: 9
[15:36:34.462] INFO: level: 15
[15:36:34.462] INFO: triggerdelay: 0
[15:36:34.462] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[15:36:34.462] INFO: Log level: INFO
[15:36:34.476] QUIET: Connection to board DTB_WREKRL opened.
[15:36:34.479] 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:
------------------------------------------------------
[15:36:34.482] INFO: RPC call hashes of host and DTB match: 398089610
[15:36:36.016] INFO: DUT info:
[15:36:36.016] INFO: The DUT currently contains the following objects:
[15:36:36.016] INFO: 2 TBM Cores tbm08c (2 ON)
[15:36:36.016] INFO: TBM Core alpha (0): 7 registers set
[15:36:36.016] INFO: TBM Core beta (1): 7 registers set
[15:36:36.016] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[15:36:36.016] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[15:36:36.016] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[15:36:36.016] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[15:36:36.016] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[15:36:36.016] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[15:36:36.016] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[15:36:36.016] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[15:36:36.016] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[15:36:36.016] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[15:36:36.016] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[15:36:36.016] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[15:36:36.016] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[15:36:36.017] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[15:36:36.017] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[15:36:36.017] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[15:36:36.017] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[15:36:36.420] INFO: enter 'restricted' command line mode
[15:36:36.420] INFO: enter test to run
[15:36:42.313] INFO: test: PixelAlive no parameter change
[15:36:42.313] INFO: running: pixelalive
[15:36:42.322] INFO: ----------------------------------------------------------------------
[15:36:42.322] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[15:36:42.323] INFO: ----------------------------------------------------------------------
[15:36:42.644] INFO: Expecting 41600 events.
[15:36:46.991] INFO: 41600 events read in total (3629ms).
[15:36:47.156] INFO: Test took 4831ms.
[15:36:47.165] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:36:47.437] INFO: PixTestAlive::aliveTest() done
[15:36:47.437] INFO: number of dead pixels (per ROC): 1 0 0 0 0 0 0 1 0 0 0 0 0 0 0 0
[15:36:47.469] INFO: enter test to run
[15:37:16.777] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[15:37:16.777] INFO: running: highrate
[15:37:16.777] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[15:37:16.939] INFO: ----------------------------------------------------------------------
[15:37:16.939] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[15:37:16.939] INFO: ----------------------------------------------------------------------
[15:37:16.939] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[15:37:16.939] INFO: edge/corner pixel THR is adjusted
[15:37:16.939] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:37:17.898] INFO: Collecting data for 5 seconds...
[15:37:22.914] INFO: Done with hot pixel readout
[15:37:34.304] INFO: PixTest:: pg_setup set to default.
[15:37:34.305] INFO: 7 hot pixels found in step 0
[15:37:35.312] INFO: Collecting data for 5 seconds...
[15:37:40.328] INFO: Done with hot pixel readout
[15:37:51.648] INFO: PixTest:: pg_setup set to default.
[15:37:51.649] INFO: 7 hot pixels found in step 1
[15:37:52.641] INFO: Collecting data for 5 seconds...
[15:37:57.657] INFO: Done with hot pixel readout
[15:38:08.999] INFO: PixTest:: pg_setup set to default.
[15:38:08.000] INFO: 5 hot pixels found in step 2
[15:38:09.988] INFO: Collecting data for 5 seconds...
[15:38:15.004] INFO: Done with hot pixel readout
[15:38:26.386] INFO: PixTest:: pg_setup set to default.
[15:38:26.386] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:38:26.387] INFO: 6 hot pixels found in step 3
[15:38:27.375] INFO: Collecting data for 5 seconds...
[15:38:32.391] INFO: Done with hot pixel readout
[15:38:43.726] INFO: PixTest:: pg_setup set to default.
[15:38:43.727] INFO: 2 hot pixels found in step 4
[15:38:44.715] INFO: Collecting data for 5 seconds...
[15:38:49.731] INFO: Done with hot pixel readout
[15:39:01.142] INFO: PixTest:: pg_setup set to default.
[15:39:01.142] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:39:01.143] INFO: 4 hot pixels found in step 5
[15:39:02.133] INFO: Collecting data for 5 seconds...
[15:39:07.150] INFO: Done with hot pixel readout
[15:39:18.291] INFO: PixTest:: pg_setup set to default.
[15:39:18.291] INFO: 2 hot pixels found in step 6
[15:39:19.281] INFO: Collecting data for 5 seconds...
[15:39:24.298] INFO: Done with hot pixel readout
[15:39:35.805] INFO: PixTest:: pg_setup set to default.
[15:39:35.805] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:39:35.806] INFO: 2 hot pixels found in step 7
[15:39:36.795] INFO: Collecting data for 5 seconds...
[15:39:41.812] INFO: Done with hot pixel readout
[15:39:52.769] INFO: PixTest:: pg_setup set to default.
[15:39:52.769] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:39:52.770] INFO: 3 hot pixels found in step 8
[15:39:53.758] INFO: Collecting data for 5 seconds...
[15:39:58.777] INFO: Done with hot pixel readout
[15:40:09.972] INFO: PixTest:: pg_setup set to default.
[15:40:09.972] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:40:09.973] INFO: 3 hot pixels found in step 9
[15:40:10.961] INFO: Collecting data for 5 seconds...
[15:40:15.980] INFO: Done with hot pixel readout
[15:40:26.969] INFO: PixTest:: pg_setup set to default.
[15:40:26.969] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:40:26.970] INFO: 3 hot pixels found in step 10
[15:40:27.959] INFO: Collecting data for 5 seconds...
[15:40:32.977] INFO: Done with hot pixel readout
[15:40:44.081] INFO: PixTest:: pg_setup set to default.
[15:40:44.081] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:40:44.082] INFO: 1 hot pixels found in step 11
[15:40:44.115] INFO: 1 hot pixels could not be trimmed and have been masked.
[15:40:44.118] INFO: PixTest::trimHotPixels() done
[15:40:44.119] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C0.dat
[15:40:44.124] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C1.dat
[15:40:44.130] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C2.dat
[15:40:44.136] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C3.dat
[15:40:44.141] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C4.dat
[15:40:44.147] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C5.dat
[15:40:44.152] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C6.dat
[15:40:44.158] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C7.dat
[15:40:44.163] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C8.dat
[15:40:44.168] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C9.dat
[15:40:44.173] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C10.dat
[15:40:44.179] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C11.dat
[15:40:44.184] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C12.dat
[15:40:44.189] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C13.dat
[15:40:44.195] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C14.dat
[15:40:44.200] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C15.dat
[15:40:44.205] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//defaultMaskFile.dat
[15:40:44.217] INFO: enter test to run
[15:41:30.943] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[15:41:30.944] INFO: running: highrate
[15:41:30.948] INFO: ----------------------------------------------------------------------
[15:41:30.948] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[15:41:30.948] INFO: ----------------------------------------------------------------------
[15:41:30.948] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[15:41:30.948] INFO: edge/corner pixel THR is adjusted
[15:41:30.948] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:41:31.906] INFO: Collecting data for 1 seconds...
[15:41:32.909] INFO: Done with hot pixel readout
[15:41:36.843] INFO: PixTest:: pg_setup set to default.
[15:41:36.844] INFO: 0 hot pixels found in step 0
[15:41:36.849] INFO: 0 hot pixels could not be trimmed and have been masked.
[15:41:36.931] INFO: PixTest::trimHotPixels() done
[15:41:36.931] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C0.dat
[15:41:36.944] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C1.dat
[15:41:36.953] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C2.dat
[15:41:36.961] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C3.dat
[15:41:36.967] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C4.dat
[15:41:36.974] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C5.dat
[15:41:36.981] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C6.dat
[15:41:36.986] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C7.dat
[15:41:36.992] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C8.dat
[15:41:36.997] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C9.dat
[15:41:37.002] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C10.dat
[15:41:37.008] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C11.dat
[15:41:37.013] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C12.dat
[15:41:37.018] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C13.dat
[15:41:37.024] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C14.dat
[15:41:37.029] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C15.dat
[15:41:37.035] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-1-15_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//defaultMaskFile.dat
[15:41:37.044] INFO: enter test to run
[15:42:04.119] INFO: test: HighRate no parameter change
[15:42:04.119] INFO: running: highrate
[15:42:04.120] INFO: ----------------------------------------------------------------------
[15:42:04.120] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[15:42:04.121] INFO: ----------------------------------------------------------------------
[15:42:04.261] INFO: Expecting 768 events.
[15:42:05.396] INFO: 768 events read in total (419ms).
[15:42:05.396] INFO: Test took 1268ms.
[15:42:06.199] INFO: Expecting 41600 events.
[15:42:09.302] INFO: 41600 events read in total (2576ms).
[15:42:09.303] INFO: Test took 3901ms.
[15:42:09.333] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:10.060] INFO: Expecting 41600 events.
[15:42:13.232] INFO: 41600 events read in total (2646ms).
[15:42:13.233] INFO: Test took 3884ms.
[15:42:13.265] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:13.991] INFO: Expecting 41600 events.
[15:42:17.298] INFO: 41600 events read in total (2780ms).
[15:42:17.299] INFO: Test took 4017ms.
[15:42:17.331] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:18.052] INFO: Expecting 41600 events.
[15:42:21.296] INFO: 41600 events read in total (2717ms).
[15:42:21.297] INFO: Test took 3950ms.
[15:42:21.329] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:22.053] INFO: Expecting 41600 events.
[15:42:25.323] INFO: 41600 events read in total (2743ms).
[15:42:25.323] INFO: Test took 3978ms.
[15:42:25.355] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:26.083] INFO: Expecting 41600 events.
[15:42:29.363] INFO: 41600 events read in total (2753ms).
[15:42:29.364] INFO: Test took 3992ms.
[15:42:29.396] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:30.125] INFO: Expecting 41600 events.
[15:42:33.391] INFO: 41600 events read in total (2740ms).
[15:42:33.392] INFO: Test took 3979ms.
[15:42:33.424] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:34.146] INFO: Expecting 41600 events.
[15:42:37.431] INFO: 41600 events read in total (2758ms).
[15:42:37.432] INFO: Test took 3992ms.
[15:42:37.464] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:38.175] INFO: Expecting 41600 events.
[15:42:41.454] INFO: 41600 events read in total (2752ms).
[15:42:41.455] INFO: Test took 3975ms.
[15:42:41.487] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:42.207] INFO: Expecting 41600 events.
[15:42:45.427] INFO: 41600 events read in total (2693ms).
[15:42:45.428] INFO: Test took 3925ms.
[15:42:45.460] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:46.187] INFO: Expecting 41600 events.
[15:42:49.390] INFO: 41600 events read in total (2676ms).
[15:42:49.391] INFO: Test took 3915ms.
[15:42:49.422] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:50.152] INFO: Expecting 41600 events.
[15:42:53.352] INFO: 41600 events read in total (2673ms).
[15:42:53.353] INFO: Test took 3914ms.
[15:42:53.384] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:54.115] INFO: Expecting 41600 events.
[15:42:57.346] INFO: 41600 events read in total (2704ms).
[15:42:57.347] INFO: Test took 3945ms.
[15:42:57.378] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:58.108] INFO: Expecting 41600 events.
[15:43:01.328] INFO: 41600 events read in total (2693ms).
[15:43:01.329] INFO: Test took 3936ms.
[15:43:01.359] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:43:02.086] INFO: Expecting 41600 events.
[15:43:05.291] INFO: 41600 events read in total (2678ms).
[15:43:05.292] INFO: Test took 3916ms.
[15:43:05.322] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:43:06.054] INFO: Expecting 41600 events.
[15:43:09.251] INFO: 41600 events read in total (2670ms).
[15:43:09.252] INFO: Test took 3912ms.
[15:43:09.283] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:43:10.014] INFO: Expecting 41600 events.
[15:43:13.220] INFO: 41600 events read in total (2679ms).
[15:43:13.221] INFO: Test took 3920ms.
[15:43:13.252] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:43:13.982] INFO: Expecting 41600 events.
[15:43:17.191] INFO: 41600 events read in total (2682ms).
[15:43:17.192] INFO: Test took 3923ms.
[15:43:17.223] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:43:17.951] INFO: Expecting 41600 events.
[15:43:21.130] INFO: 41600 events read in total (2652ms).
[15:43:21.131] INFO: Test took 3890ms.
[15:43:21.162] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:43:21.894] INFO: Expecting 41600 events.
[15:43:24.940] INFO: 41600 events read in total (2519ms).
[15:43:24.941] INFO: Test took 3762ms.
[15:43:24.970] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:43:25.342] INFO: enter test to run
[15:43:29.719] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[15:43:29.719] INFO: running: xray
[15:43:29.720] INFO: ----------------------------------------------------------------------
[15:43:29.720] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:43:29.720] INFO: ----------------------------------------------------------------------
[15:43:30.683] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:43:42.604] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[15:44:11.971] INFO: Resuming triggers.
[15:44:23.896] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[15:44:52.931] INFO: Resuming triggers.
[15:45:04.855] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[15:45:34.100] INFO: Resuming triggers.
[15:45:46.026] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[15:46:15.301] INFO: Resuming triggers.
[15:46:27.228] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[15:46:56.519] INFO: Resuming triggers.
[15:47:08.448] INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[15:47:37.738] INFO: Resuming triggers.
[15:47:49.660] INFO: run duration 83 seconds, buffer almost full (81%), pausing triggers.
[15:48:18.885] INFO: Resuming triggers.
[15:48:30.813] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[15:48:59.997] INFO: Resuming triggers.
[15:49:04.907] INFO: data taking finished, elapsed time: 100 seconds.
[15:49:17.222] INFO: PixTest:: pg_setup set to default.
[15:49:17.226] INFO: PixTestXray::doPhRun() done
[15:49:17.361] INFO: enter test to run
[15:50:00.020] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[15:50:00.020] INFO: running: xray
[15:50:00.021] INFO: ----------------------------------------------------------------------
[15:50:00.021] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:50:00.021] INFO: ----------------------------------------------------------------------
[15:50:00.985] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:50:08.221] INFO: run duration 7 seconds, buffer almost full (81%), pausing triggers.
[15:50:38.511] INFO: Resuming triggers.
[15:50:45.750] INFO: run duration 14 seconds, buffer almost full (81%), pausing triggers.
[15:51:16.920] INFO: Resuming triggers.
[15:51:24.155] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[15:51:54.953] INFO: Resuming triggers.
[15:52:02.194] INFO: run duration 28 seconds, buffer almost full (81%), pausing triggers.
[15:52:33.228] INFO: Resuming triggers.
[15:52:40.461] INFO: run duration 36 seconds, buffer almost full (81%), pausing triggers.
[15:53:11.986] INFO: Resuming triggers.
[15:53:19.220] INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[15:53:50.538] INFO: Resuming triggers.
[15:53:57.774] INFO: run duration 50 seconds, buffer almost full (81%), pausing triggers.
[15:54:28.462] INFO: Resuming triggers.
[15:54:35.696] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[15:55:05.001] INFO: Resuming triggers.
[15:55:13.235] INFO: run duration 64 seconds, buffer almost full (81%), pausing triggers.
[15:55:43.415] INFO: Resuming triggers.
[15:55:50.653] INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[15:56:20.992] INFO: Resuming triggers.
[15:56:28.228] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[15:56:58.551] INFO: Resuming triggers.
[15:57:05.790] INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[15:57:35.950] INFO: Resuming triggers.
[15:57:43.181] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[15:58:13.193] INFO: Resuming triggers.
[15:58:19.461] INFO: data taking finished, elapsed time: 100 seconds.
[15:58:45.916] INFO: PixTest:: pg_setup set to default.
[15:58:45.919] INFO: PixTestXray::doPhRun() done
[15:58:46.069] INFO: enter test to run
[15:59:08.440] INFO: test: HighRate no parameter change
[15:59:08.440] INFO: running: highrate
[15:59:08.442] INFO: ----------------------------------------------------------------------
[15:59:08.442] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[15:59:08.442] INFO: ----------------------------------------------------------------------
[15:59:08.583] INFO: Expecting 768 events.
[15:59:09.716] INFO: 768 events read in total (418ms).
[15:59:09.716] INFO: Test took 1267ms.
[15:59:10.520] INFO: Expecting 41600 events.
[15:59:13.581] INFO: 41600 events read in total (2534ms).
[15:59:13.582] INFO: Test took 3858ms.
[15:59:13.612] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:59:14.347] INFO: Expecting 41600 events.
[15:59:17.514] INFO: 41600 events read in total (2641ms).
[15:59:17.515] INFO: Test took 3885ms.
[15:59:17.547] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:59:18.273] INFO: Expecting 41600 events.
[15:59:21.469] INFO: 41600 events read in total (2669ms).
[15:59:21.470] INFO: Test took 3905ms.
[15:59:21.502] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:59:22.232] INFO: Expecting 41600 events.
[15:59:25.447] INFO: 41600 events read in total (2688ms).
[15:59:25.448] INFO: Test took 3929ms.
[15:59:25.479] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:59:26.205] INFO: Expecting 41600 events.
[15:59:29.410] INFO: 41600 events read in total (2678ms).
[15:59:29.411] INFO: Test took 3914ms.
[15:59:29.443] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:59:30.172] INFO: Expecting 41600 events.
[15:59:33.380] INFO: 41600 events read in total (2681ms).
[15:59:33.381] INFO: Test took 3921ms.
[15:59:33.412] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:59:34.139] INFO: Expecting 41600 events.
[15:59:37.376] INFO: 41600 events read in total (2710ms).
[15:59:37.377] INFO: Test took 3948ms.
[15:59:37.408] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:59:38.134] INFO: Expecting 41600 events.
[15:59:41.340] INFO: 41600 events read in total (2679ms).
[15:59:41.341] INFO: Test took 3916ms.
[15:59:41.372] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:59:42.102] INFO: Expecting 41600 events.
[15:59:45.331] INFO: 41600 events read in total (2702ms).
[15:59:45.332] INFO: Test took 3942ms.
[15:59:45.363] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:59:46.090] INFO: Expecting 41600 events.
[15:59:49.283] INFO: 41600 events read in total (2666ms).
[15:59:49.283] INFO: Test took 3902ms.
[15:59:49.314] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:59:50.046] INFO: Expecting 41600 events.
[15:59:53.218] INFO: 41600 events read in total (2645ms).
[15:59:53.219] INFO: Test took 3886ms.
[15:59:53.250] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:59:53.980] INFO: Expecting 41600 events.
[15:59:57.211] INFO: 41600 events read in total (2704ms).
[15:59:57.212] INFO: Test took 3945ms.
[15:59:57.244] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:59:57.971] INFO: Expecting 41600 events.
[16:00:01.162] INFO: 41600 events read in total (2664ms).
[16:00:01.163] INFO: Test took 3902ms.
[16:00:01.195] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:00:01.924] INFO: Expecting 41600 events.
[16:00:05.100] INFO: 41600 events read in total (2649ms).
[16:00:05.101] INFO: Test took 3888ms.
[16:00:05.133] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:00:05.863] INFO: Expecting 41600 events.
[16:00:09.081] INFO: 41600 events read in total (2691ms).
[16:00:09.082] INFO: Test took 3930ms.
[16:00:09.113] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:00:09.841] INFO: Expecting 41600 events.
[16:00:12.993] INFO: 41600 events read in total (2625ms).
[16:00:12.994] INFO: Test took 3862ms.
[16:00:13.026] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:00:13.753] INFO: Expecting 41600 events.
[16:00:16.965] INFO: 41600 events read in total (2685ms).
[16:00:16.966] INFO: Test took 3923ms.
[16:00:16.998] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:00:17.726] INFO: Expecting 41600 events.
[16:00:20.913] INFO: 41600 events read in total (2660ms).
[16:00:20.914] INFO: Test took 3898ms.
[16:00:20.945] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:00:21.677] INFO: Expecting 41600 events.
[16:00:24.885] INFO: 41600 events read in total (2682ms).
[16:00:24.886] INFO: Test took 3923ms.
[16:00:24.917] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:00:25.647] INFO: Expecting 41600 events.
[16:00:28.687] INFO: 41600 events read in total (2513ms).
[16:00:28.688] INFO: Test took 3753ms.
[16:00:28.718] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:00:29.095] INFO: enter test to run
[16:01:36.447] INFO: test: HighRate no parameter change
[16:01:36.447] INFO: running: highrate
[16:01:36.448] INFO: ----------------------------------------------------------------------
[16:01:36.448] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:01:36.449] INFO: ----------------------------------------------------------------------
[16:01:37.063] INFO: Expecting 208000 events.
[16:01:48.794] INFO: 208000 events read in total (11204ms).
[16:01:48.797] INFO: Test took 12340ms.
[16:01:48.929] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:01:49.177] INFO: number of dead pixels (per ROC): 1 0 0 0 0 0 0 1 0 0 0 0 0 0 0 0
[16:01:49.177] INFO: number of red-efficiency pixels: 56 41 81 110 140 136 123 87 71 105 108 81 76 46 17 23
[16:01:49.177] INFO: number of X-ray hits detected: 57448 35434 57304 92078 100514 104073 103639 75683 69305 97736 95705 80629 77674 48159 17223 18908
[16:01:49.177] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[16:01:49.177] INFO: number of Vcal hits detected: 207894 207956 207919 207886 207858 207860 207872 207857 207928 207893 207884 207919 207922 207954 207983 207977
[16:01:49.177] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0 99.9 100.0 100.0 100.0 100.0 100.0
[16:01:49.177] INFO: Vcal hit overall efficiency (%): 99.9 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[16:01:49.177] INFO: X-ray hit rate [MHz/cm2]: 16.8 10.4 16.8 27.0 29.5 30.5 30.4 22.2 20.3 28.6 28.1 23.6 22.8 14.1 5.0 5.5
[16:01:49.177] INFO: PixTestHighRate::doXPixelAlive() done
[16:01:49.227] INFO: PixTest:: pg_setup set to default.
[16:01:49.239] INFO: enter test to run
[16:02:53.559] INFO: test: HighRate no parameter change
[16:02:53.559] INFO: running: highrate
[16:02:53.560] INFO: ----------------------------------------------------------------------
[16:02:53.560] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:02:53.560] INFO: ----------------------------------------------------------------------
[16:02:54.181] INFO: Expecting 208000 events.
[16:03:07.801] INFO: 208000 events read in total (13093ms).
[16:03:07.805] INFO: Test took 14236ms.
[16:03:08.075] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:03:08.372] INFO: number of dead pixels (per ROC): 1 0 0 0 0 0 0 1 0 0 0 0 0 0 0 0
[16:03:08.372] INFO: number of red-efficiency pixels: 177 97 181 303 387 458 429 261 192 318 275 285 194 129 37 39
[16:03:08.372] INFO: number of X-ray hits detected: 115542 71750 113929 185146 201570 208822 208731 152551 138546 194547 190887 161429 157812 95310 34806 38012
[16:03:08.372] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[16:03:08.372] INFO: number of Vcal hits detected: 207759 207901 207809 207687 207584 207509 207532 207669 207807 207667 207701 207703 207800 207867 207963 207961
[16:03:08.372] INFO: Vcal hit fiducial efficiency (%): 99.9 100.0 99.9 99.9 99.8 99.8 99.8 99.9 99.9 99.8 99.9 99.9 99.9 99.9 100.0 100.0
[16:03:08.372] INFO: Vcal hit overall efficiency (%): 99.9 100.0 99.9 99.8 99.8 99.8 99.8 99.8 99.9 99.8 99.9 99.9 99.9 99.9 100.0 100.0
[16:03:08.372] INFO: X-ray hit rate [MHz/cm2]: 33.9 21.0 33.4 54.3 59.1 61.2 61.2 44.7 40.6 57.0 56.0 47.3 46.3 27.9 10.2 11.1
[16:03:08.372] INFO: PixTestHighRate::doXPixelAlive() done
[16:03:08.419] INFO: PixTest:: pg_setup set to default.
[16:03:08.432] INFO: enter test to run
[16:03:41.655] INFO: test: HighRate no parameter change
[16:03:41.655] INFO: running: highrate
[16:03:41.656] INFO: ----------------------------------------------------------------------
[16:03:41.656] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:03:41.656] INFO: ----------------------------------------------------------------------
[16:03:42.275] INFO: Expecting 208000 events.
[16:03:57.223] INFO: 208000 events read in total (14421ms).
[16:03:57.230] INFO: Test took 15565ms.
[16:03:57.639] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:03:57.982] INFO: number of dead pixels (per ROC): 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[16:03:57.982] INFO: number of red-efficiency pixels: 378 222 385 840 988 1058 1076 669 388 755 647 636 449 281 54 75
[16:03:57.982] INFO: number of X-ray hits detected: 178843 112673 176700 287201 313226 325053 322889 235836 215419 303308 297592 250046 244348 149238 54384 59613
[16:03:57.982] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[16:03:57.982] INFO: number of Vcal hits detected: 207515 207767 207568 207018 206794 206711 206672 207148 207581 207143 207219 207261 207508 207699 207946 207925
[16:03:57.982] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.8 99.6 99.5 99.4 99.4 99.6 99.8 99.6 99.7 99.7 99.8 99.9 100.0 100.0
[16:03:57.982] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.8 99.5 99.4 99.4 99.4 99.6 99.8 99.6 99.6 99.6 99.8 99.9 100.0 100.0
[16:03:57.982] INFO: X-ray hit rate [MHz/cm2]: 52.4 33.0 51.8 84.2 91.8 95.3 94.6 69.1 63.1 88.9 87.2 73.3 71.6 43.7 15.9 17.5
[16:03:57.982] INFO: PixTestHighRate::doXPixelAlive() done
[16:03:58.029] INFO: PixTest:: pg_setup set to default.
[16:03:58.044] INFO: enter test to run
[16:04:02.127] INFO: test: exit no parameter change
[16:04:02.442] QUIET: Connection to board 33 closed.
[16:04:02.457] INFO: pXar: this is the end, my friend