[11:53:49.316] INFO: *** Welcome to pxar ***
[11:53:49.316] INFO: *** Today: 2016/06/28
[11:53:50.262] INFO: *** Version: v1.9.0-814-g7497
[11:53:50.262] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//dacParameters35_C15.dat
[11:53:50.339] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//tbmParameters_C0b.dat
[11:53:50.339] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//defaultMaskFile.dat
[11:53:50.345] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C15.dat
[11:53:50.537] INFO: clk: 4
[11:53:50.538] INFO: ctr: 4
[11:53:50.538] INFO: sda: 19
[11:53:50.538] INFO: tin: 9
[11:53:50.538] INFO: level: 15
[11:53:50.538] INFO: triggerdelay: 0
[11:53:50.538] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[11:53:50.538] INFO: Log level: INFO
[11:53:50.570] QUIET: Connection to board DTB_WREK4U opened.
[11:53:50.573] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 32
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREK4U
MAC address: 40D855118020
Hostname: pixelDTB032
Comment:
------------------------------------------------------
[11:53:50.575] INFO: RPC call hashes of host and DTB match: 398089610
[11:53:52.112] INFO: DUT info:
[11:53:52.112] INFO: The DUT currently contains the following objects:
[11:53:52.112] INFO: 2 TBM Cores tbm08c (2 ON)
[11:53:52.125] INFO: TBM Core alpha (0): 7 registers set
[11:53:52.125] INFO: TBM Core beta (1): 7 registers set
[11:53:52.125] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[11:53:52.125] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[11:53:52.125] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[11:53:52.125] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[11:53:52.125] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[11:53:52.125] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[11:53:52.125] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[11:53:52.125] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[11:53:52.125] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[11:53:52.125] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[11:53:52.125] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[11:53:52.125] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[11:53:52.125] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[11:53:52.125] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[11:53:52.125] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[11:53:52.126] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[11:53:52.126] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[11:53:52.619] INFO: enter 'restricted' command line mode
[11:53:52.619] INFO: enter test to run
[11:53:58.874] INFO: test: PixelAlive no parameter change
[11:53:58.874] INFO: running: pixelalive
[11:53:58.947] INFO: ----------------------------------------------------------------------
[11:53:58.947] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[11:53:58.947] INFO: ----------------------------------------------------------------------
[11:53:59.266] INFO: Expecting 41600 events.
[11:54:03.625] INFO: 41600 events read in total (3641ms).
[11:54:03.790] INFO: Test took 4839ms.
[11:54:03.805] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:54:04.361] INFO: PixTestAlive::aliveTest() done
[11:54:04.361] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 3 1 0 0 0
[11:54:04.503] INFO: enter test to run
[11:54:53.010] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[11:54:53.010] INFO: running: highrate
[11:54:53.025] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[11:54:53.295] INFO: ----------------------------------------------------------------------
[11:54:53.295] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[11:54:53.295] INFO: ----------------------------------------------------------------------
[11:54:53.295] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[11:54:53.295] INFO: edge/corner pixel THR is adjusted
[11:54:53.295] INFO: PixTestHighRate::trimHotPixels: step 0...
[11:54:54.254] INFO: Collecting data for 5 seconds...
[11:54:59.273] INFO: Done with hot pixel readout
[11:55:11.216] INFO: PixTest:: pg_setup set to default.
[11:55:11.217] INFO: 14 hot pixels found in step 0
[11:55:12.229] INFO: Collecting data for 5 seconds...
[11:55:17.247] INFO: Done with hot pixel readout
[11:55:28.574] INFO: PixTest:: pg_setup set to default.
[11:55:28.574] INFO: 16 hot pixels found in step 1
[11:55:29.562] INFO: Collecting data for 5 seconds...
[11:55:34.580] INFO: Done with hot pixel readout
[11:55:46.144] INFO: PixTest:: pg_setup set to default.
[11:55:46.145] INFO: 12 hot pixels found in step 2
[11:55:47.133] INFO: Collecting data for 5 seconds...
[11:55:52.152] INFO: Done with hot pixel readout
[11:56:03.576] INFO: PixTest:: pg_setup set to default.
[11:56:03.577] INFO: 14 hot pixels found in step 3
[11:56:04.565] INFO: Collecting data for 5 seconds...
[11:56:09.582] INFO: Done with hot pixel readout
[11:56:09.977] ERROR: <datapipe.cc/CheckEventValidity:L491> Channel 0 Number of ROCs (6) != Token Chain Length (8)
[11:56:09.977] ERROR: <datapipe.cc/CheckEventValidity:L491> Channel 1 Number of ROCs (6) != Token Chain Length (8)
[11:56:09.977] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[11:56:09.977] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0f3 8040 4388 4389 4388 4389 4388 4389 4388 4389 2d0 2625 e000 c000
[11:56:09.977] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0ed 80c0 4188 4188 4188 4188 4188 4188 4188 4188 d8 202f e000 c000
[11:56:09.977] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0ee 8000 4188 4188 4188 512 2647 4188 4188 4188 4188 2c9 2081 4188 e000 c000
[11:56:09.977] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0ef 8040 418a 418a 418a 418a 55b 2a49 418a 418a 70c 244f 418a 418a e000 c000
[11:56:09.977] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0f0 80b1 4188 4188 4388 4388 458 2443 5f8 4388 4388 4388 e000 c000
[11:56:09.977] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0f1 80c0 4388 4388 4388 74d 204b 4388 4389 34c 204f 4389 503 204f 4389 4389 e000 c000
[11:56:09.977] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0f2 8000 4388 4388 e0 224a 4389 4389 21b 2645 4388 4388 4389 4389 e000 c000
[11:56:09.977] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[11:56:09.977] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1f3 8040 4388 4389 4c9 2044 4388 d2 2842 4389 4388 2e1 2689 4389 4388 280 2642 4389 68c 2065 e000 c000
[11:56:09.977] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1ed 80c0 4188 4188 4188 4188 4188 4188 4188 4188 660 244d e000 c000
[11:56:09.977] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1ee 8000 4188 2ca 2645 6cb 284e 809 2a40 4188 4188 a1 2645 4188 4188 4188 4188 4188 e000 c000
[11:56:09.977] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1ef 8040 418a 813 2643 418a 418a 418a 819 204d 418a 418a 418a 418a e000 c000
[11:56:09.978] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1f0 80b1 4189 51 2262 4389 452 206c 54 4389 4389 4389 254 2a45 4389 4389 e000 c000
[11:56:09.978] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1f1 80c0 4388 4388 149 2a2f 4388 4388 74b 2682 4389 710 2640 4389 4389 4389 e000 c000
[11:56:09.978] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1f2 8000 4388 4388 80c 2048 4389 4389 71a 264b 4388 4388 20c 2a4f 4389 4389 e000 c000
[11:56:20.941] INFO: PixTest:: pg_setup set to default.
[11:56:20.942] INFO: 10 hot pixels found in step 4
[11:56:21.930] INFO: Collecting data for 5 seconds...
[11:56:26.949] INFO: Done with hot pixel readout
[11:56:38.390] INFO: PixTest:: pg_setup set to default.
[11:56:38.390] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:56:38.390] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:56:38.391] INFO: 14 hot pixels found in step 5
[11:56:39.379] INFO: Collecting data for 5 seconds...
[11:56:44.398] INFO: Done with hot pixel readout
[11:56:55.955] INFO: PixTest:: pg_setup set to default.
[11:56:55.955] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:56:55.955] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:56:55.956] INFO: 11 hot pixels found in step 6
[11:56:56.944] INFO: Collecting data for 5 seconds...
[11:57:01.961] INFO: Done with hot pixel readout
[11:57:13.811] INFO: PixTest:: pg_setup set to default.
[11:57:13.811] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:57:13.811] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:57:13.812] INFO: 6 hot pixels found in step 7
[11:57:14.801] INFO: Collecting data for 5 seconds...
[11:57:19.820] INFO: Done with hot pixel readout
[11:57:31.704] INFO: PixTest:: pg_setup set to default.
[11:57:31.704] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:57:31.705] INFO: 6 hot pixels found in step 8
[11:57:32.693] INFO: Collecting data for 5 seconds...
[11:57:37.715] INFO: Done with hot pixel readout
[11:57:49.627] INFO: PixTest:: pg_setup set to default.
[11:57:49.627] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:57:49.627] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:57:49.628] INFO: 5 hot pixels found in step 9
[11:57:50.616] INFO: Collecting data for 5 seconds...
[11:57:55.634] INFO: Done with hot pixel readout
[11:58:07.704] INFO: PixTest:: pg_setup set to default.
[11:58:07.704] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:58:07.704] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:58:07.705] INFO: 3 hot pixels found in step 10
[11:58:08.694] INFO: Collecting data for 5 seconds...
[11:58:13.712] INFO: Done with hot pixel readout
[11:58:25.653] INFO: PixTest:: pg_setup set to default.
[11:58:25.653] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:58:25.653] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:58:25.654] INFO: 5 hot pixels found in step 11
[11:58:26.642] INFO: Collecting data for 5 seconds...
[11:58:31.661] INFO: Done with hot pixel readout
[11:58:43.655] INFO: PixTest:: pg_setup set to default.
[11:58:43.655] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:58:43.655] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:58:43.656] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:58:43.656] INFO: 7 hot pixels found in step 12
[11:58:44.644] INFO: Collecting data for 5 seconds...
[11:58:49.664] INFO: Done with hot pixel readout
[11:59:01.467] INFO: PixTest:: pg_setup set to default.
[11:59:01.467] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:59:01.468] INFO: 5 hot pixels found in step 13
[11:59:02.456] INFO: Collecting data for 5 seconds...
[11:59:07.475] INFO: Done with hot pixel readout
[11:59:19.350] INFO: PixTest:: pg_setup set to default.
[11:59:19.350] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:59:19.350] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:59:19.350] INFO: 3 hot pixels found in step 14
[11:59:19.381] INFO: 3 hot pixels could not be trimmed and have been masked.
[11:59:19.397] INFO: PixTest::trimHotPixels() done
[11:59:19.416] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C0.dat
[11:59:19.429] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C1.dat
[11:59:19.435] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C2.dat
[11:59:19.440] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C3.dat
[11:59:19.446] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C4.dat
[11:59:19.451] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C5.dat
[11:59:19.456] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C6.dat
[11:59:19.462] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C7.dat
[11:59:19.467] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C8.dat
[11:59:19.472] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C9.dat
[11:59:19.478] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C10.dat
[11:59:19.483] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C11.dat
[11:59:19.489] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C12.dat
[11:59:19.494] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C13.dat
[11:59:19.499] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C14.dat
[11:59:19.505] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C15.dat
[11:59:19.511] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//defaultMaskFile.dat
[11:59:19.527] INFO: enter test to run
[11:59:47.567] INFO: test: timing no parameter change
[11:59:47.568] INFO: running: timing
[11:59:47.571] INFO: ######################################################################
[11:59:47.571] INFO: PixTestTiming::doTest()
[11:59:47.571] INFO: ######################################################################
[11:59:47.571] INFO: ----------------------------------------------------------------------
[11:59:47.571] INFO: PixTestTiming::TBMPhaseScan()
[11:59:47.571] INFO: ----------------------------------------------------------------------
[12:05:34.790] INFO: TBM Phase Settings: 252
[12:05:34.790] INFO: 400MHz Phase: 7
[12:05:34.790] INFO: 160MHz Phase: 7
[12:05:34.790] INFO: Functional Phase Area: 3
[12:05:34.805] INFO: Test took 347234 ms.
[12:05:34.806] INFO: PixTestTiming::TBMPhaseScan() done.
[12:05:34.806] INFO: ----------------------------------------------------------------------
[12:05:34.806] INFO: PixTestTiming::ROCDelayScan()
[12:05:34.806] INFO: ----------------------------------------------------------------------
[12:07:40.548] INFO: ROC Delay Settings: 228
[12:07:40.548] INFO: ROC Header-Trailer/Token Delay: 11
[12:07:40.548] INFO: ROC Port 0 Delay: 4
[12:07:40.548] INFO: ROC Port 1 Delay: 4
[12:07:40.548] INFO: Functional ROC Area: 4
[12:07:40.551] INFO: Test took 125745 ms.
[12:07:40.551] INFO: PixTestTiming::ROCDelayScan() done.
[12:07:40.551] INFO: ----------------------------------------------------------------------
[12:07:40.551] INFO: PixTestTiming::TimingTest()
[12:07:40.551] INFO: ----------------------------------------------------------------------
[12:07:56.834] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:08:11.959] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:08:26.985] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:08:42.208] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:08:57.280] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:09:12.390] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:09:27.647] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:09:43.052] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:09:58.219] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:10:13.546] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:10:13.927] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:10:13.939] INFO: ----------------------------------------------------------------------
[12:10:13.939] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[12:10:13.939] INFO: ----------------------------------------------------------------------
[12:10:13.939] INFO: ----------------------------------------------------------------------
[12:10:13.939] INFO: Read back bit status: 1
[12:10:13.939] INFO: ----------------------------------------------------------------------
[12:10:13.939] INFO: ----------------------------------------------------------------------
[12:10:13.939] INFO: Timings are good!
[12:10:13.939] INFO: ----------------------------------------------------------------------
[12:10:13.939] INFO: Test took 153388 ms.
[12:10:13.939] INFO: PixTestTiming::TimingTest() done.
[12:10:13.939] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//tbmParameters_C0a.dat
[12:10:13.940] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//tbmParameters_C0b.dat
[12:10:13.940] INFO: PixTestTiming::doTest took 626372 ms.
[12:10:13.940] INFO: PixTestTiming::doTest() done
[12:10:13.940] INFO: Write out TBMPhaseScan_0_V0
[12:10:13.940] INFO: Write out TBMPhaseScan_1_V0
[12:10:13.940] INFO: Write out CombinedTBMPhaseScan_V0
[12:10:13.941] INFO: Write out ROCDelayScan3_V0
[12:10:13.941] INFO: enter test to run
[12:11:08.283] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[12:11:08.283] INFO: running: highrate
[12:11:08.288] INFO: ----------------------------------------------------------------------
[12:11:08.288] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[12:11:08.289] INFO: ----------------------------------------------------------------------
[12:11:08.289] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[12:11:08.289] INFO: edge/corner pixel THR is adjusted
[12:11:08.289] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:11:09.247] INFO: Collecting data for 5 seconds...
[12:11:14.264] INFO: Done with hot pixel readout
[12:11:25.859] INFO: PixTest:: pg_setup set to default.
[12:11:25.860] INFO: 4 hot pixels found in step 0
[12:11:26.852] INFO: Collecting data for 5 seconds...
[12:11:31.869] INFO: Done with hot pixel readout
[12:11:43.491] INFO: PixTest:: pg_setup set to default.
[12:11:43.491] INFO: 3 hot pixels found in step 1
[12:11:44.484] INFO: Collecting data for 5 seconds...
[12:11:49.500] INFO: Done with hot pixel readout
[12:12:01.144] INFO: PixTest:: pg_setup set to default.
[12:12:01.145] INFO: 4 hot pixels found in step 2
[12:12:02.137] INFO: Collecting data for 5 seconds...
[12:12:07.154] INFO: Done with hot pixel readout
[12:12:18.750] INFO: PixTest:: pg_setup set to default.
[12:12:18.751] INFO: 4 hot pixels found in step 3
[12:12:19.744] INFO: Collecting data for 5 seconds...
[12:12:24.761] INFO: Done with hot pixel readout
[12:12:36.388] INFO: PixTest:: pg_setup set to default.
[12:12:36.389] INFO: 6 hot pixels found in step 4
[12:12:37.382] INFO: Collecting data for 5 seconds...
[12:12:42.398] INFO: Done with hot pixel readout
[12:12:53.982] INFO: PixTest:: pg_setup set to default.
[12:12:53.982] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:12:53.982] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:12:53.983] INFO: 6 hot pixels found in step 5
[12:12:54.977] INFO: Collecting data for 5 seconds...
[12:12:59.993] INFO: Done with hot pixel readout
[12:13:11.618] INFO: PixTest:: pg_setup set to default.
[12:13:11.618] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:13:11.618] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:13:11.619] INFO: 5 hot pixels found in step 6
[12:13:12.612] INFO: Collecting data for 5 seconds...
[12:13:17.628] INFO: Done with hot pixel readout
[12:13:29.280] INFO: PixTest:: pg_setup set to default.
[12:13:29.280] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:13:29.280] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:13:29.281] INFO: 4 hot pixels found in step 7
[12:13:30.272] INFO: Collecting data for 5 seconds...
[12:13:35.289] INFO: Done with hot pixel readout
[12:13:46.914] INFO: PixTest:: pg_setup set to default.
[12:13:46.914] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:13:46.914] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:13:46.915] INFO: 4 hot pixels found in step 8
[12:13:47.908] INFO: Collecting data for 5 seconds...
[12:13:52.924] INFO: Done with hot pixel readout
[12:14:04.603] INFO: PixTest:: pg_setup set to default.
[12:14:04.603] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:14:04.603] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:14:04.603] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:14:04.604] INFO: 6 hot pixels found in step 9
[12:14:05.595] INFO: Collecting data for 5 seconds...
[12:14:10.611] INFO: Done with hot pixel readout
[12:14:22.229] INFO: PixTest:: pg_setup set to default.
[12:14:22.229] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:14:22.229] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:14:22.230] INFO: 4 hot pixels found in step 10
[12:14:23.223] INFO: Collecting data for 5 seconds...
[12:14:28.240] INFO: Done with hot pixel readout
[12:14:39.833] INFO: PixTest:: pg_setup set to default.
[12:14:39.833] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:14:39.833] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:14:39.833] INFO: 3 hot pixels found in step 11
[12:14:40.825] INFO: Collecting data for 5 seconds...
[12:14:45.842] INFO: Done with hot pixel readout
[12:14:57.437] INFO: PixTest:: pg_setup set to default.
[12:14:57.438] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:14:57.438] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:14:57.438] INFO: 4 hot pixels found in step 12
[12:14:58.431] INFO: Collecting data for 5 seconds...
[12:15:03.446] INFO: Done with hot pixel readout
[12:15:15.077] INFO: PixTest:: pg_setup set to default.
[12:15:15.077] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:15:15.077] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:15:15.078] INFO: 7 hot pixels found in step 13
[12:15:16.069] INFO: Collecting data for 5 seconds...
[12:15:21.085] INFO: Done with hot pixel readout
[12:15:32.702] INFO: PixTest:: pg_setup set to default.
[12:15:32.702] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:15:32.702] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:15:32.703] INFO: 5 hot pixels found in step 14
[12:15:32.738] INFO: 5 hot pixels could not be trimmed and have been masked.
[12:15:32.742] INFO: PixTest::trimHotPixels() done
[12:15:32.742] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C0.dat
[12:15:32.748] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C1.dat
[12:15:32.753] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C2.dat
[12:15:32.760] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C3.dat
[12:15:32.765] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C4.dat
[12:15:32.770] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C5.dat
[12:15:32.776] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C6.dat
[12:15:32.781] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C7.dat
[12:15:32.786] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C8.dat
[12:15:32.791] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C9.dat
[12:15:32.796] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C10.dat
[12:15:32.801] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C11.dat
[12:15:32.807] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C12.dat
[12:15:32.812] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C13.dat
[12:15:32.817] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C14.dat
[12:15:32.822] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C15.dat
[12:15:32.827] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//defaultMaskFile.dat
[12:15:32.838] INFO: enter test to run
[12:16:13.313] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[12:16:13.313] INFO: running: highrate
[12:16:13.319] INFO: ----------------------------------------------------------------------
[12:16:13.319] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[12:16:13.319] INFO: ----------------------------------------------------------------------
[12:16:13.319] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[12:16:13.319] INFO: edge/corner pixel THR is adjusted
[12:16:13.319] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:16:14.277] INFO: Collecting data for 1 seconds...
[12:16:15.282] INFO: Done with hot pixel readout
[12:16:19.209] INFO: PixTest:: pg_setup set to default.
[12:16:19.210] INFO: 0 hot pixels found in step 0
[12:16:19.215] INFO: 0 hot pixels could not be trimmed and have been masked.
[12:16:19.307] INFO: PixTest::trimHotPixels() done
[12:16:19.307] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C0.dat
[12:16:19.319] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C1.dat
[12:16:19.326] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C2.dat
[12:16:19.331] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C3.dat
[12:16:19.337] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C4.dat
[12:16:19.343] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C5.dat
[12:16:19.350] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C6.dat
[12:16:19.355] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C7.dat
[12:16:19.360] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C8.dat
[12:16:19.365] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C9.dat
[12:16:19.371] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C10.dat
[12:16:19.376] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C11.dat
[12:16:19.381] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C12.dat
[12:16:19.386] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C13.dat
[12:16:19.391] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C14.dat
[12:16:19.397] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C15.dat
[12:16:19.402] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-3-50_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//defaultMaskFile.dat
[12:16:19.412] INFO: enter test to run
[12:16:54.153] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[12:16:54.153] INFO: running: xray
[12:16:54.154] INFO: ----------------------------------------------------------------------
[12:16:54.154] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:16:54.154] INFO: ----------------------------------------------------------------------
[12:16:55.133] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:17:06.675] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[12:17:35.961] INFO: Resuming triggers.
[12:17:47.500] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[12:18:16.817] INFO: Resuming triggers.
[12:18:28.353] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[12:18:57.504] INFO: Resuming triggers.
[12:19:09.040] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[12:19:38.166] INFO: Resuming triggers.
[12:19:49.705] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[12:20:18.883] INFO: Resuming triggers.
[12:20:30.418] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[12:20:59.735] INFO: Resuming triggers.
[12:21:11.273] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[12:21:41.468] INFO: Resuming triggers.
[12:21:53.004] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[12:22:22.681] INFO: Resuming triggers.
[12:22:30.745] INFO: data taking finished, elapsed time: 100 seconds.
[12:22:51.737] INFO: PixTest:: pg_setup set to default.
[12:22:51.740] INFO: PixTestXray::doPhRun() done
[12:22:51.875] INFO: enter test to run
[12:23:37.134] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[12:23:37.134] INFO: running: xray
[12:23:37.135] INFO: ----------------------------------------------------------------------
[12:23:37.135] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:23:37.135] INFO: ----------------------------------------------------------------------
[12:23:38.101] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:23:44.963] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[12:24:15.095] INFO: Resuming triggers.
[12:24:21.960] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[12:24:52.070] INFO: Resuming triggers.
[12:24:58.937] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[12:25:29.071] INFO: Resuming triggers.
[12:25:35.943] INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[12:26:06.105] INFO: Resuming triggers.
[12:26:12.976] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[12:26:43.124] INFO: Resuming triggers.
[12:26:49.990] INFO: run duration 41 seconds, buffer almost full (81%), pausing triggers.
[12:27:20.104] INFO: Resuming triggers.
[12:27:26.968] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[12:27:57.136] INFO: Resuming triggers.
[12:28:04.005] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[12:28:34.184] INFO: Resuming triggers.
[12:28:41.047] INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[12:29:11.173] INFO: Resuming triggers.
[12:29:18.038] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[12:29:48.219] INFO: Resuming triggers.
[12:29:55.082] INFO: run duration 75 seconds, buffer almost full (81%), pausing triggers.
[12:30:25.231] INFO: Resuming triggers.
[12:30:32.099] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[12:31:02.893] INFO: Resuming triggers.
[12:31:09.758] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[12:31:40.501] INFO: Resuming triggers.
[12:31:47.371] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[12:32:18.196] INFO: Resuming triggers.
[12:32:22.398] INFO: data taking finished, elapsed time: 100 seconds.
[12:32:42.173] INFO: PixTest:: pg_setup set to default.
[12:32:42.176] INFO: PixTestXray::doPhRun() done
[12:32:42.329] INFO: enter test to run
[12:33:20.306] INFO: test: HighRate no parameter change
[12:33:20.306] INFO: running: highrate
[12:33:20.307] INFO: ----------------------------------------------------------------------
[12:33:20.307] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[12:33:20.307] INFO: ----------------------------------------------------------------------
[12:33:20.450] INFO: Expecting 768 events.
[12:33:21.585] INFO: 768 events read in total (419ms).
[12:33:21.585] INFO: Test took 1269ms.
[12:33:22.388] INFO: Expecting 41600 events.
[12:33:25.484] INFO: 41600 events read in total (2569ms).
[12:33:25.485] INFO: Test took 3893ms.
[12:33:25.519] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:33:26.242] INFO: Expecting 41600 events.
[12:33:29.470] INFO: 41600 events read in total (2701ms).
[12:33:29.471] INFO: Test took 3935ms.
[12:33:29.504] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:33:30.227] INFO: Expecting 41600 events.
[12:33:33.517] INFO: 41600 events read in total (2763ms).
[12:33:33.518] INFO: Test took 3997ms.
[12:33:33.553] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:33:34.275] INFO: Expecting 41600 events.
[12:33:37.573] INFO: 41600 events read in total (2771ms).
[12:33:37.574] INFO: Test took 4004ms.
[12:33:37.608] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:33:38.326] INFO: Expecting 41600 events.
[12:33:41.561] INFO: 41600 events read in total (2709ms).
[12:33:41.562] INFO: Test took 3937ms.
[12:33:41.596] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:33:42.311] INFO: Expecting 41600 events.
[12:33:45.493] INFO: 41600 events read in total (2655ms).
[12:33:45.494] INFO: Test took 3880ms.
[12:33:45.528] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:33:46.245] INFO: Expecting 41600 events.
[12:33:49.509] INFO: 41600 events read in total (2737ms).
[12:33:49.509] INFO: Test took 3963ms.
[12:33:49.544] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:33:50.263] INFO: Expecting 41600 events.
[12:33:53.594] INFO: 41600 events read in total (2805ms).
[12:33:53.595] INFO: Test took 4034ms.
[12:33:53.630] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:33:54.348] INFO: Expecting 41600 events.
[12:33:57.660] INFO: 41600 events read in total (2785ms).
[12:33:57.661] INFO: Test took 4013ms.
[12:33:57.695] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:33:58.415] INFO: Expecting 41600 events.
[12:34:01.679] INFO: 41600 events read in total (2738ms).
[12:34:01.680] INFO: Test took 3967ms.
[12:34:01.714] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:34:02.434] INFO: Expecting 41600 events.
[12:34:05.650] INFO: 41600 events read in total (2689ms).
[12:34:05.651] INFO: Test took 3919ms.
[12:34:05.685] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:34:06.392] INFO: Expecting 41600 events.
[12:34:09.744] INFO: 41600 events read in total (2825ms).
[12:34:09.745] INFO: Test took 4041ms.
[12:34:09.779] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:34:10.504] INFO: Expecting 41600 events.
[12:34:13.900] INFO: 41600 events read in total (2870ms).
[12:34:13.901] INFO: Test took 4105ms.
[12:34:13.934] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:34:14.660] INFO: Expecting 41600 events.
[12:34:17.918] INFO: 41600 events read in total (2731ms).
[12:34:17.919] INFO: Test took 3967ms.
[12:34:17.952] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:34:18.679] INFO: Expecting 41600 events.
[12:34:21.885] INFO: 41600 events read in total (2680ms).
[12:34:21.886] INFO: Test took 3916ms.
[12:34:21.918] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:34:22.643] INFO: Expecting 41600 events.
[12:34:25.870] INFO: 41600 events read in total (2700ms).
[12:34:25.871] INFO: Test took 3935ms.
[12:34:25.905] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:34:26.630] INFO: Expecting 41600 events.
[12:34:29.853] INFO: 41600 events read in total (2696ms).
[12:34:29.854] INFO: Test took 3931ms.
[12:34:29.886] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:34:30.610] INFO: Expecting 41600 events.
[12:34:33.840] INFO: 41600 events read in total (2703ms).
[12:34:33.841] INFO: Test took 3937ms.
[12:34:33.875] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:34:34.600] INFO: Expecting 41600 events.
[12:34:37.822] INFO: 41600 events read in total (2695ms).
[12:34:37.823] INFO: Test took 3929ms.
[12:34:37.856] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:34:38.581] INFO: Expecting 41600 events.
[12:34:41.685] INFO: 41600 events read in total (2578ms).
[12:34:41.685] INFO: Test took 3812ms.
[12:34:41.718] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:34:42.083] INFO: enter test to run
[12:34:53.794] INFO: test: HighRate no parameter change
[12:34:53.794] INFO: running: highrate
[12:34:53.795] INFO: ----------------------------------------------------------------------
[12:34:53.795] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:34:53.795] INFO: ----------------------------------------------------------------------
[12:34:54.418] INFO: Expecting 208000 events.
[12:35:06.279] INFO: 208000 events read in total (11334ms).
[12:35:06.282] INFO: Test took 12475ms.
[12:35:06.419] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:35:06.672] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 3 1 0 0 0
[12:35:06.672] INFO: number of red-efficiency pixels: 70 35 71 115 107 128 123 94 88 98 99 89 92 62 15 16
[12:35:06.672] INFO: number of X-ray hits detected: 57279 35943 61577 97081 102638 111814 112372 78214 81254 105027 100712 84740 88805 52906 18544 20152
[12:35:06.672] 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:35:06.672] INFO: number of Vcal hits detected: 207929 207964 207928 207881 207892 207869 207874 207906 207910 207900 207900 207764 207859 207937 207985 207984
[12:35:06.672] 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 100.0 100.0 100.0 100.0 100.0 100.0
[12:35:06.672] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0 100.0 99.9 99.9 100.0 100.0 100.0
[12:35:06.672] INFO: X-ray hit rate [MHz/cm2]: 16.8 10.5 18.0 28.5 30.1 32.8 32.9 22.9 23.8 30.8 29.5 24.8 26.0 15.5 5.4 5.9
[12:35:06.672] INFO: PixTestHighRate::doXPixelAlive() done
[12:35:06.721] INFO: PixTest:: pg_setup set to default.
[12:35:06.736] INFO: enter test to run
[12:35:35.897] INFO: test: HighRate no parameter change
[12:35:35.897] INFO: running: highrate
[12:35:35.898] INFO: ----------------------------------------------------------------------
[12:35:35.898] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:35:35.898] INFO: ----------------------------------------------------------------------
[12:35:36.519] INFO: Expecting 208000 events.
[12:35:49.953] INFO: 208000 events read in total (12908ms).
[12:35:49.958] INFO: Test took 14050ms.
[12:35:50.239] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:35:50.537] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 3 1 0 0 0
[12:35:50.537] INFO: number of red-efficiency pixels: 205 100 229 328 323 484 392 233 255 350 317 255 237 156 45 44
[12:35:50.537] INFO: number of X-ray hits detected: 116849 73584 126568 199965 208416 228485 229992 160893 166541 214772 205325 173981 182060 108093 38205 42302
[12:35:50.537] 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:35:50.537] INFO: number of Vcal hits detected: 207783 207897 207755 207649 207669 207464 207575 207749 207733 207635 207670 207584 207704 207831 207954 207956
[12:35:50.537] INFO: Vcal hit fiducial efficiency (%): 99.9 100.0 99.9 99.8 99.9 99.8 99.8 99.9 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[12:35:50.537] INFO: Vcal hit overall efficiency (%): 99.9 100.0 99.9 99.8 99.8 99.7 99.8 99.9 99.9 99.8 99.8 99.8 99.9 99.9 100.0 100.0
[12:35:50.537] INFO: X-ray hit rate [MHz/cm2]: 34.2 21.6 37.1 58.6 61.1 67.0 67.4 47.2 48.8 63.0 60.2 51.0 53.4 31.7 11.2 12.4
[12:35:50.537] INFO: PixTestHighRate::doXPixelAlive() done
[12:35:50.587] INFO: PixTest:: pg_setup set to default.
[12:35:50.600] INFO: enter test to run
[12:36:18.233] INFO: test: HighRate no parameter change
[12:36:18.233] INFO: running: highrate
[12:36:18.234] INFO: ----------------------------------------------------------------------
[12:36:18.234] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:36:18.234] INFO: ----------------------------------------------------------------------
[12:36:18.854] INFO: Expecting 208000 events.
[12:36:34.091] INFO: 208000 events read in total (14710ms).
[12:36:34.099] INFO: Test took 15854ms.
[12:36:34.523] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:36:34.865] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 3 1 0 0 0
[12:36:34.865] INFO: number of red-efficiency pixels: 354 183 524 713 736 1168 815 507 490 750 697 508 544 377 64 60
[12:36:34.865] INFO: number of X-ray hits detected: 176171 110532 190423 300853 315391 344397 346135 241555 251286 323063 309786 261736 274131 162949 57530 64418
[12:36:34.865] 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:36:34.865] INFO: number of Vcal hits detected: 207585 207810 207361 207159 207166 206518 207015 207412 207466 207144 207188 207285 207345 207576 207935 207938
[12:36:34.865] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.7 99.6 99.6 99.4 99.6 99.8 99.8 99.6 99.6 99.8 99.7 99.8 100.0 100.0
[12:36:34.865] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.7 99.6 99.6 99.3 99.5 99.7 99.7 99.6 99.6 99.7 99.7 99.8 100.0 100.0
[12:36:34.865] INFO: X-ray hit rate [MHz/cm2]: 51.6 32.4 55.8 88.2 92.4 100.9 101.5 70.8 73.7 94.7 90.8 76.7 80.3 47.8 16.9 18.9
[12:36:34.865] INFO: PixTestHighRate::doXPixelAlive() done
[12:36:34.919] INFO: PixTest:: pg_setup set to default.
[12:36:34.936] INFO: enter test to run
[12:37:18.881] INFO: test: exit no parameter change
[12:37:19.245] QUIET: Connection to board 32 closed.
[12:37:19.246] INFO: pXar: this is the end, my friend