[12:49:08.674] INFO: *** Welcome to pxar ***
[12:49:08.674] INFO: *** Today: 2016/06/23
[12:49:08.694] INFO: *** Version: v1.9.0-814-g7497
[12:49:08.694] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-2-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//dacParameters35_C15.dat
[12:49:08.749] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-2-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//tbmParameters_C0b.dat
[12:49:08.749] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-2-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//defaultMaskFile.dat
[12:49:08.759] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-2-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C15.dat
[12:49:08.899] INFO: clk: 4
[12:49:08.899] INFO: ctr: 4
[12:49:08.899] INFO: sda: 19
[12:49:08.899] INFO: tin: 9
[12:49:08.899] INFO: level: 15
[12:49:08.899] INFO: triggerdelay: 0
[12:49:08.899] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[12:49:08.899] INFO: Log level: INFO
[12:49:08.918] QUIET: Connection to board DTB_WREK4U opened.
[12:49:08.921] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 32
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREK4U
MAC address: 40D855118020
Hostname: pixelDTB032
Comment:
------------------------------------------------------
[12:49:08.924] INFO: RPC call hashes of host and DTB match: 398089610
[12:49:10.465] INFO: DUT info:
[12:49:10.465] INFO: The DUT currently contains the following objects:
[12:49:10.465] INFO: 2 TBM Cores tbm08c (2 ON)
[12:49:10.465] INFO: TBM Core alpha (0): 7 registers set
[12:49:10.465] INFO: TBM Core beta (1): 7 registers set
[12:49:10.465] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[12:49:10.465] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[12:49:10.465] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[12:49:10.465] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[12:49:10.466] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[12:49:10.466] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[12:49:10.466] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[12:49:10.466] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[12:49:10.466] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[12:49:10.466] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[12:49:10.466] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[12:49:10.466] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[12:49:10.466] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[12:49:10.466] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[12:49:10.466] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[12:49:10.466] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[12:49:10.466] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[12:49:10.870] INFO: enter 'restricted' command line mode
[12:49:10.870] INFO: enter test to run
[12:49:19.121] INFO: test: PixelAlive no parameter change
[12:49:19.121] INFO: running: pixelalive
[12:49:19.130] INFO: ----------------------------------------------------------------------
[12:49:19.130] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[12:49:19.130] INFO: ----------------------------------------------------------------------
[12:49:19.450] INFO: Expecting 41600 events.
[12:49:23.777] INFO: 41600 events read in total (3609ms).
[12:49:23.947] INFO: Test took 4813ms.
[12:49:23.957] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:49:24.218] INFO: PixTestAlive::aliveTest() done
[12:49:24.218] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1
[12:49:24.250] INFO: enter test to run
[12:49:44.993] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[12:49:44.993] INFO: running: highrate
[12:49:44.993] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-2-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[12:49:45.220] INFO: ----------------------------------------------------------------------
[12:49:45.220] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[12:49:45.220] INFO: ----------------------------------------------------------------------
[12:49:45.220] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[12:49:45.220] INFO: edge/corner pixel THR is adjusted
[12:49:45.220] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:49:46.180] INFO: Collecting data for 5 seconds...
[12:49:51.198] INFO: Done with hot pixel readout
[12:50:02.723] INFO: PixTest:: pg_setup set to default.
[12:50:02.724] INFO: 7 hot pixels found in step 0
[12:50:03.735] INFO: Collecting data for 5 seconds...
[12:50:08.752] INFO: Done with hot pixel readout
[12:50:20.304] INFO: PixTest:: pg_setup set to default.
[12:50:20.305] INFO: 8 hot pixels found in step 1
[12:50:21.297] INFO: Collecting data for 5 seconds...
[12:50:26.313] INFO: Done with hot pixel readout
[12:50:37.883] INFO: PixTest:: pg_setup set to default.
[12:50:37.884] INFO: 8 hot pixels found in step 2
[12:50:38.875] INFO: Collecting data for 5 seconds...
[12:50:43.891] INFO: Done with hot pixel readout
[12:50:55.465] INFO: PixTest:: pg_setup set to default.
[12:50:55.466] INFO: 5 hot pixels found in step 3
[12:50:56.455] INFO: Collecting data for 5 seconds...
[12:51:01.472] INFO: Done with hot pixel readout
[12:51:13.076] INFO: PixTest:: pg_setup set to default.
[12:51:13.077] INFO: 4 hot pixels found in step 4
[12:51:14.067] INFO: Collecting data for 5 seconds...
[12:51:19.083] INFO: Done with hot pixel readout
[12:51:30.664] INFO: PixTest:: pg_setup set to default.
[12:51:30.665] INFO: 7 hot pixels found in step 5
[12:51:31.656] INFO: Collecting data for 5 seconds...
[12:51:36.677] INFO: Done with hot pixel readout
[12:51:48.338] INFO: PixTest:: pg_setup set to default.
[12:51:48.339] INFO: 4 hot pixels found in step 6
[12:51:49.330] INFO: Collecting data for 5 seconds...
[12:51:54.347] INFO: Done with hot pixel readout
[12:52:05.932] INFO: PixTest:: pg_setup set to default.
[12:52:05.933] INFO: 4 hot pixels found in step 7
[12:52:06.923] INFO: Collecting data for 5 seconds...
[12:52:11.939] INFO: Done with hot pixel readout
[12:52:23.534] INFO: PixTest:: pg_setup set to default.
[12:52:23.535] INFO: 3 hot pixels found in step 8
[12:52:24.525] INFO: Collecting data for 5 seconds...
[12:52:29.542] INFO: Done with hot pixel readout
[12:52:41.163] INFO: PixTest:: pg_setup set to default.
[12:52:41.164] INFO: 1 hot pixels found in step 9
[12:52:42.155] INFO: Collecting data for 5 seconds...
[12:52:47.173] INFO: Done with hot pixel readout
[12:52:58.766] INFO: PixTest:: pg_setup set to default.
[12:52:58.767] INFO: 2 hot pixels found in step 10
[12:52:59.758] INFO: Collecting data for 5 seconds...
[12:53:04.775] INFO: Done with hot pixel readout
[12:53:16.383] INFO: PixTest:: pg_setup set to default.
[12:53:16.384] INFO: 3 hot pixels found in step 11
[12:53:17.375] INFO: Collecting data for 5 seconds...
[12:53:22.392] INFO: Done with hot pixel readout
[12:53:34.010] INFO: PixTest:: pg_setup set to default.
[12:53:34.010] INFO: 3 hot pixels found in step 12
[12:53:35.002] INFO: Collecting data for 5 seconds...
[12:53:40.019] INFO: Done with hot pixel readout
[12:53:51.636] INFO: PixTest:: pg_setup set to default.
[12:53:51.637] INFO: 1 hot pixels found in step 13
[12:53:52.628] INFO: Collecting data for 5 seconds...
[12:53:57.646] INFO: Done with hot pixel readout
[12:54:09.264] INFO: PixTest:: pg_setup set to default.
[12:54:09.265] INFO: 2 hot pixels found in step 14
[12:54:09.300] INFO: 2 hot pixels could not be trimmed and have been masked.
[12:54:09.304] INFO: PixTest::trimHotPixels() done
[12:54:09.304] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C0.dat
[12:54:09.310] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C1.dat
[12:54:09.334] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C2.dat
[12:54:09.346] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C3.dat
[12:54:09.353] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C4.dat
[12:54:09.359] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C5.dat
[12:54:09.364] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C6.dat
[12:54:09.369] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C7.dat
[12:54:09.375] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C8.dat
[12:54:09.380] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C9.dat
[12:54:09.385] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C10.dat
[12:54:09.390] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C11.dat
[12:54:09.396] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C12.dat
[12:54:09.401] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C13.dat
[12:54:09.406] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C14.dat
[12:54:09.412] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C15.dat
[12:54:09.417] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-2-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//defaultMaskFile.dat
[12:54:09.433] INFO: enter test to run
[12:54:41.551] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[12:54:41.551] INFO: running: highrate
[12:54:41.555] INFO: ----------------------------------------------------------------------
[12:54:41.555] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[12:54:41.556] INFO: ----------------------------------------------------------------------
[12:54:41.556] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[12:54:41.556] INFO: edge/corner pixel THR is adjusted
[12:54:41.556] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:54:42.513] INFO: Collecting data for 1 seconds...
[12:54:43.516] INFO: Done with hot pixel readout
[12:54:47.553] INFO: PixTest:: pg_setup set to default.
[12:54:47.554] INFO: 0 hot pixels found in step 0
[12:54:47.560] INFO: 0 hot pixels could not be trimmed and have been masked.
[12:54:47.641] INFO: PixTest::trimHotPixels() done
[12:54:47.641] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C0.dat
[12:54:47.653] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C1.dat
[12:54:47.665] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C2.dat
[12:54:47.671] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C3.dat
[12:54:47.676] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C4.dat
[12:54:47.682] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C5.dat
[12:54:47.687] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C6.dat
[12:54:47.693] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C7.dat
[12:54:47.698] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C8.dat
[12:54:47.704] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C9.dat
[12:54:47.709] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C10.dat
[12:54:47.715] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C11.dat
[12:54:47.720] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C12.dat
[12:54:47.725] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C13.dat
[12:54:47.731] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C14.dat
[12:54:47.736] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C15.dat
[12:54:47.742] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-2-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//defaultMaskFile.dat
[12:54:47.752] INFO: enter test to run
[12:55:29.655] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[12:55:29.655] INFO: running: xray
[12:55:29.656] INFO: ----------------------------------------------------------------------
[12:55:29.656] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:55:29.656] INFO: ----------------------------------------------------------------------
[12:55:30.621] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:55:42.217] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[12:56:12.031] INFO: Resuming triggers.
[12:56:23.628] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[12:56:53.544] INFO: Resuming triggers.
[12:57:05.140] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[12:57:35.188] INFO: Resuming triggers.
[12:57:46.784] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[12:58:16.122] INFO: Resuming triggers.
[12:58:27.714] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[12:58:56.957] INFO: Resuming triggers.
[12:59:08.550] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[12:59:37.981] INFO: Resuming triggers.
[12:59:49.573] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[13:00:18.886] INFO: Resuming triggers.
[13:00:30.483] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[13:00:59.716] INFO: Resuming triggers.
[13:01:07.315] INFO: data taking finished, elapsed time: 100 seconds.
[13:01:26.884] INFO: PixTest:: pg_setup set to default.
[13:01:26.887] INFO: PixTestXray::doPhRun() done
[13:01:27.022] INFO: enter test to run
[13:02:13.420] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[13:02:13.420] INFO: running: xray
[13:02:13.421] INFO: ----------------------------------------------------------------------
[13:02:13.421] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:02:13.421] INFO: ----------------------------------------------------------------------
[13:02:14.385] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:02:21.262] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[13:02:51.569] INFO: Resuming triggers.
[13:02:58.444] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[13:03:28.848] INFO: Resuming triggers.
[13:03:35.727] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[13:04:06.026] INFO: Resuming triggers.
[13:04:12.901] INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[13:04:43.157] INFO: Resuming triggers.
[13:04:50.038] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[13:05:20.364] INFO: Resuming triggers.
[13:05:27.243] INFO: run duration 41 seconds, buffer almost full (81%), pausing triggers.
[13:05:57.630] INFO: Resuming triggers.
[13:06:04.512] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[13:06:35.886] INFO: Resuming triggers.
[13:06:42.766] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[13:07:14.045] INFO: Resuming triggers.
[13:07:20.925] INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[13:07:24.384] ERROR: <datapipe.cc/CheckEventValidity:L480> Channel 0 has NoTokenPass but 8 ROCs were found
[13:07:24.385] ERROR: <datapipe.cc/CheckEventValidity:L480> Channel 1 has NoTokenPass but 3 ROCs were found
[13:07:24.385] ERROR: <datapipe.cc/CheckEventID:L463> Channel 1 Event ID mismatch: local ID (205) != TBM ID (240)
[13:07:24.385] ERROR: <datapipe.cc/CheckEventValidity:L491> Channel 1 Number of ROCs (2) != Token Chain Length (8)
[13:07:24.385] ERROR: <datapipe.cc/CheckEventID:L463> Channel 1 Event ID mismatch: local ID (241) != TBM ID (205)
[13:07:24.385] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[13:07:24.385] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0cf 8040 43ca 43ca 43ca 453 226a 43ca 5 2a47 20a 204c 652 2245 43ca c 204b 43ca d 2a48 2dc 264e 858 262e 43ca b 284f 43ca e000 c000
[13:07:24.385] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0c9 80c0 4388 4388 4388 4388 11 2840 148 2068 552 264e 4388 5a 2848 4388 24b 204f 30c 2a4a 34a 2a2c 4388 50c 204f 4388 e000 c000
[13:07:24.385] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0ca 8000 4388 4388 4388 71c 242a 4388 d8 264d 4388 619 2244 4388 409 2468 409 204f 4388 490 244f 4388 55d 2442 614 2a40 e000 c000
[13:07:24.385] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0cb 8040 4388 258 2a24 4388 4388 4388 54c 224c 4388 358 242b 84a 2a46 84b 2a8a 4388 5a 2a40 c5 204d 4388 10d 2a4a 550 2a4d 4388 dc 2041 e000 c000
[13:07:24.385] ERROR: <datapipe.cc/Read:L166> ====== 2 ====== a0cc 80b1 4388 4388 2d9 288c 4388 413 284e 4388 4388 4388 30b 204f 4388 854 2a24 53c8 db 204c 3e5 3503 5ff 3fd7 f7f 3fd7 2aa 2ddb 795 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:07:24.385] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0cd 80c0 43c8 52 2644 43c8 6e2 264e 43c8 43c8 289 2846 84a 2266 43c8 449 2844 518 2861 6cb 288a 749 2247 43c8 1a 2446 15a 204b 150 2444 43c8 553 264f 43c8 15 2266 e000 c000
[13:07:24.385] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a0ce 8000 43c8 43c8 43c8 851 2442 43c8 43c8 255 2061 43c8 31b 2845 6cd 204f 43c8 2cc 2026 44d 204b 645 2089 43c8 1 2048 211 2662 e000 c000
[13:07:24.385] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[13:07:24.385] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1d0 80b1 43c9 43c9 43c9 218 2641 359 204a 4d0 224e 43c9 642 282a 43c9 602 204a 43c9 43c9 43c9 861 2680 e000 c000
[13:07:24.385] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1cb 8040 4388 4388 4388 108 2046 559 2648 559 2a68 65d 244a 709 2642 802 2247 4388 9 244a 418 2442 4388 4388 49c 2a29 4388 4388 e000 c000
[13:07:24.385] ERROR: <datapipe.cc/Read:L166> ====== 2 ====== a1cc 80b1 4388 2c9 2646 44a 224a 458 2642 4388 d 204a 4d 284f 40a 2865 43c8 140c 2649 61d 2aaa 1aa3 2a02 1f6b 22ea 1b7e
[13:07:24.385] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1f0 8008 494 43c8 3 264c 443 2a65 43c8 43c8 e000 c000
[13:07:24.385] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1cd 80c0 43c8 4db 2068 755 2048 43c8 10c 2242 51d 2888 43c8 20b 2644 43c8 4a2 2664 43c8 15d 2241 43c8 43c8 6db 224a 43c8 e000 c000
[13:07:24.385] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1ce 8000 43c8 43c8 4d0 2844 550 284c 43c8 62 2046 60 282e 6d3 266f 43c8 451 284f 43c8 44c 2a4f 680 2642 43c8 43c8 43c8 e000 c000
[13:07:24.385] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a1cf 8040 43ca 43ca 43ca 491 2649 75d 264a 43ca 43ca d8 2a48 318 2a4c 695 2665 43ca 43ca 859 204f 43ca e000 c000
[13:07:51.891] INFO: Resuming triggers.
[13:07:58.766] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[13:08:18.227] ERROR: <datapipe.cc/CheckEventValidity:L491> Channel 0 Number of ROCs (6) != Token Chain Length (8)
[13:08:18.227] ERROR: <datapipe.cc/CheckEventValidity:L491> Channel 1 Number of ROCs (6) != Token Chain Length (8)
[13:08:18.228] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[13:08:18.228] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a05a 8000 4388 dd 2642 4388 4388 4388 612 2242 4388 691 2063 713 244c 710 2a2c 4388 409 204f 4388 218 2448 218 2640 4388 4c 2448 8a 2a2e d1 204f 113 264a 283 2865 550 244f e000 c000
[13:08:18.228] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a054 80b1 43c8 693 2a88 842 262c 43c8 113 2a65 31b 2661 43c8 85c 2649 43c8 699 244e 43c8 43c8 11a 224f 861 244a 43c8 4cc 224e 55c 264a 43c8 e000 c000
[13:08:18.228] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a055 80c0 43c8 1a 204c 43c8 293 2448 43c8 34d 264e 43c8 4cd 2460 43c8 245 2464 514 2a62 550 2a45 43c8 13 2448 9c 2245 43c8 9c 2048 24c 2a6c 445 204e 75c 2049 43c8 e000 c000
[13:08:18.228] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a056 8000 43c8 41c 2440 69d 2864 43c8 1d 204c 43c8 752 264a 43c8 89 222a 51c 204f 51a 244a 845 2648 43c8 55d 244a 43c8 43c8 252 2a2c 43c8 e000 c000
[13:08:18.228] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a057 8040 43c8 85d 2244 43c8 518 2466 518 264f 4388 45c 2442 841 20fb 5f8 4388 35d 204c 4388 99 2046 4388 c8 282a 610 2644 813 2266 4388 48 2245 e000 c000
[13:08:18.228] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a058 80b1 4388 4388 4388 60b 2049 4388 818 2a44 4388 4388 54 2245 4388 71d 264f 4388 e000 c000
[13:08:18.228] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a059 80c0 4388 4388 518 2a6c 4388 313 266f 458 2642 550 2a40 4388 314 2646 4388 4388 5a 2848 250 2a45 4388 4388 214 224a e000 c000
[13:08:18.228] ERROR: <datapipe.cc/Read:L164> Dumping the flawed event +- 3 events:
[13:08:18.228] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a15a 8000 4388 4388 64b 264e 64b 2a60 709 2462 4388 858 2a4d 4388 559 226c 689 2869 4388 21c 2243 25a 204f 4388 44c 2a4b 4388 4388 e000 c000
[13:08:18.228] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a154 80b1 43c8 54a 244a 85c 2241 43c8 44a 2086 43c8 449 264c 750 202e 43c8 43c8 2c4 244d 845 2846 43c8 43c8 43c8 e000 c000
[13:08:18.228] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a155 80c0 43c8 683 2242 43c8 43c8 e0 2246 43c8 a 2446 34b 264f 43c8 43c8 362 2a62 43c8 43c8 e000 c000
[13:08:18.228] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a156 8000 43c8 61a 2844 74a 204a 43c8 6cb 2a48 43c8 544 2a45 811 2a4c 43c8 43c8 111 206b 60b 2a4f 683 2866 43c8 43c8 45b 2660 715 2a49 43c8 e000 c000
[13:08:18.228] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a157 8040 43c8 43c8 43c8 30c 2848 755 2042 760 2647 4388 4388 855 20a0 54 4388 4388 443 2a4d e000 c000
[13:08:18.228] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a158 80b1 4388 43 222c 4388 4388 712 2a40 4388 4388 8d 2862 4388 4388 4388 41d 2840 620 286f e000 c000
[13:08:18.228] ERROR: <datapipe.cc/Read:L166> ====== 0 ====== a159 80c0 4388 542 2848 4388 4388 14c 2861 4cc 2848 68d 204e 4388 4388 45c 2246 480 2465 4c0 2a62 4388 41c 2a45 4388 4388 35d 202f e000 c000
[13:08:29.832] INFO: Resuming triggers.
[13:08:36.715] INFO: run duration 75 seconds, buffer almost full (81%), pausing triggers.
[13:09:08.252] INFO: Resuming triggers.
[13:09:15.130] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[13:09:45.688] INFO: Resuming triggers.
[13:09:52.567] INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[13:10:22.793] INFO: Resuming triggers.
[13:10:29.672] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[13:11:00.119] INFO: Resuming triggers.
[13:11:04.173] INFO: data taking finished, elapsed time: 100 seconds.
[13:11:22.265] INFO: PixTest:: pg_setup set to default.
[13:11:22.268] INFO: PixTestXray::doPhRun() done
[13:11:22.415] INFO: enter test to run
[13:12:13.744] INFO: test: timing no parameter change
[13:12:13.744] INFO: running: timing
[13:12:13.762] INFO: ######################################################################
[13:12:13.762] INFO: PixTestTiming::doTest()
[13:12:13.762] INFO: ######################################################################
[13:12:13.762] INFO: ----------------------------------------------------------------------
[13:12:13.762] INFO: PixTestTiming::TBMPhaseScan()
[13:12:13.762] INFO: ----------------------------------------------------------------------
[13:16:40.914] INFO: TBM Phase Settings: 16
[13:16:40.914] INFO: 400MHz Phase: 4
[13:16:40.914] INFO: 160MHz Phase: 0
[13:16:40.914] INFO: Functional Phase Area: 3
[13:16:40.923] INFO: Test took 267161 ms.
[13:16:40.923] INFO: PixTestTiming::TBMPhaseScan() done.
[13:16:40.924] INFO: ----------------------------------------------------------------------
[13:16:40.924] INFO: PixTestTiming::ROCDelayScan()
[13:16:40.924] INFO: ----------------------------------------------------------------------
[13:18:41.339] INFO: ROC Delay Settings: 219
[13:18:41.339] INFO: ROC Header-Trailer/Token Delay: 11
[13:18:41.339] INFO: ROC Port 0 Delay: 3
[13:18:41.339] INFO: ROC Port 1 Delay: 3
[13:18:41.339] INFO: Functional ROC Area: 4
[13:18:41.342] INFO: Test took 120418 ms.
[13:18:41.342] INFO: PixTestTiming::ROCDelayScan() done.
[13:18:41.342] INFO: ----------------------------------------------------------------------
[13:18:41.342] INFO: PixTestTiming::TimingTest()
[13:18:41.342] INFO: ----------------------------------------------------------------------
[13:18:57.451] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:19:12.308] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:19:27.324] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:19:42.503] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:19:57.713] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:20:13.139] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:20:28.289] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:20:43.489] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:20:58.524] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:21:13.760] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:21:14.142] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:21:14.154] INFO: ----------------------------------------------------------------------
[13:21:14.154] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[13:21:14.154] INFO: ----------------------------------------------------------------------
[13:21:14.154] INFO: ----------------------------------------------------------------------
[13:21:14.154] INFO: Read back bit status: 1
[13:21:14.154] INFO: ----------------------------------------------------------------------
[13:21:14.154] INFO: ----------------------------------------------------------------------
[13:21:14.154] INFO: Timings are good!
[13:21:14.154] INFO: ----------------------------------------------------------------------
[13:21:14.154] INFO: Test took 152812 ms.
[13:21:14.154] INFO: PixTestTiming::TimingTest() done.
[13:21:14.184] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//tbmParameters_C0a.dat
[13:21:14.188] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//tbmParameters_C0b.dat
[13:21:14.188] INFO: PixTestTiming::doTest took 540429 ms.
[13:21:14.188] INFO: PixTestTiming::doTest() done
[13:21:14.189] INFO: Write out TBMPhaseScan_0_V0
[13:21:14.189] INFO: Write out TBMPhaseScan_1_V0
[13:21:14.189] INFO: Write out CombinedTBMPhaseScan_V0
[13:21:14.215] INFO: Write out ROCDelayScan3_V0
[13:21:14.215] INFO: enter test to run
[13:21:44.596] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[13:21:44.596] INFO: running: xray
[13:21:44.597] INFO: ----------------------------------------------------------------------
[13:21:44.597] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:21:44.597] INFO: ----------------------------------------------------------------------
[13:21:45.563] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:21:52.447] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[13:22:22.705] INFO: Resuming triggers.
[13:22:29.584] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[13:22:59.925] INFO: Resuming triggers.
[13:23:06.808] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[13:23:37.069] INFO: Resuming triggers.
[13:23:43.950] INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[13:24:14.204] INFO: Resuming triggers.
[13:24:21.082] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[13:24:51.370] INFO: Resuming triggers.
[13:24:58.255] INFO: run duration 41 seconds, buffer almost full (81%), pausing triggers.
[13:25:28.530] INFO: Resuming triggers.
[13:25:35.417] INFO: run duration 48 seconds, buffer almost full (81%), pausing triggers.
[13:26:05.761] INFO: Resuming triggers.
[13:26:12.649] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[13:26:42.980] INFO: Resuming triggers.
[13:26:49.861] INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[13:27:20.002] INFO: Resuming triggers.
[13:27:26.890] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[13:27:57.053] INFO: Resuming triggers.
[13:28:03.943] INFO: run duration 75 seconds, buffer almost full (81%), pausing triggers.
[13:28:34.588] INFO: Resuming triggers.
[13:28:41.476] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[13:29:12.029] INFO: Resuming triggers.
[13:29:18.914] INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[13:29:49.772] INFO: Resuming triggers.
[13:29:56.655] INFO: run duration 96 seconds, buffer almost full (81%), pausing triggers.
[13:30:27.877] INFO: Resuming triggers.
[13:30:31.837] INFO: data taking finished, elapsed time: 100 seconds.
[13:30:49.819] INFO: PixTest:: pg_setup set to default.
[13:30:49.822] INFO: PixTestXray::doPhRun() done
[13:30:49.973] INFO: enter test to run
[13:34:04.839] INFO: test: HighRate no parameter change
[13:34:04.839] INFO: running: highrate
[13:34:04.840] INFO: ----------------------------------------------------------------------
[13:34:04.840] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[13:34:04.841] INFO: ----------------------------------------------------------------------
[13:34:04.982] INFO: Expecting 768 events.
[13:34:06.116] INFO: 768 events read in total (418ms).
[13:34:06.117] INFO: Test took 1269ms.
[13:34:06.920] INFO: Expecting 41600 events.
[13:34:09.966] INFO: 41600 events read in total (2519ms).
[13:34:09.967] INFO: Test took 3843ms.
[13:34:09.999] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:34:10.728] INFO: Expecting 41600 events.
[13:34:13.896] INFO: 41600 events read in total (2641ms).
[13:34:13.897] INFO: Test took 3881ms.
[13:34:13.930] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:34:14.658] INFO: Expecting 41600 events.
[13:34:17.869] INFO: 41600 events read in total (2684ms).
[13:34:17.870] INFO: Test took 3923ms.
[13:34:17.903] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:34:18.631] INFO: Expecting 41600 events.
[13:34:21.840] INFO: 41600 events read in total (2682ms).
[13:34:21.841] INFO: Test took 3919ms.
[13:34:21.873] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:34:22.601] INFO: Expecting 41600 events.
[13:34:25.812] INFO: 41600 events read in total (2684ms).
[13:34:25.813] INFO: Test took 3922ms.
[13:34:25.846] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:34:26.574] INFO: Expecting 41600 events.
[13:34:29.794] INFO: 41600 events read in total (2693ms).
[13:34:29.795] INFO: Test took 3930ms.
[13:34:29.828] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:34:30.551] INFO: Expecting 41600 events.
[13:34:33.776] INFO: 41600 events read in total (2698ms).
[13:34:33.777] INFO: Test took 3931ms.
[13:34:33.810] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:34:34.533] INFO: Expecting 41600 events.
[13:34:37.762] INFO: 41600 events read in total (2702ms).
[13:34:37.763] INFO: Test took 3935ms.
[13:34:37.796] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:34:38.519] INFO: Expecting 41600 events.
[13:34:41.745] INFO: 41600 events read in total (2699ms).
[13:34:41.746] INFO: Test took 3932ms.
[13:34:41.779] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:34:42.503] INFO: Expecting 41600 events.
[13:34:45.721] INFO: 41600 events read in total (2691ms).
[13:34:45.722] INFO: Test took 3925ms.
[13:34:45.755] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:34:46.482] INFO: Expecting 41600 events.
[13:34:49.693] INFO: 41600 events read in total (2684ms).
[13:34:49.694] INFO: Test took 3921ms.
[13:34:49.727] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:34:50.456] INFO: Expecting 41600 events.
[13:34:53.673] INFO: 41600 events read in total (2690ms).
[13:34:53.674] INFO: Test took 3930ms.
[13:34:53.707] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:34:54.430] INFO: Expecting 41600 events.
[13:34:57.648] INFO: 41600 events read in total (2691ms).
[13:34:57.649] INFO: Test took 3925ms.
[13:34:57.682] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:34:58.409] INFO: Expecting 41600 events.
[13:35:01.632] INFO: 41600 events read in total (2696ms).
[13:35:01.633] INFO: Test took 3934ms.
[13:35:01.666] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:35:02.392] INFO: Expecting 41600 events.
[13:35:05.605] INFO: 41600 events read in total (2687ms).
[13:35:05.606] INFO: Test took 3921ms.
[13:35:05.639] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:35:06.368] INFO: Expecting 41600 events.
[13:35:09.587] INFO: 41600 events read in total (2692ms).
[13:35:09.587] INFO: Test took 3932ms.
[13:35:09.620] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:35:10.347] INFO: Expecting 41600 events.
[13:35:13.568] INFO: 41600 events read in total (2694ms).
[13:35:13.569] INFO: Test took 3930ms.
[13:35:13.601] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:35:14.326] INFO: Expecting 41600 events.
[13:35:17.543] INFO: 41600 events read in total (2690ms).
[13:35:17.544] INFO: Test took 3925ms.
[13:35:17.576] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:35:18.303] INFO: Expecting 41600 events.
[13:35:21.515] INFO: 41600 events read in total (2685ms).
[13:35:21.516] INFO: Test took 3923ms.
[13:35:21.549] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:35:22.275] INFO: Expecting 41600 events.
[13:35:25.389] INFO: 41600 events read in total (2587ms).
[13:35:25.389] INFO: Test took 3822ms.
[13:35:25.422] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:35:25.788] INFO: enter test to run
[13:37:52.190] INFO: test: HighRate no parameter change
[13:37:52.190] INFO: running: highrate
[13:37:52.191] INFO: ----------------------------------------------------------------------
[13:37:52.191] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:37:52.191] INFO: ----------------------------------------------------------------------
[13:37:52.811] INFO: Expecting 208000 events.
[13:38:04.651] INFO: 208000 events read in total (11313ms).
[13:38:04.654] INFO: Test took 12451ms.
[13:38:04.792] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:38:05.044] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1
[13:38:05.044] INFO: number of red-efficiency pixels: 65 53 72 129 138 145 116 82 88 112 101 86 103 75 19 25
[13:38:05.044] INFO: number of X-ray hits detected: 62324 40126 64033 101276 111471 114850 108280 76698 71551 93943 92727 79635 81304 49060 20855 26319
[13:38:05.044] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:38:05.044] INFO: number of Vcal hits detected: 207935 207947 207925 207867 207857 207851 207881 207918 207910 207884 207898 207913 207895 207923 207980 207926
[13:38:05.044] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 100.0 100.0 100.0 100.0 100.0 100.0
[13:38:05.044] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 100.0 100.0 99.9 100.0 100.0 100.0
[13:38:05.044] INFO: X-ray hit rate [MHz/cm2]: 18.3 11.8 18.8 29.7 32.7 33.7 31.7 22.5 21.0 27.5 27.2 23.3 23.8 14.4 6.1 7.7
[13:38:05.044] INFO: PixTestHighRate::doXPixelAlive() done
[13:38:05.090] INFO: PixTest:: pg_setup set to default.
[13:38:05.104] INFO: enter test to run
[13:38:24.501] INFO: test: HighRate no parameter change
[13:38:24.502] INFO: running: highrate
[13:38:24.503] INFO: ----------------------------------------------------------------------
[13:38:24.503] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:38:24.503] INFO: ----------------------------------------------------------------------
[13:38:25.123] INFO: Expecting 208000 events.
[13:38:38.534] INFO: 208000 events read in total (12885ms).
[13:38:38.541] INFO: Test took 14026ms.
[13:38:38.834] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:38:39.136] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1
[13:38:39.136] INFO: number of red-efficiency pixels: 191 125 249 401 508 533 395 241 246 385 279 245 276 199 52 58
[13:38:39.136] INFO: number of X-ray hits detected: 127554 83035 131247 207007 228219 234292 222240 158199 148648 194218 190507 163794 167692 101776 43424 54343
[13:38:39.136] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:38:39.136] INFO: number of Vcal hits detected: 207792 207871 207726 207575 207445 207413 207577 207744 207737 207591 207705 207748 207710 207792 207944 207892
[13:38:39.136] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.7 99.7 99.8 99.9 99.9 99.8 99.9 99.9 99.9 99.9 100.0 100.0
[13:38:39.136] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.7 99.7 99.8 99.9 99.9 99.8 99.9 99.9 99.9 99.9 100.0 99.9
[13:38:39.136] INFO: X-ray hit rate [MHz/cm2]: 37.4 24.3 38.5 60.7 66.9 68.7 65.1 46.4 43.6 56.9 55.8 48.0 49.2 29.8 12.7 15.9
[13:38:39.136] INFO: PixTestHighRate::doXPixelAlive() done
[13:38:39.182] INFO: PixTest:: pg_setup set to default.
[13:38:39.197] INFO: enter test to run
[13:39:09.797] INFO: test: HighRate no parameter change
[13:39:09.797] INFO: running: highrate
[13:39:09.798] INFO: ----------------------------------------------------------------------
[13:39:09.798] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:39:09.798] INFO: ----------------------------------------------------------------------
[13:39:10.422] INFO: Expecting 208000 events.
[13:39:25.341] INFO: 208000 events read in total (14392ms).
[13:39:25.348] INFO: Test took 15537ms.
[13:39:25.761] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:39:26.105] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1
[13:39:26.105] INFO: number of red-efficiency pixels: 362 216 591 982 1186 1284 939 558 526 870 619 509 653 413 78 98
[13:39:26.105] INFO: number of X-ray hits detected: 193550 126602 198718 312816 344828 354538 335389 239801 224191 291970 288703 248794 252768 153687 65752 82368
[13:39:26.105] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:39:26.105] INFO: number of Vcal hits detected: 207585 207768 207256 206786 206481 206280 206873 207366 207401 206962 207316 207452 207255 207508 207915 207848
[13:39:26.105] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.7 99.5 99.3 99.3 99.5 99.7 99.7 99.5 99.7 99.8 99.7 99.8 100.0 100.0
[13:39:26.105] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.6 99.4 99.3 99.2 99.5 99.7 99.7 99.5 99.7 99.7 99.6 99.8 100.0 99.9
[13:39:26.105] INFO: X-ray hit rate [MHz/cm2]: 56.7 37.1 58.2 91.7 101.1 103.9 98.3 70.3 65.7 85.6 84.6 72.9 74.1 45.0 19.3 24.1
[13:39:26.105] INFO: PixTestHighRate::doXPixelAlive() done
[13:39:26.151] INFO: PixTest:: pg_setup set to default.
[13:39:26.167] INFO: enter test to run
[13:39:32.917] INFO: test: exit no parameter change
[13:39:33.262] QUIET: Connection to board 32 closed.
[13:39:33.264] INFO: pXar: this is the end, my friend