[09:45:08.390] INFO: *** Welcome to pxar ***
[09:45:08.390] INFO: *** Today: 2016/04/13
[09:45:08.819] INFO: *** Version: v1.9.0-796-gef167-dirty
[09:45:08.819] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-K-2-23_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-K-2-23_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//dacParameters35_C15.dat
[09:45:08.838] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-K-2-23_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-K-2-23_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//tbmParameters_C0b.dat
[09:45:08.838] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-K-2-23_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//defaultMaskFile.dat
[09:45:08.838] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-K-2-23_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-K-2-23_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C15.dat
[09:45:09.012] INFO: clk: 4
[09:45:09.012] INFO: ctr: 4
[09:45:09.012] INFO: sda: 19
[09:45:09.012] INFO: tin: 9
[09:45:09.012] INFO: level: 15
[09:45:09.012] INFO: triggerdelay: 0
[09:45:09.012] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[09:45:09.012] INFO: Log level: INFO
[09:45:09.043] QUIET: Connection to board DTB_WREKRL opened.
[09:45:09.046] 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:
------------------------------------------------------
[09:45:09.049] INFO: RPC call hashes of host and DTB match: 398089610
[09:45:10.579] INFO: DUT info:
[09:45:10.579] INFO: The DUT currently contains the following objects:
[09:45:10.579] INFO: 2 TBM Cores tbm08c (2 ON)
[09:45:10.589] INFO: TBM Core alpha (0): 7 registers set
[09:45:10.589] INFO: TBM Core beta (1): 7 registers set
[09:45:10.589] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[09:45:10.589] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[09:45:10.589] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[09:45:10.589] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[09:45:10.589] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[09:45:10.589] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[09:45:10.589] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[09:45:10.589] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[09:45:10.589] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[09:45:10.589] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[09:45:10.589] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[09:45:10.589] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[09:45:10.590] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[09:45:10.590] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[09:45:10.590] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[09:45:10.590] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[09:45:10.590] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[09:45:11.027] INFO: enter 'restricted' command line mode
[09:45:11.027] INFO: enter test to run
[09:45:24.638] INFO: test: timing no parameter change
[09:45:24.638] INFO: running: timing
[09:45:24.680] INFO: ######################################################################
[09:45:24.680] INFO: PixTestTiming::doTest()
[09:45:24.680] INFO: ######################################################################
[09:45:24.681] INFO: ----------------------------------------------------------------------
[09:45:24.681] INFO: PixTestTiming::TBMPhaseScan()
[09:45:24.681] INFO: ----------------------------------------------------------------------
[09:50:08.607] INFO: TBM Phase Settings: 208
[09:50:08.607] INFO: 400MHz Phase: 4
[09:50:08.607] INFO: 160MHz Phase: 6
[09:50:08.607] INFO: Functional Phase Area: 3
[09:50:08.617] INFO: Test took 283937 ms.
[09:50:08.617] INFO: PixTestTiming::TBMPhaseScan() done.
[09:50:08.617] INFO: ----------------------------------------------------------------------
[09:50:08.617] INFO: PixTestTiming::ROCDelayScan()
[09:50:08.617] INFO: ----------------------------------------------------------------------
[09:52:07.738] INFO: ROC Delay Settings: 219
[09:52:07.738] INFO: ROC Header-Trailer/Token Delay: 11
[09:52:07.738] INFO: ROC Port 0 Delay: 3
[09:52:07.738] INFO: ROC Port 1 Delay: 3
[09:52:07.738] INFO: Functional ROC Area: 4
[09:52:07.741] INFO: Test took 119124 ms.
[09:52:07.741] INFO: PixTestTiming::ROCDelayScan() done.
[09:52:07.741] INFO: ----------------------------------------------------------------------
[09:52:07.741] INFO: PixTestTiming::TimingTest()
[09:52:07.741] INFO: ----------------------------------------------------------------------
[09:52:16.234] ERROR: <datapipe.cc/CheckEventValidity:L491> Channel 0 Number of ROCs (4) != Token Chain Length (8)
[09:52:16.234] ERROR: <datapipe.cc/CheckEventID:L463> Channel 0 Event ID mismatch: local ID (128) != TBM ID (83)
[09:52:24.091] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:52:39.046] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:52:54.010] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:53:08.966] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:53:23.927] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:53:38.893] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:53:53.843] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:54:08.809] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:54:23.793] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:54:38.233] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:54:38.615] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:54:38.641] INFO: ----------------------------------------------------------------------
[09:54:38.641] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[09:54:38.641] INFO: ----------------------------------------------------------------------
[09:54:38.641] INFO: ----------------------------------------------------------------------
[09:54:38.641] INFO: Read back bit status: 1
[09:54:38.641] INFO: ----------------------------------------------------------------------
[09:54:38.641] ERROR: <PixTest.cc/banner:L1418> ----------------------------------------------------------------------
[09:54:38.641] ERROR: <PixTest.cc/banner:L1419> Timings are not good :(
[09:54:38.641] ERROR: <PixTest.cc/banner:L1420> ----------------------------------------------------------------------
[09:54:38.641] INFO: Test took 150900 ms.
[09:54:38.641] INFO: PixTestTiming::TimingTest() done.
[09:54:38.641] INFO: Problem with TimingTest! Timings not saved!
[09:54:38.641] INFO: PixTestTiming::doTest took 553980 ms.
[09:54:38.641] INFO: PixTestTiming::doTest() done
[09:54:38.642] INFO: Write out TBMPhaseScan_0_V0
[09:54:38.757] INFO: Write out TBMPhaseScan_1_V0
[09:54:38.757] INFO: Write out CombinedTBMPhaseScan_V0
[09:54:38.758] INFO: Write out ROCDelayScan3_V0
[09:54:38.758] INFO: enter test to run
[09:54:52.706] INFO: test: PixelAlive no parameter change
[09:54:52.706] INFO: running: pixelalive
[09:54:52.728] INFO: ----------------------------------------------------------------------
[09:54:52.728] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[09:54:52.728] INFO: ----------------------------------------------------------------------
[09:54:53.048] INFO: Expecting 41600 events.
[09:54:57.387] INFO: 41600 events read in total (3624ms).
[09:54:57.388] INFO: Test took 4657ms.
[09:54:57.394] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:54:57.813] INFO: PixTestAlive::aliveTest() done
[09:54:57.813] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 258 0 0 0 0 0 0 0 0
[09:54:57.816] INFO: enter test to run
[09:55:32.706] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[09:55:32.706] INFO: running: highrate
[09:55:32.722] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-K-2-23_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-K-2-23_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[09:55:33.009] INFO: ----------------------------------------------------------------------
[09:55:33.009] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[09:55:33.009] INFO: ----------------------------------------------------------------------
[09:55:33.009] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[09:55:33.009] INFO: edge/corner pixel THR is adjusted
[09:55:33.009] INFO: PixTestHighRate::trimHotPixels: step 0...
[09:55:33.967] INFO: Collecting data for 5 seconds...
[09:55:38.983] INFO: Done with hot pixel readout
[09:55:51.098] INFO: PixTest:: pg_setup set to default.
[09:55:51.099] INFO: 29 hot pixels found in step 0
[09:55:52.095] INFO: Collecting data for 5 seconds...
[09:55:57.111] INFO: Done with hot pixel readout
[09:56:09.196] INFO: PixTest:: pg_setup set to default.
[09:56:09.197] INFO: 29 hot pixels found in step 1
[09:56:10.192] INFO: Collecting data for 5 seconds...
[09:56:15.209] INFO: Done with hot pixel readout
[09:56:27.369] INFO: PixTest:: pg_setup set to default.
[09:56:27.370] INFO: 21 hot pixels found in step 2
[09:56:28.366] INFO: Collecting data for 5 seconds...
[09:56:33.382] INFO: Done with hot pixel readout
[09:56:45.511] INFO: PixTest:: pg_setup set to default.
[09:56:45.512] INFO: 27 hot pixels found in step 3
[09:56:46.507] INFO: Collecting data for 5 seconds...
[09:56:51.523] INFO: Done with hot pixel readout
[09:57:03.640] INFO: PixTest:: pg_setup set to default.
[09:57:03.641] INFO: 22 hot pixels found in step 4
[09:57:04.635] INFO: Collecting data for 5 seconds...
[09:57:09.650] INFO: Done with hot pixel readout
[09:57:21.819] INFO: PixTest:: pg_setup set to default.
[09:57:21.819] INFO: 23 hot pixels found in step 5
[09:57:22.814] INFO: Collecting data for 5 seconds...
[09:57:27.831] INFO: Done with hot pixel readout
[09:57:39.926] INFO: PixTest:: pg_setup set to default.
[09:57:39.926] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:57:39.927] INFO: 23 hot pixels found in step 6
[09:57:40.923] INFO: Collecting data for 5 seconds...
[09:57:45.939] INFO: Done with hot pixel readout
[09:57:57.992] INFO: PixTest:: pg_setup set to default.
[09:57:57.993] INFO: 15 hot pixels found in step 7
[09:57:58.988] INFO: Collecting data for 5 seconds...
[09:58:04.003] INFO: Done with hot pixel readout
[09:58:16.093] INFO: PixTest:: pg_setup set to default.
[09:58:16.093] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:58:16.093] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:58:16.093] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:58:16.094] INFO: 12 hot pixels found in step 8
[09:58:17.088] INFO: Collecting data for 5 seconds...
[09:58:22.105] INFO: Done with hot pixel readout
[09:58:34.202] INFO: PixTest:: pg_setup set to default.
[09:58:34.202] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:58:34.202] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:58:34.203] INFO: 12 hot pixels found in step 9
[09:58:35.198] INFO: Collecting data for 5 seconds...
[09:58:40.215] INFO: Done with hot pixel readout
[09:58:52.361] INFO: PixTest:: pg_setup set to default.
[09:58:52.361] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:58:52.361] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:58:52.361] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:58:52.362] INFO: 14 hot pixels found in step 10
[09:58:53.356] INFO: Collecting data for 5 seconds...
[09:58:58.372] INFO: Done with hot pixel readout
[09:59:04.352] ERROR: <datapipe.cc/CheckEventValidity:L491> Channel 0 Number of ROCs (4) != Token Chain Length (8)
[09:59:04.352] ERROR: <datapipe.cc/CheckEventID:L463> Channel 0 Event ID mismatch: local ID (236) != TBM ID (127)
[09:59:04.352] ERROR: <datapipe.cc/CheckEventValidity:L491> Channel 0 Number of ROCs (1) != Token Chain Length (8)
[09:59:04.352] ERROR: <datapipe.cc/CheckEventID:L463> Channel 0 Event ID mismatch: local ID (128) != TBM ID (236)
[09:59:04.352] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[09:59:04.352] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0ef 8040 4c38 2d4 2a6a 4c38 351 2480 4c38 513 2463 513 2062 4c38 4c38 30d 2087 4c38 4c38 6c9 2080 4c38 e000 c000
[09:59:04.352] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0ea 8000 4c38 4c38 4c38 4c39 4c38 54 284d 4c38 71d 2264 4c38 2c5 2068 4c38 4cb 2465 e000 c000
[09:59:04.352] ERROR: <datapipe.cc/Read:L166> ====== 2 ====== a0eb 8040 4c38 4c39 155 2a40 4c38 4c38 48 2042
[09:59:04.352] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a07f 8097 4c38 e000 c000
[09:59:04.352] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0ec 80b1 4c38 4c38 4c38 4c38 358 264f 4c38 4c38 4c38 4c38 10 2821 1 2240 e000 c000
[09:59:04.352] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0ed 80c0 4c38 4c38 4c38 4c38 4c38 4c38 4d2 2448 6c4 2844 4c38 4c38 359 2644 711 2a4e e000 c000
[09:59:04.352] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0ee 8000 4c38 4c38 4c38 4c38 358 2644 4c38 4c38 205 204f 4c38 509 2461 4c38 e000 c000
[09:59:10.707] INFO: PixTest:: pg_setup set to default.
[09:59:10.707] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:59:10.707] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:59:10.707] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:59:10.708] INFO: 14 hot pixels found in step 11
[09:59:11.702] INFO: Collecting data for 5 seconds...
[09:59:16.719] INFO: Done with hot pixel readout
[09:59:28.840] INFO: PixTest:: pg_setup set to default.
[09:59:28.840] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:59:28.840] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:59:28.841] INFO: 9 hot pixels found in step 12
[09:59:29.836] INFO: Collecting data for 5 seconds...
[09:59:34.852] INFO: Done with hot pixel readout
[09:59:43.481] ERROR: <datapipe.cc/CheckEventValidity:L491> Channel 0 Number of ROCs (4) != Token Chain Length (8)
[09:59:43.482] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[09:59:43.482] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a067 8040 4c3a 655 2646 4c3a 4c38 4c38 15d 282c 4c3a 658 224d 4c3a 4c38 455 284e 4c39 294 2a4d e000 c000
[09:59:43.482] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a061 80c0 4c38 4c38 252 2a4d 4c38 618 244a 4c38 4c38 4c38 4c38 4c38 e000 c000
[09:59:43.482] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a062 8000 4c38 4c38 4c38 4c38 29b 2065 4c38 4c38 58 282d 4c38 4c38 e000 c000
[09:59:43.482] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a063 8040 4c38 4c38 2a1 2841 4c38 4c38 44a 2264 4c38 4c38 48c 264f 4c38 4c3a 449 242a e000 c000
[09:59:43.482] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a064 80b1 7fc 27f8 7f8 4c38 4c38 4c38 84a 262c 4c38 353 266e 4c38 89 204d e000 c000
[09:59:43.482] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a065 80c0 4c38 4c38 361 2667 4c38 4c38 4c38 a 2245 711 2464 4c38 4c38 709 2661 4c39 e000 c000
[09:59:43.482] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a066 8000 4c38 4c38 721 2049 4c3a 4c3a 4c38 51b 204f 695 2462 4c38 512 244d 75d 2a41 4c3a 9c 2667 845 204f 4c39 e000 c000
[09:59:46.974] INFO: PixTest:: pg_setup set to default.
[09:59:46.974] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:59:46.974] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:59:46.974] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:59:46.974] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:59:46.975] INFO: 9 hot pixels found in step 13
[09:59:47.969] INFO: Collecting data for 5 seconds...
[09:59:52.986] INFO: Done with hot pixel readout
[10:00:05.054] INFO: PixTest:: pg_setup set to default.
[10:00:05.054] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:00:05.054] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:00:05.055] INFO: 6 hot pixels found in step 14
[10:00:05.093] INFO: 6 hot pixels could not be trimmed and have been masked.
[10:00:05.097] INFO: PixTest::trimHotPixels() done
[10:00:05.097] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-23_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C0.dat
[10:00:05.103] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-23_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C1.dat
[10:00:05.108] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-23_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C2.dat
[10:00:05.113] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-23_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C3.dat
[10:00:05.119] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-23_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C4.dat
[10:00:05.124] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-23_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C5.dat
[10:00:05.129] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-23_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C6.dat
[10:00:05.134] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-23_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C7.dat
[10:00:05.139] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-23_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C8.dat
[10:00:05.144] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-23_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C9.dat
[10:00:05.149] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-23_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C10.dat
[10:00:05.154] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-23_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C11.dat
[10:00:05.160] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-23_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C12.dat
[10:00:05.165] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-23_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C13.dat
[10:00:05.180] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-23_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C14.dat
[10:00:05.191] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-23_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C15.dat
[10:00:05.196] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-K-2-23_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//defaultMaskFile.dat
[10:00:05.214] INFO: enter test to run
[10:01:18.647] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[10:01:18.647] INFO: running: highrate
[10:01:18.652] INFO: ----------------------------------------------------------------------
[10:01:18.652] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[10:01:18.652] INFO: ----------------------------------------------------------------------
[10:01:18.652] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[10:01:18.652] INFO: edge/corner pixel THR is adjusted
[10:01:18.652] INFO: PixTestHighRate::trimHotPixels: step 0...
[10:01:19.610] INFO: Collecting data for 1 seconds...
[10:01:20.612] INFO: Done with hot pixel readout
[10:01:24.769] INFO: PixTest:: pg_setup set to default.
[10:01:24.769] INFO: 0 hot pixels found in step 0
[10:01:24.774] INFO: 0 hot pixels could not be trimmed and have been masked.
[10:01:24.858] INFO: PixTest::trimHotPixels() done
[10:01:24.858] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-23_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C0.dat
[10:01:24.866] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-23_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C1.dat
[10:01:24.873] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-23_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C2.dat
[10:01:24.879] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-23_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C3.dat
[10:01:24.884] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-23_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C4.dat
[10:01:24.889] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-23_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C5.dat
[10:01:24.894] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-23_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C6.dat
[10:01:24.899] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-23_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C7.dat
[10:01:24.904] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-23_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C8.dat
[10:01:24.910] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-23_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C9.dat
[10:01:24.915] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-23_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C10.dat
[10:01:24.921] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-23_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C11.dat
[10:01:24.926] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-23_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C12.dat
[10:01:24.931] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-23_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C13.dat
[10:01:24.936] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-23_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C14.dat
[10:01:24.942] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-23_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//trimParameters35_C15.dat
[10:01:24.947] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-K-2-23_FPIXTest-17C-FNAL-160408-0917_2016-04-08_09h17m_1460125040/000_FPIXTest_p17//defaultMaskFile.dat
[10:01:24.958] INFO: enter test to run
[10:02:24.103] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[10:02:24.103] INFO: running: xray
[10:02:24.104] INFO: ----------------------------------------------------------------------
[10:02:24.104] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[10:02:24.104] INFO: ----------------------------------------------------------------------
[10:02:25.068] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[10:02:36.072] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[10:03:05.690] INFO: Resuming triggers.
[10:03:16.696] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[10:03:35.309] ERROR: <datapipe.cc/CheckEventValidity:L491> Channel 0 Number of ROCs (4) != Token Chain Length (8)
[10:03:35.309] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[10:03:35.309] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a037 8040 4c3a 4c3a 4c38 4c38 dc 2a49 4c3a 4c3a 35a 224e 4c38 605 204d 4c39 e000 c000
[10:03:35.309] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a031 80c0 4c38 4c38 4c38 4c0 2a4f 4c38 4c38 c8 2a64 4c38 4c38 45c 224c 4c38 e000 c000
[10:03:35.309] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a032 8000 4c38 4c38 d1 2a49 4c38 4c38 804 2a2f 4c38 4c38 4c38 4c38 e000 c000
[10:03:35.309] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a033 8040 4c38 34d 2266 4c38 4c38 4c38 348 2269 513 2a4c 4c38 4c38 4c38 28b 2a4b 4c3a e000 c000
[10:03:35.309] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a034 80b1 7fc 27f8 7f8 4c38 cd 2442 4c5 2a41 4c38 4c38 4c38 28c 2248 4c38 15a 2646 e000 c000
[10:03:35.309] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a035 80c0 4c38 4c38 4c38 9a 2662 9a 2a4c 4c38 694 2229 4c38 243 2a61 4d9 204c 75c 264e 4c38 4c38 240 244f 2c0 2469 4d9 2286 613 2666 4c39 551 2a2f e000 c000
[10:03:35.310] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a036 8000 4c38 4c38 4c3a 4c3a 4c38 445 2a4a 4c38 4c3a 691 264f 4c39 645 242c e000 c000
[10:03:46.454] INFO: Resuming triggers.
[10:03:57.460] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[10:04:27.105] INFO: Resuming triggers.
[10:04:38.114] INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[10:05:02.201] INFO: Resuming triggers.
[10:05:13.206] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[10:05:42.776] INFO: Resuming triggers.
[10:05:53.779] INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[10:06:23.357] INFO: Resuming triggers.
[10:06:34.364] INFO: run duration 76 seconds, buffer almost full (81%), pausing triggers.
[10:07:03.953] INFO: Resuming triggers.
[10:07:14.953] INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[10:07:44.591] INFO: Resuming triggers.
[10:07:55.595] INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[10:08:25.262] INFO: Resuming triggers.
[10:08:26.545] INFO: data taking finished, elapsed time: 100 seconds.
[10:08:30.359] INFO: PixTest:: pg_setup set to default.
[10:08:30.362] INFO: PixTestXray::doPhRun() done
[10:08:30.577] INFO: enter test to run
[10:09:02.948] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[10:09:02.948] INFO: running: xray
[10:09:02.949] INFO: ----------------------------------------------------------------------
[10:09:02.949] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[10:09:02.949] INFO: ----------------------------------------------------------------------
[10:09:03.935] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[10:09:10.293] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[10:09:40.476] INFO: Resuming triggers.
[10:09:46.839] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[10:10:16.970] INFO: Resuming triggers.
[10:10:23.330] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[10:10:53.468] INFO: Resuming triggers.
[10:10:59.825] INFO: run duration 25 seconds, buffer almost full (81%), pausing triggers.
[10:11:29.906] INFO: Resuming triggers.
[10:11:36.264] INFO: run duration 31 seconds, buffer almost full (81%), pausing triggers.
[10:12:06.409] INFO: Resuming triggers.
[10:12:12.770] INFO: run duration 38 seconds, buffer almost full (81%), pausing triggers.
[10:12:42.887] INFO: Resuming triggers.
[10:12:49.249] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[10:13:19.453] INFO: Resuming triggers.
[10:13:25.816] INFO: run duration 50 seconds, buffer almost full (81%), pausing triggers.
[10:13:55.910] INFO: Resuming triggers.
[10:14:02.270] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[10:14:32.409] INFO: Resuming triggers.
[10:14:38.774] INFO: run duration 63 seconds, buffer almost full (81%), pausing triggers.
[10:15:05.799] INFO: Resuming triggers.
[10:15:12.165] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[10:15:42.288] INFO: Resuming triggers.
[10:15:48.653] INFO: run duration 76 seconds, buffer almost full (81%), pausing triggers.
[10:16:18.708] INFO: Resuming triggers.
[10:16:25.075] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[10:16:55.227] INFO: Resuming triggers.
[10:17:01.590] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[10:17:31.636] INFO: Resuming triggers.
[10:17:37.995] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[10:18:08.122] INFO: Resuming triggers.
[10:18:13.023] INFO: data taking finished, elapsed time: 100 seconds.
[10:18:36.333] INFO: PixTest:: pg_setup set to default.
[10:18:36.336] INFO: PixTestXray::doPhRun() done
[10:18:36.490] INFO: enter test to run
[10:19:22.055] INFO: test: HighRate no parameter change
[10:19:22.055] INFO: running: highrate
[10:19:22.057] INFO: ----------------------------------------------------------------------
[10:19:22.057] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[10:19:22.057] INFO: ----------------------------------------------------------------------
[10:19:22.196] INFO: Expecting 768 events.
[10:19:23.330] INFO: 768 events read in total (418ms).
[10:19:23.330] INFO: Test took 1267ms.
[10:19:24.133] INFO: Expecting 41600 events.
[10:19:27.264] INFO: 41600 events read in total (2604ms).
[10:19:27.266] INFO: Test took 3926ms.
[10:19:27.301] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:19:28.023] INFO: Expecting 41600 events.
[10:19:31.266] INFO: 41600 events read in total (2716ms).
[10:19:31.267] INFO: Test took 3948ms.
[10:19:31.304] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:19:32.027] INFO: Expecting 41600 events.
[10:19:35.271] INFO: 41600 events read in total (2717ms).
[10:19:35.272] INFO: Test took 3949ms.
[10:19:35.308] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:19:36.027] INFO: Expecting 41600 events.
[10:19:39.282] INFO: 41600 events read in total (2728ms).
[10:19:39.283] INFO: Test took 3956ms.
[10:19:39.319] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:19:40.041] INFO: Expecting 41600 events.
[10:19:43.311] INFO: 41600 events read in total (2743ms).
[10:19:43.312] INFO: Test took 3974ms.
[10:19:43.348] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:19:44.065] INFO: Expecting 41600 events.
[10:19:47.324] INFO: 41600 events read in total (2732ms).
[10:19:47.325] INFO: Test took 3958ms.
[10:19:47.361] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:19:48.083] INFO: Expecting 41600 events.
[10:19:51.340] INFO: 41600 events read in total (2730ms).
[10:19:51.341] INFO: Test took 3963ms.
[10:19:51.377] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:19:52.097] INFO: Expecting 41600 events.
[10:19:55.372] INFO: 41600 events read in total (2748ms).
[10:19:55.373] INFO: Test took 3976ms.
[10:19:55.410] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:19:56.128] INFO: Expecting 41600 events.
[10:19:59.391] INFO: 41600 events read in total (2736ms).
[10:19:59.392] INFO: Test took 3963ms.
[10:19:59.427] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:20:00.145] INFO: Expecting 41600 events.
[10:20:03.413] INFO: 41600 events read in total (2741ms).
[10:20:03.414] INFO: Test took 3967ms.
[10:20:03.450] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:20:04.169] INFO: Expecting 41600 events.
[10:20:07.445] INFO: 41600 events read in total (2750ms).
[10:20:07.446] INFO: Test took 3978ms.
[10:20:07.482] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:20:08.203] INFO: Expecting 41600 events.
[10:20:11.467] INFO: 41600 events read in total (2737ms).
[10:20:11.468] INFO: Test took 3966ms.
[10:20:11.504] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:20:12.226] INFO: Expecting 41600 events.
[10:20:15.487] INFO: 41600 events read in total (2734ms).
[10:20:15.488] INFO: Test took 3965ms.
[10:20:15.524] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:20:16.246] INFO: Expecting 41600 events.
[10:20:19.509] INFO: 41600 events read in total (2737ms).
[10:20:19.510] INFO: Test took 3968ms.
[10:20:19.546] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:20:20.269] INFO: Expecting 41600 events.
[10:20:23.536] INFO: 41600 events read in total (2740ms).
[10:20:23.537] INFO: Test took 3972ms.
[10:20:23.572] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:20:24.293] INFO: Expecting 41600 events.
[10:20:27.558] INFO: 41600 events read in total (2738ms).
[10:20:27.559] INFO: Test took 3967ms.
[10:20:27.595] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:20:28.316] INFO: Expecting 41600 events.
[10:20:31.576] INFO: 41600 events read in total (2733ms).
[10:20:31.577] INFO: Test took 3962ms.
[10:20:31.612] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:20:32.333] INFO: Expecting 41600 events.
[10:20:35.588] INFO: 41600 events read in total (2729ms).
[10:20:35.589] INFO: Test took 3958ms.
[10:20:35.624] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:20:36.348] INFO: Expecting 41600 events.
[10:20:39.603] INFO: 41600 events read in total (2728ms).
[10:20:39.604] INFO: Test took 3961ms.
[10:20:39.640] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:20:40.359] INFO: Expecting 41600 events.
[10:20:43.452] INFO: 41600 events read in total (2566ms).
[10:20:43.453] INFO: Test took 3795ms.
[10:20:43.488] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:20:43.842] INFO: enter test to run
[10:20:49.743] INFO: test: HighRate no parameter change
[10:20:49.743] INFO: running: highrate
[10:20:49.744] INFO: ----------------------------------------------------------------------
[10:20:49.744] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:20:49.744] INFO: ----------------------------------------------------------------------
[10:20:50.350] INFO: Expecting 208000 events.
[10:21:02.334] INFO: 208000 events read in total (11457ms).
[10:21:02.337] INFO: Test took 12587ms.
[10:21:02.495] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:21:02.751] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 80 0 0 0 160 0 0 0 0
[10:21:02.751] INFO: number of red-efficiency pixels: 94 60 80 157 165 145 136 198 118 101 153 276 134 57 27 44
[10:21:02.751] INFO: number of X-ray hits detected: 73901 46271 70267 108826 122457 121797 116139 86060 92473 105223 106928 88023 95185 52913 23553 26946
[10:21:02.751] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:21:02.751] INFO: number of Vcal hits detected: 207903 207940 207917 207838 207830 207851 207862 203881 207881 207898 207843 199880 207865 207942 207973 207953
[10:21:02.751] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 100.0 100.0 100.0
[10:21:02.751] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 98.0 99.9 100.0 99.9 96.1 99.9 100.0 100.0 100.0
[10:21:02.751] INFO: X-ray hit rate [MHz/cm2]: 21.7 13.6 20.6 31.9 35.9 35.7 34.0 25.2 27.1 30.8 31.3 25.8 27.9 15.5 6.9 7.9
[10:21:02.751] INFO: PixTestHighRate::doXPixelAlive() done
[10:21:02.799] INFO: PixTest:: pg_setup set to default.
[10:21:02.815] INFO: enter test to run
[10:21:23.575] INFO: test: HighRate no parameter change
[10:21:23.575] INFO: running: highrate
[10:21:23.576] INFO: ----------------------------------------------------------------------
[10:21:23.576] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:21:23.576] INFO: ----------------------------------------------------------------------
[10:21:24.194] INFO: Expecting 208000 events.
[10:21:38.074] INFO: 208000 events read in total (13354ms).
[10:21:38.080] INFO: Test took 14494ms.
[10:21:38.404] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:21:38.710] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 80 0 0 0 160 0 0 0 0
[10:21:38.710] INFO: number of red-efficiency pixels: 274 159 294 487 664 516 436 478 367 328 454 552 439 164 53 75
[10:21:38.711] INFO: number of X-ray hits detected: 153170 95988 146524 226348 253319 253434 240906 181049 193486 218715 221454 181707 197463 111588 49583 56376
[10:21:38.711] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:21:38.711] INFO: number of Vcal hits detected: 207711 207827 207666 207460 207266 207437 207532 203561 207607 207641 207505 199580 207531 207826 207946 207921
[10:21:38.711] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.7 99.8 99.8 99.8 99.8 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[10:21:38.711] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.7 99.6 99.7 99.8 97.9 99.8 99.8 99.8 96.0 99.8 99.9 100.0 100.0
[10:21:38.711] INFO: X-ray hit rate [MHz/cm2]: 44.9 28.1 42.9 66.3 74.2 74.3 70.6 53.1 56.7 64.1 64.9 53.3 57.9 32.7 14.5 16.5
[10:21:38.711] INFO: PixTestHighRate::doXPixelAlive() done
[10:21:38.760] INFO: PixTest:: pg_setup set to default.
[10:21:38.772] INFO: enter test to run
[10:22:04.766] INFO: test: HighRate no parameter change
[10:22:04.766] INFO: running: highrate
[10:22:04.767] INFO: ----------------------------------------------------------------------
[10:22:04.767] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:22:04.767] INFO: ----------------------------------------------------------------------
[10:22:05.378] INFO: Expecting 208000 events.
[10:22:21.340] INFO: 208000 events read in total (15435ms).
[10:22:21.348] INFO: Test took 16572ms.
[10:22:21.848] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:22:22.211] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 80 0 0 0 160 0 0 0 0
[10:22:22.211] INFO: number of red-efficiency pixels: 618 346 664 1231 1503 1243 1003 1009 920 790 1118 1040 977 349 91 104
[10:22:22.211] INFO: number of X-ray hits detected: 233267 145955 222395 343048 383827 384674 365523 274371 294875 331492 335563 276465 301569 168662 75289 85998
[10:22:22.211] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:22:22.211] INFO: number of Vcal hits detected: 207246 207613 207089 206434 205939 206435 206742 202750 206833 207075 206570 198900 206802 207573 207905 207893
[10:22:22.212] INFO: Vcal hit fiducial efficiency (%): 99.7 99.8 99.6 99.3 99.1 99.3 99.5 99.4 99.5 99.6 99.4 99.5 99.5 99.8 100.0 100.0
[10:22:22.212] INFO: Vcal hit overall efficiency (%): 99.6 99.8 99.6 99.2 99.0 99.2 99.4 97.5 99.4 99.6 99.3 95.6 99.4 99.8 100.0 99.9
[10:22:22.212] INFO: X-ray hit rate [MHz/cm2]: 68.4 42.8 65.2 100.5 112.5 112.8 107.1 80.4 86.4 97.2 98.4 81.0 88.4 49.4 22.1 25.2
[10:22:22.212] INFO: PixTestHighRate::doXPixelAlive() done
[10:22:22.260] INFO: PixTest:: pg_setup set to default.
[10:22:22.273] INFO: enter test to run
[10:22:25.774] INFO: test: exit no parameter change
[10:22:26.144] QUIET: Connection to board 33 closed.
[10:22:26.146] INFO: pXar: this is the end, my friend