[13:37:57.363] INFO: *** Welcome to pxar ***
[13:37:57.363] INFO: *** Today: 2016/07/28
[13:37:57.394] INFO: *** Version: v1.9.0-818-g96727
[13:37:57.394] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-I-4-50_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-I-4-50_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//dacParameters35_C15.dat
[13:37:57.424] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-I-4-50_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-I-4-50_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//tbmParameters_C0b.dat
[13:37:57.424] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-I-4-50_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//defaultMaskFile.dat
[13:37:57.424] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-I-4-50_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-I-4-50_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C15.dat
[13:37:57.535] INFO: clk: 4
[13:37:57.535] INFO: ctr: 4
[13:37:57.535] INFO: sda: 19
[13:37:57.535] INFO: tin: 9
[13:37:57.535] INFO: level: 15
[13:37:57.535] INFO: triggerdelay: 0
[13:37:57.535] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[13:37:57.535] INFO: Log level: INFO
[13:37:57.553] QUIET: Connection to board DTB_WREKRL opened.
[13:37:57.556] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 33
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREKRL
MAC address: 40D855118021
Hostname: pixelDTB033
Comment:
------------------------------------------------------
[13:37:57.559] INFO: RPC call hashes of host and DTB match: 398089610
[13:37:59.088] INFO: DUT info:
[13:37:59.088] INFO: The DUT currently contains the following objects:
[13:37:59.088] INFO: 2 TBM Cores tbm08c (2 ON)
[13:37:59.089] INFO: TBM Core alpha (0): 7 registers set
[13:37:59.089] INFO: TBM Core beta (1): 7 registers set
[13:37:59.089] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[13:37:59.089] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[13:37:59.089] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[13:37:59.089] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[13:37:59.089] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[13:37:59.089] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[13:37:59.089] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[13:37:59.089] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[13:37:59.089] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[13:37:59.089] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[13:37:59.089] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[13:37:59.090] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[13:37:59.090] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[13:37:59.090] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[13:37:59.090] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[13:37:59.090] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[13:37:59.090] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[13:37:59.493] INFO: enter 'restricted' command line mode
[13:37:59.493] INFO: enter test to run
[13:38:25.839] INFO: test: PixelAlive no parameter change
[13:38:25.839] INFO: running: pixelalive
[13:38:25.848] INFO: ----------------------------------------------------------------------
[13:38:25.848] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[13:38:25.848] INFO: ----------------------------------------------------------------------
[13:38:26.167] INFO: Expecting 41600 events.
[13:38:30.497] INFO: 41600 events read in total (3611ms).
[13:38:30.665] INFO: Test took 4815ms.
[13:38:30.677] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:38:30.942] INFO: PixTestAlive::aliveTest() done
[13:38:30.942] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[13:38:30.971] INFO: enter test to run
[13:40:14.567] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[13:40:14.567] INFO: running: highrate
[13:40:14.567] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-I-4-50_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-I-4-50_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[13:40:14.870] INFO: ----------------------------------------------------------------------
[13:40:14.870] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[13:40:14.870] INFO: ----------------------------------------------------------------------
[13:40:14.870] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[13:40:14.870] INFO: edge/corner pixel THR is adjusted
[13:40:14.870] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:40:15.828] INFO: Collecting data for 5 seconds...
[13:40:20.848] INFO: Done with hot pixel readout
[13:40:32.612] INFO: PixTest:: pg_setup set to default.
[13:40:32.613] INFO: 3 hot pixels found in step 0
[13:40:33.601] INFO: Collecting data for 5 seconds...
[13:40:38.620] INFO: Done with hot pixel readout
[13:40:50.375] INFO: PixTest:: pg_setup set to default.
[13:40:50.376] INFO: 4 hot pixels found in step 1
[13:40:51.370] INFO: Collecting data for 5 seconds...
[13:40:56.388] INFO: Done with hot pixel readout
[13:41:07.543] INFO: PixTest:: pg_setup set to default.
[13:41:07.544] INFO: 5 hot pixels found in step 2
[13:41:08.536] INFO: Collecting data for 5 seconds...
[13:41:13.554] INFO: Done with hot pixel readout
[13:41:24.912] INFO: PixTest:: pg_setup set to default.
[13:41:24.913] INFO: 3 hot pixels found in step 3
[13:41:25.905] INFO: Collecting data for 5 seconds...
[13:41:30.923] INFO: Done with hot pixel readout
[13:41:42.469] INFO: PixTest:: pg_setup set to default.
[13:41:42.470] INFO: 6 hot pixels found in step 4
[13:41:43.462] INFO: Collecting data for 5 seconds...
[13:41:48.480] INFO: Done with hot pixel readout
[13:42:00.088] INFO: PixTest:: pg_setup set to default.
[13:42:00.089] INFO: 3 hot pixels found in step 5
[13:42:01.081] INFO: Collecting data for 5 seconds...
[13:42:06.101] INFO: Done with hot pixel readout
[13:42:18.026] INFO: PixTest:: pg_setup set to default.
[13:42:18.026] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:42:18.027] INFO: 3 hot pixels found in step 6
[13:42:19.019] INFO: Collecting data for 5 seconds...
[13:42:24.038] INFO: Done with hot pixel readout
[13:42:35.839] INFO: PixTest:: pg_setup set to default.
[13:42:35.840] INFO: 5 hot pixels found in step 7
[13:42:36.834] INFO: Collecting data for 5 seconds...
[13:42:41.854] INFO: Done with hot pixel readout
[13:42:53.570] INFO: PixTest:: pg_setup set to default.
[13:42:53.571] INFO: 4 hot pixels found in step 8
[13:42:54.564] INFO: Collecting data for 5 seconds...
[13:42:59.585] INFO: Done with hot pixel readout
[13:43:11.353] INFO: PixTest:: pg_setup set to default.
[13:43:11.354] INFO: 3 hot pixels found in step 9
[13:43:12.345] INFO: Collecting data for 5 seconds...
[13:43:17.366] INFO: Done with hot pixel readout
[13:43:29.210] INFO: PixTest:: pg_setup set to default.
[13:43:29.211] INFO: 6 hot pixels found in step 10
[13:43:30.204] INFO: Collecting data for 5 seconds...
[13:43:35.226] INFO: Done with hot pixel readout
[13:43:47.146] INFO: PixTest:: pg_setup set to default.
[13:43:47.147] INFO: 3 hot pixels found in step 11
[13:43:48.140] INFO: Collecting data for 5 seconds...
[13:43:53.161] INFO: Done with hot pixel readout
[13:44:04.889] INFO: PixTest:: pg_setup set to default.
[13:44:04.889] INFO: 3 hot pixels found in step 12
[13:44:05.882] INFO: Collecting data for 5 seconds...
[13:44:10.898] INFO: Done with hot pixel readout
[13:44:22.553] INFO: PixTest:: pg_setup set to default.
[13:44:22.554] INFO: 3 hot pixels found in step 13
[13:44:23.546] INFO: Collecting data for 5 seconds...
[13:44:28.563] INFO: Done with hot pixel readout
[13:44:40.190] INFO: PixTest:: pg_setup set to default.
[13:44:40.191] INFO: 5 hot pixels found in step 14
[13:44:40.227] INFO: 5 hot pixels could not be trimmed and have been masked.
[13:44:40.231] INFO: PixTest::trimHotPixels() done
[13:44:40.231] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-50_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C0.dat
[13:44:40.236] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-50_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C1.dat
[13:44:40.242] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-50_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C2.dat
[13:44:40.248] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-50_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C3.dat
[13:44:40.254] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-50_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C4.dat
[13:44:40.259] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-50_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C5.dat
[13:44:40.264] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-50_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C6.dat
[13:44:40.270] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-50_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C7.dat
[13:44:40.275] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-50_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C8.dat
[13:44:40.280] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-50_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C9.dat
[13:44:40.286] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-50_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C10.dat
[13:44:40.291] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-50_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C11.dat
[13:44:40.296] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-50_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C12.dat
[13:44:40.301] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-50_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C13.dat
[13:44:40.307] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-50_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C14.dat
[13:44:40.312] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-50_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C15.dat
[13:44:40.317] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-I-4-50_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//defaultMaskFile.dat
[13:44:40.328] INFO: enter test to run
[13:45:18.700] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[13:45:18.700] INFO: running: highrate
[13:45:18.705] INFO: ----------------------------------------------------------------------
[13:45:18.705] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[13:45:18.705] INFO: ----------------------------------------------------------------------
[13:45:18.705] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[13:45:18.705] INFO: edge/corner pixel THR is adjusted
[13:45:18.705] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:45:19.663] INFO: Collecting data for 1 seconds...
[13:45:20.667] INFO: Done with hot pixel readout
[13:45:24.622] INFO: PixTest:: pg_setup set to default.
[13:45:24.623] INFO: 0 hot pixels found in step 0
[13:45:24.629] INFO: 0 hot pixels could not be trimmed and have been masked.
[13:45:24.722] INFO: PixTest::trimHotPixels() done
[13:45:24.722] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-50_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C0.dat
[13:45:24.728] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-50_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C1.dat
[13:45:24.734] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-50_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C2.dat
[13:45:24.740] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-50_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C3.dat
[13:45:24.747] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-50_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C4.dat
[13:45:24.752] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-50_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C5.dat
[13:45:24.758] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-50_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C6.dat
[13:45:24.763] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-50_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C7.dat
[13:45:24.768] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-50_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C8.dat
[13:45:24.773] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-50_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C9.dat
[13:45:24.779] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-50_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C10.dat
[13:45:24.784] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-50_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C11.dat
[13:45:24.789] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-50_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C12.dat
[13:45:24.794] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-50_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C13.dat
[13:45:24.800] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-50_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C14.dat
[13:45:24.805] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-50_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//trimParameters35_C15.dat
[13:45:24.810] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-I-4-50_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//defaultMaskFile.dat
[13:45:24.820] INFO: enter test to run
[13:46:08.500] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[13:46:08.500] INFO: running: xray
[13:46:08.501] INFO: ----------------------------------------------------------------------
[13:46:08.501] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:46:08.501] INFO: ----------------------------------------------------------------------
[13:46:09.464] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:46:21.033] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[13:46:50.255] INFO: Resuming triggers.
[13:47:01.821] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[13:47:31.163] INFO: Resuming triggers.
[13:47:42.730] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[13:48:11.992] INFO: Resuming triggers.
[13:48:23.560] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[13:48:52.837] INFO: Resuming triggers.
[13:49:04.406] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[13:49:33.711] INFO: Resuming triggers.
[13:49:45.284] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[13:50:14.466] INFO: Resuming triggers.
[13:50:26.039] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[13:50:35.001] ERROR: <datapipe.cc/CheckEventValidity:L491> Channel 0 Number of ROCs (6) != Token Chain Length (8)
[13:50:35.001] ERROR: <datapipe.cc/CheckEventValidity:L480> Channel 1 has NoTokenPass but 6 ROCs were found
[13:50:35.001] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[13:50:35.001] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a054 80b1 43c8 43c8 253 2a40 43c8 43c8 43c8 43c8 43c8 208 2a46 43c8 695 2641 e000 c000
[13:50:35.001] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a04e 8000 4388 4388 4388 4388 4388 4388 4388 4388 1c 204f e000 c000
[13:50:35.001] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a04f 8040 438a 35c 242d 438a 344 222d 438a 851 222f 438a 438a 818 2867 438a 99 2845 711 2a4f 438a 438a 11a 2a4a e000 c000
[13:50:35.001] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a050 80b1 4388 4388 4388 4388 4388 4388 514 2440 80b 2047 811 2a49 4388 15a 2a4d 4388 e000 c000
[13:50:35.001] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a051 80c0 4388 4388 55c 2a2d 4388 4388 10d 244f 421 2849 4389 121c 3a42 34b 2815 153f 253d 3cf 2300 809 43c9 540 242d 43c9 1b 2041 e000 c000
[13:50:35.001] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a052 8000 43c8 21 2a61 43c8 43c9 43c9 54c 2029 43c8 43c8 43c9 50c 2a28 43c9 360 2460 45a 284d e000 c000
[13:50:35.001] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a053 8040 43c8 43c9 43c8 43c9 43c8 43c9 459 2641 43c8 30a 2842 319 2a41 43c9 e000 c000
[13:50:35.001] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[13:50:35.001] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a154 80b1 43c8 45a 204f 43c8 43c8 43c8 821 2065 43c8 402 222a 43c8 43c8 43c8 e000 c000
[13:50:35.002] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a14e 8000 4388 4388 108 282f 4388 682 262c 4388 4388 4388 4388 4388 e000 c000
[13:50:35.002] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a14f 8040 438a 610 2a42 438a 438a 14c 2645 438a 438a 438a 412 242f 438a 438a e000 c000
[13:50:35.002] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a150 80b1 4389 4389 4389 4389 4389 4389 4389 4389 e000 c000
[13:50:35.002] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a151 80c0 4388 761 244f 4388 4388 6cd 284c 6ca 2645 4388 43c9 171b 3849 43c9 7e0 3a80 e0fa c0af
[13:50:35.002] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a152 8000 43c8 43c8 43c9 403 2043 43c9 43c8 11c 2640 43c8 43c9 43c9 e000 c000
[13:50:35.002] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a153 8040 43c8 292 222d 54c 284f 43c9 43c8 43c9 600 242f 43c8 43c9 15c 2029 43c8 43c9 e000 c000
[13:50:37.150] ERROR: <datapipe.cc/CheckEventValidity:L480> Channel 0 has NoTokenPass but 8 ROCs were found
[13:50:37.151] ERROR: <datapipe.cc/CheckEventValidity:L480> Channel 1 has NoTokenPass but 7 ROCs were found
[13:50:37.151] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[13:50:37.151] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a01a 8000 43c8 43c8 43c8 43c8 43c8 340 262f 43c8 43c8 651 2828 43c8 445 284f e000 c000
[13:50:37.151] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a014 80b1 4388 4388 253 2445 4388 4388 4388 852 2469 4388 4388 4388 e000 c000
[13:50:37.151] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a015 80c0 4388 4388 4388 4388 4388 4388 c2 2644 4388 6d3 2849 4388 e000 c000
[13:50:37.151] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a016 8000 4388 4388 4388 4388 4388 4388 4388 484 2a4a 4c5 2a2f 4388 e000 c000
[13:50:37.151] ERROR: <datapipe.cc/Read:L166> ====== 2 ====== a017 8040 4388 853 224c 4388 4388 4388 4388 4388 549 244f 43c8 43c8 683 293e ffe 2000 ff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff
[13:50:37.151] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a018 80b1 43c8 50 2a4d 43c8 43c8 43c8 99 2844 43c8 10b 224c 43c8 43c8 43c8 e000 c000
[13:50:37.151] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a019 80c0 43c8 43c8 43c8 43c8 43c8 43c8 43c8 144 2427 43c8 e000 c000
[13:50:37.151] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[13:50:37.151] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a11a 8000 43c8 43c8 21 2262 43c8 85b 282d 43c8 75c 2041 43c8 20 242c 241 2043 43c8 43c8 43c8 e000 c000
[13:50:37.151] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a114 80b1 4388 4388 4388 14d 264e 349 284a 349 2442 4388 718 222f 4388 4388 4388 4388 e000 c000
[13:50:37.151] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a115 80c0 4388 4388 6cc 202f 4388 344 2641 4388 4388 b 242d 549 264c 4388 4388 4388 e000 c000
[13:50:37.151] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a116 8000 4388 4388 4388 4388 60c 2443 4388 4388 4388 4388 e000 c000
[13:50:37.151] ERROR: <datapipe.cc/Read:L166> ====== 2 ====== a117 8040 4388 800 244d 4388 4388 4388 65a 2a45 4388 81d 2443 43c8 43c8 680 207c 0 21ff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff 2fff fff
[13:50:37.151] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a118 80b1 43c8 43c8 43c8 b 2263 70b 284d 43c8 d 224d 242 2049 43c8 64a 2647 43c8 43c8 43c8 e000 c000
[13:50:37.151] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a119 80c0 43c8 40d 2a46 454 2068 43c8 850 224f 43c8 43c8 348 2a43 43c8 43c8 43c8 43c8 e000 c000
[13:50:40.656] ERROR: <datapipe.cc/CheckEventValidity:L491> Channel 1 Number of ROCs (7) != Token Chain Length (8)
[13:50:40.657] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[13:50:40.657] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a06c 80b1 43c8 43c8 2d4 2426 43c8 43c8 210 2245 43c8 43c8 43c8 151 262c 2cc 2241 81b 284d 43c8 d0 2a40 688 242c e000 c000
[13:50:40.657] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a066 8000 4388 4388 2d4 2421 4388 4388 4388 93 2049 4388 4388 4388 e000 c000
[13:50:40.657] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a067 8040 4388 4388 2d9 2623 4388 4388 4388 4388 40c 202c 4388 4388 480 2447 e000 c000
[13:50:40.657] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a068 80b1 4388 4388 2d4 284c 4388 4388 4388 4388 4388 4388 94 202d e000 c000
[13:50:40.657] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a069 80c0 4388 4388 4388 4388 4388 43c8 43c8 53c8 e01f c0bf
[13:50:40.657] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a06a 8000 43c8 43c8 43c8 43c8 43c8 43c8 43c8 68b 206b 43c8 701 262f e000 c000
[13:50:40.657] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a06b 8040 43c8 43c8 43c8 a1 2641 43c8 29c 2a2c 808 224e 43c8 43c8 752 2647 43c8 43c8 e000 c000
[13:50:40.657] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[13:50:40.657] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a16c 80b1 43c8 6e1 2660 43c8 43c8 43c8 43c8 43c8 43c8 43c8 e000 c000
[13:50:40.657] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a166 8000 4388 4388 50 2a2a 115 224e 24b 244e 4388 4388 4388 4388 4388 4388 e000 c000
[13:50:40.657] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a167 8040 4388 809 2064 4388 30b 264c 4388 4388 4388 58 2065 4388 4388 4388 e000 c000
[13:50:40.657] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a168 80b1 4388 605 2048 4388 4388 80a 2244 4388 4388 11c 242d 11c 262f 4388 4388 4388 e000 c000
[13:50:40.657] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a169 80c0 4388 4d8 2a46 4388 858 2263 43c8 53c8 53c8 43c8 2260 2 43c8 e000 c000
[13:50:40.657] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a16a 8000 43c8 43c8 43c8 43c8 43c8 118 2642 4e0 2645 43c8 43c8 43c8 e000 c000
[13:50:40.657] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a16b 8040 43c8 43c8 20a 2044 43c8 43c8 43c8 43c8 43c8 43c8 e000 c000
[13:50:55.471] INFO: Resuming triggers.
[13:51:07.039] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[13:51:36.464] INFO: Resuming triggers.
[13:51:44.238] INFO: data taking finished, elapsed time: 100 seconds.
[13:52:04.478] INFO: PixTest:: pg_setup set to default.
[13:52:04.481] INFO: PixTestXray::doPhRun() done
[13:52:04.626] INFO: enter test to run
[13:52:47.273] INFO: test: timing no parameter change
[13:52:47.273] INFO: running: timing
[13:52:47.277] INFO: ######################################################################
[13:52:47.289] INFO: PixTestTiming::doTest()
[13:52:47.289] INFO: ######################################################################
[13:52:47.290] INFO: ----------------------------------------------------------------------
[13:52:47.290] INFO: PixTestTiming::TBMPhaseScan()
[13:52:47.290] INFO: ----------------------------------------------------------------------
[13:57:17.094] INFO: TBM Phase Settings: 236
[13:57:17.094] INFO: 400MHz Phase: 3
[13:57:17.094] INFO: 160MHz Phase: 7
[13:57:17.094] INFO: Functional Phase Area: 4
[13:57:17.097] INFO: Test took 269808 ms.
[13:57:17.097] INFO: PixTestTiming::TBMPhaseScan() done.
[13:57:17.097] INFO: ----------------------------------------------------------------------
[13:57:17.098] INFO: PixTestTiming::ROCDelayScan()
[13:57:17.098] INFO: ----------------------------------------------------------------------
[14:01:06.526] INFO: ROC Delay Settings: 228
[14:01:06.526] INFO: ROC Header-Trailer/Token Delay: 11
[14:01:06.526] INFO: ROC Port 0 Delay: 4
[14:01:06.526] INFO: ROC Port 1 Delay: 4
[14:01:06.526] INFO: Functional ROC Area: 5
[14:01:06.529] INFO: Test took 229432 ms.
[14:01:06.529] INFO: PixTestTiming::ROCDelayScan() done.
[14:01:06.530] INFO: ----------------------------------------------------------------------
[14:01:06.530] INFO: PixTestTiming::TimingTest()
[14:01:06.530] INFO: ----------------------------------------------------------------------
[14:01:22.638] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:01:37.601] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:01:52.544] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:02:07.506] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:02:22.460] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:02:37.408] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:02:52.387] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:03:07.371] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:03:22.355] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:03:37.330] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:03:37.711] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:03:37.725] INFO: ----------------------------------------------------------------------
[14:03:37.725] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[14:03:37.725] INFO: ----------------------------------------------------------------------
[14:03:37.725] INFO: ----------------------------------------------------------------------
[14:03:37.725] INFO: Read back bit status: 1
[14:03:37.725] INFO: ----------------------------------------------------------------------
[14:03:37.725] INFO: ----------------------------------------------------------------------
[14:03:37.725] INFO: Timings are good!
[14:03:37.725] INFO: ----------------------------------------------------------------------
[14:03:37.725] INFO: Test took 151196 ms.
[14:03:37.725] INFO: PixTestTiming::TimingTest() done.
[14:03:37.725] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-50_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//tbmParameters_C0a.dat
[14:03:37.725] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-50_FPIXTest-17C-FNAL-160718-1222_2016-07-18_12h22m_1468862529/000_FPIXTest_p17//tbmParameters_C0b.dat
[14:03:37.726] INFO: PixTestTiming::doTest took 650453 ms.
[14:03:37.726] INFO: PixTestTiming::doTest() done
[14:03:37.726] INFO: Write out TBMPhaseScan_0_V0
[14:03:37.726] INFO: Write out TBMPhaseScan_1_V0
[14:03:37.726] INFO: Write out CombinedTBMPhaseScan_V0
[14:03:37.728] INFO: Write out ROCDelayScan3_V0
[14:03:37.729] INFO: enter test to run
[14:05:10.348] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[14:05:10.348] INFO: running: xray
[14:05:10.349] INFO: ----------------------------------------------------------------------
[14:05:10.349] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:05:10.349] INFO: ----------------------------------------------------------------------
[14:05:11.314] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:05:22.878] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[14:05:51.481] INFO: Resuming triggers.
[14:06:03.043] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[14:06:32.966] INFO: Resuming triggers.
[14:06:44.528] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[14:07:14.764] INFO: Resuming triggers.
[14:07:26.326] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[14:07:56.500] INFO: Resuming triggers.
[14:08:08.066] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[14:08:36.612] INFO: Resuming triggers.
[14:08:48.179] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[14:09:17.513] INFO: Resuming triggers.
[14:09:29.076] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[14:09:58.400] INFO: Resuming triggers.
[14:10:09.963] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[14:10:39.477] INFO: Resuming triggers.
[14:10:47.332] INFO: data taking finished, elapsed time: 100 seconds.
[14:11:07.394] INFO: PixTest:: pg_setup set to default.
[14:11:07.398] INFO: PixTestXray::doPhRun() done
[14:11:07.531] INFO: enter test to run
[14:12:04.417] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[14:12:04.417] INFO: running: xray
[14:12:04.419] INFO: ----------------------------------------------------------------------
[14:12:04.419] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:12:04.419] INFO: ----------------------------------------------------------------------
[14:12:05.392] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:12:12.321] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[14:12:42.413] INFO: Resuming triggers.
[14:12:49.347] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[14:13:19.373] INFO: Resuming triggers.
[14:13:26.302] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[14:13:56.386] INFO: Resuming triggers.
[14:14:03.316] INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[14:14:33.420] INFO: Resuming triggers.
[14:14:40.353] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[14:15:10.313] INFO: Resuming triggers.
[14:15:17.243] INFO: run duration 41 seconds, buffer almost full (81%), pausing triggers.
[14:15:47.367] INFO: Resuming triggers.
[14:15:54.298] INFO: run duration 48 seconds, buffer almost full (81%), pausing triggers.
[14:16:25.136] INFO: Resuming triggers.
[14:16:32.068] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[14:17:02.833] INFO: Resuming triggers.
[14:17:09.768] INFO: run duration 62 seconds, buffer almost full (81%), pausing triggers.
[14:17:40.137] INFO: Resuming triggers.
[14:17:47.073] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[14:18:17.496] INFO: Resuming triggers.
[14:18:24.427] INFO: run duration 75 seconds, buffer almost full (81%), pausing triggers.
[14:18:55.000] INFO: Resuming triggers.
[14:19:02.932] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[14:19:33.815] INFO: Resuming triggers.
[14:19:40.740] INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[14:20:11.209] INFO: Resuming triggers.
[14:20:18.136] INFO: run duration 96 seconds, buffer almost full (81%), pausing triggers.
[14:20:48.241] INFO: Resuming triggers.
[14:20:51.563] INFO: data taking finished, elapsed time: 100 seconds.
[14:21:06.434] INFO: PixTest:: pg_setup set to default.
[14:21:06.438] INFO: PixTestXray::doPhRun() done
[14:21:06.587] INFO: enter test to run
[14:21:53.333] INFO: test: HighRate no parameter change
[14:21:53.334] INFO: running: highrate
[14:21:53.348] INFO: ----------------------------------------------------------------------
[14:21:53.349] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[14:21:53.349] INFO: ----------------------------------------------------------------------
[14:21:53.503] INFO: Expecting 768 events.
[14:21:54.633] INFO: 768 events read in total (415ms).
[14:21:54.633] INFO: Test took 1264ms.
[14:21:55.436] INFO: Expecting 41600 events.
[14:21:58.535] INFO: 41600 events read in total (2572ms).
[14:21:58.536] INFO: Test took 3897ms.
[14:21:58.569] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:21:59.299] INFO: Expecting 41600 events.
[14:22:02.504] INFO: 41600 events read in total (2678ms).
[14:22:02.505] INFO: Test took 3918ms.
[14:22:02.539] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:22:03.261] INFO: Expecting 41600 events.
[14:22:06.503] INFO: 41600 events read in total (2715ms).
[14:22:06.504] INFO: Test took 3947ms.
[14:22:06.538] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:22:07.264] INFO: Expecting 41600 events.
[14:22:10.502] INFO: 41600 events read in total (2711ms).
[14:22:10.503] INFO: Test took 3947ms.
[14:22:10.536] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:22:11.263] INFO: Expecting 41600 events.
[14:22:14.508] INFO: 41600 events read in total (2718ms).
[14:22:14.509] INFO: Test took 3954ms.
[14:22:14.542] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:22:15.267] INFO: Expecting 41600 events.
[14:22:18.503] INFO: 41600 events read in total (2709ms).
[14:22:18.504] INFO: Test took 3943ms.
[14:22:18.536] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:22:19.260] INFO: Expecting 41600 events.
[14:22:22.499] INFO: 41600 events read in total (2712ms).
[14:22:22.500] INFO: Test took 3945ms.
[14:22:22.533] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:22:23.259] INFO: Expecting 41600 events.
[14:22:26.519] INFO: 41600 events read in total (2733ms).
[14:22:26.520] INFO: Test took 3970ms.
[14:22:26.553] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:22:27.278] INFO: Expecting 41600 events.
[14:22:30.526] INFO: 41600 events read in total (2721ms).
[14:22:30.527] INFO: Test took 3956ms.
[14:22:30.559] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:22:31.285] INFO: Expecting 41600 events.
[14:22:34.525] INFO: 41600 events read in total (2714ms).
[14:22:34.526] INFO: Test took 3949ms.
[14:22:34.559] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:22:35.287] INFO: Expecting 41600 events.
[14:22:38.542] INFO: 41600 events read in total (2728ms).
[14:22:38.543] INFO: Test took 3967ms.
[14:22:38.576] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:22:39.300] INFO: Expecting 41600 events.
[14:22:42.549] INFO: 41600 events read in total (2722ms).
[14:22:42.550] INFO: Test took 3955ms.
[14:22:42.583] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:22:43.306] INFO: Expecting 41600 events.
[14:22:46.549] INFO: 41600 events read in total (2716ms).
[14:22:46.550] INFO: Test took 3950ms.
[14:22:46.584] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:22:47.311] INFO: Expecting 41600 events.
[14:22:50.568] INFO: 41600 events read in total (2730ms).
[14:22:50.568] INFO: Test took 3966ms.
[14:22:50.602] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:22:51.327] INFO: Expecting 41600 events.
[14:22:54.526] INFO: 41600 events read in total (2673ms).
[14:22:54.527] INFO: Test took 3906ms.
[14:22:54.561] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:22:55.284] INFO: Expecting 41600 events.
[14:22:58.525] INFO: 41600 events read in total (2714ms).
[14:22:58.526] INFO: Test took 3947ms.
[14:22:58.559] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:22:59.286] INFO: Expecting 41600 events.
[14:23:02.532] INFO: 41600 events read in total (2719ms).
[14:23:02.533] INFO: Test took 3957ms.
[14:23:02.566] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:03.293] INFO: Expecting 41600 events.
[14:23:06.550] INFO: 41600 events read in total (2730ms).
[14:23:06.551] INFO: Test took 3966ms.
[14:23:06.583] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:07.308] INFO: Expecting 41600 events.
[14:23:10.547] INFO: 41600 events read in total (2712ms).
[14:23:10.548] INFO: Test took 3946ms.
[14:23:10.581] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:11.308] INFO: Expecting 41600 events.
[14:23:14.388] INFO: 41600 events read in total (2553ms).
[14:23:14.389] INFO: Test took 3789ms.
[14:23:14.422] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:14.786] INFO: enter test to run
[14:23:37.901] INFO: test: HighRate no parameter change
[14:23:37.901] INFO: running: highrate
[14:23:37.902] INFO: ----------------------------------------------------------------------
[14:23:37.902] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:23:37.902] INFO: ----------------------------------------------------------------------
[14:23:38.517] INFO: Expecting 208000 events.
[14:23:50.299] INFO: 208000 events read in total (11255ms).
[14:23:50.302] INFO: Test took 12388ms.
[14:23:50.443] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:50.693] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:23:50.693] INFO: number of red-efficiency pixels: 54 53 72 124 130 127 130 98 88 84 103 100 98 57 31 29
[14:23:50.693] INFO: number of X-ray hits detected: 66371 42434 65297 104061 108558 112338 112113 83956 78247 89828 88383 78615 80754 46376 22337 25697
[14:23:50.693] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:23:50.693] INFO: number of Vcal hits detected: 207945 207946 207928 207873 207870 207871 207867 207893 207911 207915 207896 207898 207899 207942 207969 207971
[14:23:50.693] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0
[14:23:50.693] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0
[14:23:50.693] INFO: X-ray hit rate [MHz/cm2]: 19.5 12.4 19.1 30.5 31.8 32.9 32.9 24.6 22.9 26.3 25.9 23.0 23.7 13.6 6.5 7.5
[14:23:50.693] INFO: PixTestHighRate::doXPixelAlive() done
[14:23:50.743] INFO: PixTest:: pg_setup set to default.
[14:23:50.760] INFO: enter test to run
[14:24:34.948] INFO: test: HighRate no parameter change
[14:24:34.948] INFO: running: highrate
[14:24:34.950] INFO: ----------------------------------------------------------------------
[14:24:34.950] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:24:34.950] INFO: ----------------------------------------------------------------------
[14:24:35.565] INFO: Expecting 208000 events.
[14:24:48.994] INFO: 208000 events read in total (12902ms).
[14:24:48.999] INFO: Test took 14037ms.
[14:24:49.280] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:24:49.578] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:24:49.578] INFO: number of red-efficiency pixels: 197 135 223 474 405 375 434 268 213 275 246 263 236 152 63 60
[14:24:49.578] INFO: number of X-ray hits detected: 134419 86366 133414 212219 219561 228589 227729 171685 159505 182944 180226 159588 165720 94329 45710 52555
[14:24:49.578] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:24:49.578] INFO: number of Vcal hits detected: 207786 207858 207761 207481 207565 207602 207533 207694 207776 207712 207747 207720 207757 207840 207937 207940
[14:24:49.579] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.8 99.8 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0
[14:24:49.579] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.8 99.8 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0
[14:24:49.579] INFO: X-ray hit rate [MHz/cm2]: 39.4 25.3 39.1 62.2 64.4 67.0 66.7 50.3 46.8 53.6 52.8 46.8 48.6 27.6 13.4 15.4
[14:24:49.579] INFO: PixTestHighRate::doXPixelAlive() done
[14:24:49.629] INFO: PixTest:: pg_setup set to default.
[14:24:49.647] INFO: enter test to run
[14:25:21.060] INFO: test: HighRate no parameter change
[14:25:21.060] INFO: running: highrate
[14:25:21.061] INFO: ----------------------------------------------------------------------
[14:25:21.061] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:25:21.061] INFO: ----------------------------------------------------------------------
[14:25:21.678] INFO: Expecting 208000 events.
[14:25:36.788] INFO: 208000 events read in total (14583ms).
[14:25:36.795] INFO: Test took 15722ms.
[14:25:37.231] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:25:37.573] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:25:37.573] INFO: number of red-efficiency pixels: 391 234 492 1063 904 892 978 551 404 571 546 583 500 288 86 91
[14:25:37.573] INFO: number of X-ray hits detected: 202511 129800 198898 317492 329466 341786 340964 258118 240036 273872 269899 239681 249094 142502 68186 78884
[14:25:37.573] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:25:37.573] INFO: number of Vcal hits detected: 207545 207744 207407 206716 206905 206936 206779 207324 207571 207383 207399 207324 207460 207683 207911 207906
[14:25:37.573] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.8 99.4 99.5 99.5 99.5 99.7 99.8 99.7 99.7 99.7 99.8 99.9 100.0 100.0
[14:25:37.573] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.7 99.4 99.5 99.5 99.4 99.7 99.8 99.7 99.7 99.7 99.7 99.8 100.0 100.0
[14:25:37.573] INFO: X-ray hit rate [MHz/cm2]: 59.4 38.0 58.3 93.1 96.6 100.2 99.9 75.7 70.4 80.3 79.1 70.3 73.0 41.8 20.0 23.1
[14:25:37.573] INFO: PixTestHighRate::doXPixelAlive() done
[14:25:37.623] INFO: PixTest:: pg_setup set to default.
[14:25:37.639] INFO: enter test to run
[14:25:51.396] INFO: test: exit no parameter change
[14:25:51.723] QUIET: Connection to board 33 closed.
[14:25:51.735] INFO: pXar: this is the end, my friend