[15:40:09.696] INFO: *** Welcome to pxar ***
[15:40:09.696] INFO: *** Today: 2016/09/09
[15:40:10.514] INFO: *** Version: v1.9.0-818-g96727
[15:40:10.514] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-3-42_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-3-42_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//dacParameters35_C15.dat
[15:40:10.539] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-3-42_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-3-42_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//tbmParameters_C0b.dat
[15:40:10.539] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-3-42_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//defaultMaskFile.dat
[15:40:10.546] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-3-42_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-3-42_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C15.dat
[15:40:10.641] INFO: clk: 4
[15:40:10.641] INFO: ctr: 4
[15:40:10.641] INFO: sda: 19
[15:40:10.641] INFO: tin: 9
[15:40:10.641] INFO: level: 15
[15:40:10.641] INFO: triggerdelay: 0
[15:40:10.641] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[15:40:10.641] INFO: Log level: INFO
[15:40:10.680] QUIET: Connection to board DTB_WREKRL opened.
[15:40:10.683] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 33
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREKRL
MAC address: 40D855118021
Hostname: pixelDTB033
Comment:
------------------------------------------------------
[15:40:10.686] INFO: RPC call hashes of host and DTB match: 398089610
[15:40:12.217] INFO: DUT info:
[15:40:12.217] INFO: The DUT currently contains the following objects:
[15:40:12.217] INFO: 2 TBM Cores tbm08c (2 ON)
[15:40:12.217] INFO: TBM Core alpha (0): 7 registers set
[15:40:12.217] INFO: TBM Core beta (1): 7 registers set
[15:40:12.217] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[15:40:12.217] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[15:40:12.217] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[15:40:12.217] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[15:40:12.217] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[15:40:12.217] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[15:40:12.217] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[15:40:12.217] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[15:40:12.217] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[15:40:12.217] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[15:40:12.217] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[15:40:12.217] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[15:40:12.217] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[15:40:12.217] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[15:40:12.217] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[15:40:12.217] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[15:40:12.217] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[15:40:12.637] INFO: enter 'restricted' command line mode
[15:40:12.637] INFO: enter test to run
[15:40:28.513] INFO: test: PixelAlive no parameter change
[15:40:28.513] INFO: running: pixelalive
[15:40:28.536] INFO: ----------------------------------------------------------------------
[15:40:28.536] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[15:40:28.536] INFO: ----------------------------------------------------------------------
[15:40:28.857] INFO: Expecting 41600 events.
[15:40:33.190] INFO: 41600 events read in total (3614ms).
[15:40:33.361] INFO: Test took 4821ms.
[15:40:33.374] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:40:33.638] INFO: PixTestAlive::aliveTest() done
[15:40:33.638] INFO: number of dead pixels (per ROC): 0 0 0 0 1 0 0 0 1 0 0 0 0 0 0 0
[15:40:33.688] INFO: enter test to run
[15:41:22.625] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[15:41:22.625] INFO: running: highrate
[15:41:22.634] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-3-42_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-3-42_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[15:41:22.923] INFO: ----------------------------------------------------------------------
[15:41:22.923] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[15:41:22.924] INFO: ----------------------------------------------------------------------
[15:41:22.924] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[15:41:22.924] INFO: edge/corner pixel THR is adjusted
[15:41:22.924] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:41:23.882] INFO: Collecting data for 5 seconds...
[15:41:28.900] INFO: Done with hot pixel readout
[15:41:40.625] INFO: PixTest:: pg_setup set to default.
[15:41:40.626] INFO: 22 hot pixels found in step 0
[15:41:41.617] INFO: Collecting data for 5 seconds...
[15:41:46.634] INFO: Done with hot pixel readout
[15:41:58.448] INFO: PixTest:: pg_setup set to default.
[15:41:58.449] INFO: 21 hot pixels found in step 1
[15:41:59.445] INFO: Collecting data for 5 seconds...
[15:42:04.462] INFO: Done with hot pixel readout
[15:42:16.284] INFO: PixTest:: pg_setup set to default.
[15:42:16.284] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:42:16.285] INFO: 20 hot pixels found in step 2
[15:42:17.279] INFO: Collecting data for 5 seconds...
[15:42:22.295] INFO: Done with hot pixel readout
[15:42:34.143] INFO: PixTest:: pg_setup set to default.
[15:42:34.143] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:42:34.144] INFO: 15 hot pixels found in step 3
[15:42:35.138] INFO: Collecting data for 5 seconds...
[15:42:40.155] INFO: Done with hot pixel readout
[15:42:52.043] INFO: PixTest:: pg_setup set to default.
[15:42:52.043] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:42:52.044] INFO: 17 hot pixels found in step 4
[15:42:53.037] INFO: Collecting data for 5 seconds...
[15:42:58.054] INFO: Done with hot pixel readout
[15:43:09.926] INFO: PixTest:: pg_setup set to default.
[15:43:09.926] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:43:09.927] INFO: 12 hot pixels found in step 5
[15:43:10.920] INFO: Collecting data for 5 seconds...
[15:43:15.938] INFO: Done with hot pixel readout
[15:43:27.783] INFO: PixTest:: pg_setup set to default.
[15:43:27.783] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:43:27.784] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:43:27.784] INFO: 13 hot pixels found in step 6
[15:43:28.778] INFO: Collecting data for 5 seconds...
[15:43:33.796] INFO: Done with hot pixel readout
[15:43:45.648] INFO: PixTest:: pg_setup set to default.
[15:43:45.648] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:43:45.649] INFO: 12 hot pixels found in step 7
[15:43:46.642] INFO: Collecting data for 5 seconds...
[15:43:51.659] INFO: Done with hot pixel readout
[15:44:03.560] INFO: PixTest:: pg_setup set to default.
[15:44:03.560] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:44:03.561] INFO: 5 hot pixels found in step 8
[15:44:04.555] INFO: Collecting data for 5 seconds...
[15:44:09.571] INFO: Done with hot pixel readout
[15:44:21.440] INFO: PixTest:: pg_setup set to default.
[15:44:21.440] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:44:21.441] INFO: 7 hot pixels found in step 9
[15:44:22.434] INFO: Collecting data for 5 seconds...
[15:44:27.450] INFO: Done with hot pixel readout
[15:44:39.290] INFO: PixTest:: pg_setup set to default.
[15:44:39.291] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:44:39.291] INFO: 3 hot pixels found in step 10
[15:44:40.285] INFO: Collecting data for 5 seconds...
[15:44:45.302] INFO: Done with hot pixel readout
[15:44:57.167] INFO: PixTest:: pg_setup set to default.
[15:44:57.167] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:44:57.168] INFO: 4 hot pixels found in step 11
[15:44:58.162] INFO: Collecting data for 5 seconds...
[15:45:03.180] INFO: Done with hot pixel readout
[15:45:15.048] INFO: PixTest:: pg_setup set to default.
[15:45:15.048] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:45:15.049] INFO: 2 hot pixels found in step 12
[15:45:16.043] INFO: Collecting data for 5 seconds...
[15:45:21.060] INFO: Done with hot pixel readout
[15:45:32.650] INFO: PixTest:: pg_setup set to default.
[15:45:32.650] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:45:32.651] INFO: 7 hot pixels found in step 13
[15:45:33.644] INFO: Collecting data for 5 seconds...
[15:45:38.662] INFO: Done with hot pixel readout
[15:45:50.602] INFO: PixTest:: pg_setup set to default.
[15:45:50.602] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:45:50.603] INFO: 5 hot pixels found in step 14
[15:45:50.641] INFO: 5 hot pixels could not be trimmed and have been masked.
[15:45:50.644] INFO: PixTest::trimHotPixels() done
[15:45:50.644] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-42_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C0.dat
[15:45:50.671] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-42_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C1.dat
[15:45:50.685] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-42_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C2.dat
[15:45:50.694] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-42_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C3.dat
[15:45:50.699] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-42_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C4.dat
[15:45:50.705] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-42_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C5.dat
[15:45:50.711] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-42_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C6.dat
[15:45:50.717] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-42_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C7.dat
[15:45:50.722] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-42_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C8.dat
[15:45:50.728] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-42_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C9.dat
[15:45:50.734] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-42_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C10.dat
[15:45:50.740] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-42_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C11.dat
[15:45:50.745] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-42_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C12.dat
[15:45:50.751] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-42_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C13.dat
[15:45:50.756] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-42_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C14.dat
[15:45:50.762] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-42_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C15.dat
[15:45:50.767] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-3-42_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//defaultMaskFile.dat
[15:45:50.781] INFO: enter test to run
[15:46:32.783] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[15:46:32.783] INFO: running: highrate
[15:46:32.787] INFO: ----------------------------------------------------------------------
[15:46:32.788] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[15:46:32.788] INFO: ----------------------------------------------------------------------
[15:46:32.788] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[15:46:32.788] INFO: edge/corner pixel THR is adjusted
[15:46:32.788] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:46:33.745] INFO: Collecting data for 1 seconds...
[15:46:34.749] INFO: Done with hot pixel readout
[15:46:38.820] INFO: PixTest:: pg_setup set to default.
[15:46:38.821] INFO: 0 hot pixels found in step 0
[15:46:38.826] INFO: 0 hot pixels could not be trimmed and have been masked.
[15:46:38.907] INFO: PixTest::trimHotPixels() done
[15:46:38.907] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-42_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C0.dat
[15:46:38.915] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-42_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C1.dat
[15:46:38.923] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-42_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C2.dat
[15:46:38.929] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-42_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C3.dat
[15:46:38.934] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-42_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C4.dat
[15:46:38.940] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-42_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C5.dat
[15:46:38.945] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-42_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C6.dat
[15:46:38.950] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-42_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C7.dat
[15:46:38.956] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-42_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C8.dat
[15:46:38.961] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-42_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C9.dat
[15:46:38.967] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-42_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C10.dat
[15:46:38.972] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-42_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C11.dat
[15:46:38.977] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-42_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C12.dat
[15:46:38.983] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-42_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C13.dat
[15:46:38.988] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-42_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C14.dat
[15:46:38.994] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-42_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//trimParameters35_C15.dat
[15:46:38.999] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-3-42_FPIXTest-17C-FNAL-160907-1223-150V_2016-09-07_12h23m_1473269026/000_FPIXTest_p17//defaultMaskFile.dat
[15:46:39.010] INFO: enter test to run
[15:47:03.063] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[15:47:03.063] INFO: running: xray
[15:47:03.064] INFO: ----------------------------------------------------------------------
[15:47:03.064] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:47:03.064] INFO: ----------------------------------------------------------------------
[15:47:04.027] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:47:15.280] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[15:47:45.192] INFO: Resuming triggers.
[15:47:56.441] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[15:48:00.531] ERROR: <datapipe.cc/CheckEventValidity:L491> Channel 0 Number of ROCs (4) != Token Chain Length (8)
[15:48:00.531] ERROR: <datapipe.cc/CheckEventValidity:L491> Channel 1 Number of ROCs (6) != Token Chain Length (8)
[15:48:00.531] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[15:48:00.531] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a09b 8040 4388 53 284f 4388 358 284d 4388 4388 e2 2a4d 4388 600 2642 4388 4388 4388 e000 c000
[15:48:00.531] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a095 80c0 43c8 201 2a4f 43c8 153 284d 43c8 43c8 618 2645 6cd 2a4b 43c8 43ca 104 2049 43c8 43c8 e000 c000
[15:48:00.531] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a096 8000 43c8 43c8 355 2a69 43c8 43c8 43c8 43c8 513 204f 81b 224f 43c8 43c8 e000 c000
[15:48:00.531] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a097 8040 43c8 43c8 43c8 43c8 43c8 4c5 286c 43c9 43c8 43c8 e000 c000
[15:48:00.531] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a098 80b1 4388 4388 4388 610 2a17 c41 2415 c15 25f3 eb8 4388 415 2a4a 4388 e000 c000
[15:48:00.532] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a099 80c0 4388 252 244a 4388 4388 4388 4388 4389 51 2665 4388 248 2045 4388 358 2429 e000 c000
[15:48:00.532] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a09a 8000 4388 29c 244a 4388 4388 4388 452 2865 4388 4388 4388 4388 e000 c000
[15:48:00.532] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[15:48:00.532] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a19b 8040 4388 443 244a 4388 620 2045 4388 84b 2442 4388 4388 29d 2a65 4d3 2843 4388 4388 4389 e000 c000
[15:48:00.532] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a195 80c0 43c8 43c8 858 2a2e 43c8 74b 2648 43c8 43c8 6d3 2286 43c8 43c8 43c8 660 224f e000 c000
[15:48:00.532] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a196 8000 43c8 43c8 43c8 43c8 621 2241 43c8 43c8 43c8 43c8 e000 c000
[15:48:00.532] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a197 8040 43c8 43c8 43c8 13 2841 43c8 43c8 10 2624 43c8 43c8 85d 2a2f 43c8 e000 c000
[15:48:00.532] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a198 80b1 4388 4388 1d 2461 542 2b7a 8d6 2969 7af 241c 4388 2068 225 2304 421 4388 4388 4388 31c 242d e000 c000
[15:48:00.532] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a199 80c0 4388 294 2a44 4388 4388 4388 4388 61b 264f 4388 4388 438a e000 c000
[15:48:00.532] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a19a 8000 4388 4388 4388 4388 4388 4d8 262b 541 264d 4388 461 2a49 4388 4389 e000 c000
[15:48:17.922] ERROR: <datapipe.cc/CheckEventValidity:L491> Channel 0 Number of ROCs (6) != Token Chain Length (8)
[15:48:17.922] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[15:48:17.922] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0da 8000 4388 4388 4388 4388 653 2249 4388 30c 2840 508 2069 4388 4 2040 4388 4388 da 2840 e000 c000
[15:48:17.923] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0d4 80b1 43c8 43c8 43c8 43c8 242 2069 43c8 4d9 2665 43c8 43c8 43c8 e000 c000
[15:48:17.923] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0d5 80c0 43c8 51 284f 43c8 43c8 93 286c 43c8 43c8 21a 266d 43ca c2 262c 43c8 112 2049 43c8 101 2045 e000 c000
[15:48:17.923] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0d6 8000 43c8 43c8 43c8 43c8 14b 264a 43c8 43c8 43c8 43c8 e000 c000
[15:48:17.923] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0d7 8040 43c8 43c8 55a 264d 43c8 43c8 215 2a64 859 204c 4388 129 2415 39 20f8 4388 e000 c000
[15:48:17.923] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0d8 80b1 4388 4388 4388 4388 21d 2065 4388 90 266c 4388 4388 41d 224f 4388 e000 c000
[15:48:17.923] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0d9 80c0 4388 49c 244d 4388 4388 4388 4388 4389 4388 4388 e000 c000
[15:48:17.923] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[15:48:17.923] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1da 8000 4388 4388 4388 414 2843 4cb 2a4f 4388 414 2a25 801 224f 4388 4388 4388 4389 e000 c000
[15:48:17.923] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1d4 80b1 43c8 43c8 8c 2a4f 43c8 43c8 43c8 43c8 43c8 43c8 e000 c000
[15:48:17.923] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1d5 80c0 43c8 54 2061 43c8 d5 2444 30d 284f 43c8 43c8 159 2a85 43c8 64c 2425 43c8 43c8 43c8 e000 c000
[15:48:17.923] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1d6 8000 43c8 43c8 34a 202f 43c8 660 2842 43c8 43c8 43c8 43c8 43c8 e000 c000
[15:48:17.923] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1d7 8040 43c8 43c8 43c8 43c8 43c8 43c8 43c8 43c8 e000 d000
[15:48:17.923] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1d8 80b1 4388 4388 250 2643 4388 4388 4388 d5 204a 4388 2e2 286f 4388 4388 e000 c000
[15:48:17.923] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1d9 80c0 4388 4388 34a 222f 4388 4388 2d3 224f 4388 4388 4388 438a e000 c000
[15:48:20.396] ERROR: <datapipe.cc/CheckEventValidity:L491> Channel 1 Number of ROCs (6) != Token Chain Length (8)
[15:48:20.396] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[15:48:20.396] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a166 8000 43c8 43c8 98 2625 43c8 43c8 151 2a4f 43c8 43c8 2cb 2047 43c8 43c8 e000 c000
[15:48:20.396] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a160 80b1 4389 4389 4389 4389 4389 4389 41b 2462 451 204f 4389 4388 e000 c000
[15:48:20.396] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a161 80c0 4388 4388 4388 403 2061 4389 150 2a49 543 2265 4389 4388 4389 4388 e000 c000
[15:48:20.396] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a162 8000 4388 4388 51a 2a48 4389 4388 4388 4389 4389 4388 e000 c000
[15:48:20.396] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a163 8040 4388 803 224f 4389 4388 43c8 43c8 43c8 7fd e000 c000
[15:48:20.396] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a164 80b1 43c8 43c8 43c8 43c8 43c8 342 2240 43c8 43c8 43c8 344 240f e000 c000
[15:48:20.396] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a165 80c0 43c8 75a 264f 858 2445 43c8 43c8 43c8 2d1 2646 43c8 362 224e 43c8 43c8 43c8 101 202f e000 c000
[15:48:20.396] WARNING: Channel 0 ROC 4: Readback start marker after 11 readouts!
[15:48:20.396] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[15:48:20.396] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a071 80c0 43c8 65d 244e 43c8 29d 2645 43c8 43c8 43c8 43c8 43c9 645 284b 43c9 e000 c000
[15:48:20.396] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a06b 8040 43c8 43c8 43c8 43c8 43c8 110 264d 2ca 2a43 494 2447 43c8 4a2 244f 43c8 43c8 e000 c000
[15:48:20.396] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a06c 80b1 43c8 43c8 43c8 43c8 43c8 43c8 43c8 43c8 e000 c000
[15:48:20.396] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a06d 80c0 43c8 43c8 43c8 43c8 43c8 543 284b 43c8 43c8 43ca e000 c000
[15:48:20.396] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a06e 8000 43c8 254 2842 43c8 454 2449 43c8 541 2846 68b 2066 862 204e 43c8 c 2023 43ca 43c8 29a 2a6f 43c8 43c8 4d5 284f e000 c000
[15:48:20.396] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a06f 8040 43ca 43ca 43ca 43ca 43c8 43c8 43ca 43c9 155 284c e000 c000
[15:48:20.396] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a070 80b1 43c8 43c8 43c8 43c8 489 2429 43c9 24b 2a63 294 202f 43c8 40b 2666 43c8 9c 2862 54d 244e 43c9 e000 c000
[15:48:25.948] INFO: Resuming triggers.
[15:48:37.197] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[15:48:38.312] ERROR: <datapipe.cc/CheckEventValidity:L491> Channel 0 Number of ROCs (3) != Token Chain Length (8)
[15:48:38.312] ERROR: <datapipe.cc/CheckEventValidity:L491> Channel 1 Number of ROCs (6) != Token Chain Length (8)
[15:48:38.312] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[15:48:38.312] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0ea 8000 4388 4388 4388 4388 4388 4388 4388 4388 e000 c000
[15:48:38.312] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0e4 80b1 43c8 43c8 54 282d 43c8 43c8 43c8 43c8 c5 2045 43c8 28b 2465 43c8 e000 c000
[15:48:38.312] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0e5 80c0 43c8 43c8 43c8 43c8 43c8 2d8 262f 811 2a65 43ca 43c8 43c8 e000 c000
[15:48:38.312] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0e6 8000 43c8 43c8 43c8 43c8 10d 2845 115 2a6d 254 2863 43c8 54 284a 43c8 43c8 60a 2240 43c8 548 2829 e000 c000
[15:48:38.312] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0e7 8040 43c8 43c8 293 2865 4388 e023 c0ed
[15:48:38.312] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0e8 80b1 4388 4388 4388 860 2461 4388 11d 2a42 4388 4388 4388 60c 264f 4388 e000 c000
[15:48:38.312] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0e9 80c0 4388 4388 4388 4388 4388 4389 4388 688 2442 6c0 2446 4388 5c 2042 10a 224f e000 c000
[15:48:38.312] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[15:48:38.312] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1ea 8000 4388 4a 264f 4388 808 202c 4388 85c 2440 4388 4388 4388 4388 4389 e000 c000
[15:48:38.312] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1e4 80b1 43c8 43c8 43c8 43c8 544 204c 43c8 43c8 43c8 43c8 e000 c000
[15:48:38.312] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1e5 80c0 43c8 43c8 43c8 2d8 262c 51b 2045 71b 2662 43c8 43c8 752 244f 43c8 43c8 43c8 e000 c000
[15:48:38.312] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1e6 8000 43c8 43c8 43c8 43c8 43c8 9a 2044 43c8 43c8 43c8 e000 c000
[15:48:38.312] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1e7 8040 43c8 43c8 4388 4388 4388 438a aa8 207c e000 c000
[15:48:38.312] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1e8 80b1 4388 49a 2265 4388 4388 48b 2644 74c 262d 4388 4388 4388 4388 4388 e000 c000
[15:48:38.312] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1e9 80c0 4388 4388 4388 745 2442 859 2642 4388 294 2a62 4388 4388 4388 438a e000 c000
[15:48:55.026] ERROR: <datapipe.cc/CheckEventValidity:L480> Channel 0 has NoTokenPass but 8 ROCs were found
[15:48:55.026] ERROR: <datapipe.cc/CheckEventValidity:L491> Channel 1 Number of ROCs (5) != Token Chain Length (8)
[15:48:55.026] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[15:48:55.026] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a063 8040 43c8 43c9 12 2445 43c8 65b 264c 43c9 43c8 43c8 43c8 6d8 262f 43c8 e000 c000
[15:48:55.026] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a05d 80c0 4388 69b 284c 4388 4388 613 204d 4388 4388 348 284b 44c 2449 4388 cb 284f 4388 438a e000 c000
[15:48:55.026] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a05e 8000 4388 519 2868 4388 1d 2049 855 2264 4388 4388 c5 2244 550 2443 438a 4388 4388 55 204a 600 2a48 4388 e000 c000
[15:48:55.026] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a05f 8040 438a 438a 438a 438a 4388 410 286d 68c 2045 4388 438a 92 286c 4389 e000 c000
[15:48:55.026] ERROR: <datapipe.cc/Read:L166> ====== 2 ====== a060 80b1 4388 450 2846 4388 4388 4388 4389 4388 30b 2a60 43c8 40d 222f 43c9 569 43c9 3ff 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
[15:48:55.026] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a061 80c0 43c8 43c8 43c8 43c8 43c8 dd 204d 43c8 85a 2848 43c9 43c9 e000 c000
[15:48:55.026] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a062 8000 43c8 43c8 43c9 43c9 43c8 43c8 43c9 10c 2647 43c8 e000 c000
[15:48:55.026] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[15:48:55.026] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a163 8040 43c8 43c9 21b 284b 43c8 43c8 43c8 2c5 2a43 31b 2664 31b 2a66 43c8 43c8 43c8 e000 c000
[15:48:55.026] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a15d 80c0 4388 6d1 264c 4388 4388 28a 244f 438a 4388 488 202b 4388 62 2668 4388 4389 e000 c000
[15:48:55.026] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a15e 8000 4388 219 204c 4388 4388 cb 264c 4389 c 282f 113 262f 4388 751 2a43 438a 4388 4388 29d 2649 e000 c000
[15:48:55.026] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a15f 8040 438a 2ca 2260 438a 438a 4388 4cd 244e 68b 2664 438a 4389 438a 609 2a21 4388 e000 c000
[15:48:55.026] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a160 80b1 4389 50b 204f 849 2246 4389 24b 2a45 4389 4389 43c9 219 224c 413 2503 81f 43c8 e000 c000
[15:48:55.026] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a161 80c0 43c8 43c8 43c8 41b 2a62 43c9 43c9 262 244f 43c8 150 2a45 43c9 43c8 51a 2a4a e000 c000
[15:48:55.026] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a162 8000 43c8 284 2040 43c8 308 2243 43c9 15b 2a4b 740 2643 43c8 43c8 43c9 c5 2044 c4 282d 43c9 43c8 299 2045 e000 c000
[15:49:07.501] INFO: Resuming triggers.
[15:49:18.758] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[15:49:49.119] INFO: Resuming triggers.
[15:50:00.371] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[15:50:30.701] INFO: Resuming triggers.
[15:50:41.959] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[15:51:12.403] INFO: Resuming triggers.
[15:51:23.657] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[15:51:54.143] INFO: Resuming triggers.
[15:52:05.404] INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[15:52:34.735] INFO: Resuming triggers.
[15:52:45.069] INFO: data taking finished, elapsed time: 100 seconds.
[15:53:12.042] INFO: PixTest:: pg_setup set to default.
[15:53:12.046] INFO: PixTestXray::doPhRun() done
[15:53:12.292] INFO: enter test to run
[15:54:00.764] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[15:54:00.764] INFO: running: xray
[15:54:00.765] INFO: ----------------------------------------------------------------------
[15:54:00.765] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:54:00.765] INFO: ----------------------------------------------------------------------
[15:54:01.730] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:54:08.309] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[15:54:38.524] INFO: Resuming triggers.
[15:54:45.102] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[15:55:15.348] INFO: Resuming triggers.
[15:55:21.926] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[15:55:52.108] INFO: Resuming triggers.
[15:55:58.685] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[15:56:28.906] INFO: Resuming triggers.
[15:56:35.480] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[15:57:05.660] INFO: Resuming triggers.
[15:57:12.233] INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[15:57:42.455] INFO: Resuming triggers.
[15:57:49.029] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[15:58:19.197] INFO: Resuming triggers.
[15:58:25.772] INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[15:58:56.877] INFO: Resuming triggers.
[15:59:03.452] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[15:59:34.448] INFO: Resuming triggers.
[15:59:41.017] INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[16:00:11.901] INFO: Resuming triggers.
[16:00:18.472] INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[16:00:49.442] INFO: Resuming triggers.
[16:00:56.017] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[16:01:26.861] INFO: Resuming triggers.
[16:01:33.436] INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[16:02:04.020] INFO: Resuming triggers.
[16:02:10.591] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[16:02:42.049] INFO: Resuming triggers.
[16:02:48.625] INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[16:03:19.983] INFO: Resuming triggers.
[16:03:21.720] INFO: data taking finished, elapsed time: 100 seconds.
[16:03:30.309] INFO: PixTest:: pg_setup set to default.
[16:03:30.312] INFO: PixTestXray::doPhRun() done
[16:03:30.470] INFO: enter test to run
[16:04:28.856] INFO: test: HighRate no parameter change
[16:04:28.856] INFO: running: highrate
[16:04:28.914] INFO: ----------------------------------------------------------------------
[16:04:28.914] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[16:04:28.914] INFO: ----------------------------------------------------------------------
[16:04:29.138] INFO: Expecting 768 events.
[16:04:30.291] INFO: 768 events read in total (437ms).
[16:04:30.291] INFO: Test took 1316ms.
[16:04:31.094] INFO: Expecting 41600 events.
[16:04:34.274] INFO: 41600 events read in total (2653ms).
[16:04:34.275] INFO: Test took 3871ms.
[16:04:34.314] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:04:35.027] INFO: Expecting 41600 events.
[16:04:38.327] INFO: 41600 events read in total (2773ms).
[16:04:38.328] INFO: Test took 3996ms.
[16:04:38.362] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:04:39.082] INFO: Expecting 41600 events.
[16:04:42.326] INFO: 41600 events read in total (2717ms).
[16:04:42.327] INFO: Test took 3947ms.
[16:04:42.362] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:04:43.084] INFO: Expecting 41600 events.
[16:04:46.407] INFO: 41600 events read in total (2797ms).
[16:04:46.408] INFO: Test took 4027ms.
[16:04:46.448] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:04:47.157] INFO: Expecting 41600 events.
[16:04:50.455] INFO: 41600 events read in total (2771ms).
[16:04:50.456] INFO: Test took 3987ms.
[16:04:50.493] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:04:51.207] INFO: Expecting 41600 events.
[16:04:54.460] INFO: 41600 events read in total (2726ms).
[16:04:54.461] INFO: Test took 3949ms.
[16:04:54.496] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:04:55.221] INFO: Expecting 41600 events.
[16:04:58.563] INFO: 41600 events read in total (2816ms).
[16:04:58.564] INFO: Test took 4049ms.
[16:04:58.599] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:04:59.322] INFO: Expecting 41600 events.
[16:05:02.628] INFO: 41600 events read in total (2780ms).
[16:05:02.629] INFO: Test took 4010ms.
[16:05:02.664] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:05:03.384] INFO: Expecting 41600 events.
[16:05:06.819] INFO: 41600 events read in total (2908ms).
[16:05:06.821] INFO: Test took 4140ms.
[16:05:06.860] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:05:07.571] INFO: Expecting 41600 events.
[16:05:10.848] INFO: 41600 events read in total (2751ms).
[16:05:10.849] INFO: Test took 3972ms.
[16:05:10.885] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:05:11.605] INFO: Expecting 41600 events.
[16:05:14.949] INFO: 41600 events read in total (2817ms).
[16:05:14.951] INFO: Test took 4048ms.
[16:05:14.989] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:05:15.703] INFO: Expecting 41600 events.
[16:05:19.018] INFO: 41600 events read in total (2788ms).
[16:05:19.019] INFO: Test took 4010ms.
[16:05:19.055] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:05:19.768] INFO: Expecting 41600 events.
[16:05:23.081] INFO: 41600 events read in total (2786ms).
[16:05:23.082] INFO: Test took 4007ms.
[16:05:23.117] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:05:23.840] INFO: Expecting 41600 events.
[16:05:27.107] INFO: 41600 events read in total (2740ms).
[16:05:27.108] INFO: Test took 3973ms.
[16:05:27.144] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:05:27.863] INFO: Expecting 41600 events.
[16:05:31.128] INFO: 41600 events read in total (2738ms).
[16:05:31.128] INFO: Test took 3967ms.
[16:05:31.163] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:05:31.882] INFO: Expecting 41600 events.
[16:05:35.164] INFO: 41600 events read in total (2755ms).
[16:05:35.165] INFO: Test took 3983ms.
[16:05:35.201] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:05:35.924] INFO: Expecting 41600 events.
[16:05:39.254] INFO: 41600 events read in total (2803ms).
[16:05:39.255] INFO: Test took 4036ms.
[16:05:39.291] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:05:40.014] INFO: Expecting 41600 events.
[16:05:43.273] INFO: 41600 events read in total (2733ms).
[16:05:43.274] INFO: Test took 3964ms.
[16:05:43.309] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:05:44.031] INFO: Expecting 41600 events.
[16:05:47.255] INFO: 41600 events read in total (2697ms).
[16:05:47.256] INFO: Test took 3928ms.
[16:05:47.290] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:05:48.011] INFO: Expecting 41600 events.
[16:05:51.057] INFO: 41600 events read in total (2519ms).
[16:05:51.058] INFO: Test took 3748ms.
[16:05:51.091] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:05:51.459] INFO: enter test to run
[16:06:18.551] INFO: test: HighRate no parameter change
[16:06:18.551] INFO: running: highrate
[16:06:18.552] INFO: ----------------------------------------------------------------------
[16:06:18.552] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:06:18.552] INFO: ----------------------------------------------------------------------
[16:06:19.170] INFO: Expecting 208000 events.
[16:06:31.065] INFO: 208000 events read in total (11368ms).
[16:06:31.069] INFO: Test took 12508ms.
[16:06:31.213] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:06:31.466] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 1 0 0 160 0 0 0 0
[16:06:31.466] INFO: number of red-efficiency pixels: 65 52 65 103 113 147 129 87 99 129 139 292 136 91 24 30
[16:06:31.466] INFO: number of X-ray hits detected: 67521 43088 64916 100723 107993 109691 110204 72683 77328 107293 107054 90657 96241 59398 23391 28342
[16:06:31.466] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[16:06:31.466] INFO: number of Vcal hits detected: 207935 207948 207935 207895 207885 207847 207867 207913 207838 207871 207856 199862 207859 207905 207975 207970
[16:06:31.466] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 100.0 99.9 99.9 99.9 100.0 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[16:06:31.467] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 96.1 99.9 100.0 100.0 100.0
[16:06:31.467] INFO: X-ray hit rate [MHz/cm2]: 19.8 12.6 19.0 29.5 31.7 32.2 32.3 21.3 22.7 31.4 31.4 26.6 28.2 17.4 6.9 8.3
[16:06:31.467] INFO: PixTestHighRate::doXPixelAlive() done
[16:06:31.514] INFO: PixTest:: pg_setup set to default.
[16:06:31.529] INFO: enter test to run
[16:06:55.054] INFO: test: HighRate no parameter change
[16:06:55.055] INFO: running: highrate
[16:06:55.056] INFO: ----------------------------------------------------------------------
[16:06:55.056] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:06:55.056] INFO: ----------------------------------------------------------------------
[16:06:55.665] INFO: Expecting 208000 events.
[16:07:09.318] INFO: 208000 events read in total (13126ms).
[16:07:09.323] INFO: Test took 14260ms.
[16:07:09.619] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:07:09.924] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 1 0 0 160 0 0 0 0
[16:07:09.924] INFO: number of red-efficiency pixels: 260 147 285 333 433 496 442 231 234 387 389 565 370 279 73 59
[16:07:09.924] INFO: number of X-ray hits detected: 139595 88711 133500 208085 223322 225961 229209 150785 160180 221590 222528 188402 199211 123279 48972 58650
[16:07:09.924] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[16:07:09.924] INFO: number of Vcal hits detected: 207721 207844 207689 207645 207534 207463 207514 207757 207694 207590 207586 199554 207601 207700 207924 207939
[16:07:09.924] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.8 99.8 99.9 99.9 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[16:07:09.924] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.7 99.8 99.9 99.9 99.8 99.8 95.9 99.8 99.9 100.0 100.0
[16:07:09.924] INFO: X-ray hit rate [MHz/cm2]: 40.9 26.0 39.1 61.0 65.5 66.2 67.2 44.2 46.9 64.9 65.2 55.2 58.4 36.1 14.4 17.2
[16:07:09.924] INFO: PixTestHighRate::doXPixelAlive() done
[16:07:09.970] INFO: PixTest:: pg_setup set to default.
[16:07:09.985] INFO: enter test to run
[16:07:36.190] INFO: test: HighRate no parameter change
[16:07:36.190] INFO: running: highrate
[16:07:36.192] INFO: ----------------------------------------------------------------------
[16:07:36.192] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:07:36.192] INFO: ----------------------------------------------------------------------
[16:07:36.810] INFO: Expecting 208000 events.
[16:07:52.524] INFO: 208000 events read in total (15187ms).
[16:07:52.532] INFO: Test took 16330ms.
[16:07:52.994] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:07:53.353] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 1 0 0 160 0 0 0 0
[16:07:53.353] INFO: number of red-efficiency pixels: 541 276 660 787 1082 1263 1040 503 482 897 967 1130 844 654 137 118
[16:07:53.353] INFO: number of X-ray hits detected: 213552 136096 204674 319033 343085 346696 351347 231376 245095 339952 341275 288270 306089 188975 75049 90390
[16:07:53.353] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[16:07:53.353] INFO: number of Vcal hits detected: 207346 207693 207141 207054 206650 206369 206702 207405 207405 206948 206815 198745 206988 207182 207856 207879
[16:07:53.353] INFO: Vcal hit fiducial efficiency (%): 99.7 99.9 99.6 99.6 99.4 99.3 99.4 99.7 99.8 99.5 99.5 99.5 99.6 99.6 99.9 99.9
[16:07:53.353] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.6 99.5 99.4 99.2 99.4 99.7 99.7 99.5 99.4 95.6 99.5 99.6 99.9 99.9
[16:07:53.353] INFO: X-ray hit rate [MHz/cm2]: 62.6 39.9 60.0 93.5 100.6 101.6 103.0 67.8 71.8 99.6 100.0 84.5 89.7 55.4 22.0 26.5
[16:07:53.353] INFO: PixTestHighRate::doXPixelAlive() done
[16:07:53.401] INFO: PixTest:: pg_setup set to default.
[16:07:53.418] INFO: enter test to run
[16:08:31.942] INFO: test: exit no parameter change
[16:08:32.421] QUIET: Connection to board 33 closed.
[16:08:32.434] INFO: pXar: this is the end, my friend