[11:30:01.544] INFO: *** Welcome to pxar ***
[11:30:01.544] INFO: *** Today: 2016/05/17
[11:30:01.566] INFO: *** Version: v1.9.0-796-gef167-dirty
[11:30:01.566] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-M-1-38_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-M-1-38_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//dacParameters35_C15.dat
[11:30:01.592] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-M-1-38_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-M-1-38_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//tbmParameters_C0b.dat
[11:30:01.593] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-M-1-38_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//defaultMaskFile.dat
[11:30:01.598] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-M-1-38_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-M-1-38_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C15.dat
[11:30:01.688] INFO: clk: 4
[11:30:01.688] INFO: ctr: 4
[11:30:01.688] INFO: sda: 19
[11:30:01.688] INFO: tin: 9
[11:30:01.688] INFO: level: 15
[11:30:01.688] INFO: triggerdelay: 0
[11:30:01.688] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[11:30:01.688] INFO: Log level: INFO
[11:30:01.704] QUIET: Connection to board DTB_WREKRL opened.
[11:30:01.707] 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:
------------------------------------------------------
[11:30:01.710] INFO: RPC call hashes of host and DTB match: 398089610
[11:30:03.234] INFO: DUT info:
[11:30:03.234] INFO: The DUT currently contains the following objects:
[11:30:03.234] INFO: 2 TBM Cores tbm08c (2 ON)
[11:30:03.234] INFO: TBM Core alpha (0): 7 registers set
[11:30:03.234] INFO: TBM Core beta (1): 7 registers set
[11:30:03.234] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[11:30:03.234] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[11:30:03.234] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[11:30:03.234] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[11:30:03.234] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[11:30:03.234] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[11:30:03.234] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[11:30:03.234] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[11:30:03.235] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[11:30:03.235] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[11:30:03.235] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[11:30:03.235] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[11:30:03.235] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[11:30:03.235] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[11:30:03.235] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[11:30:03.235] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[11:30:03.235] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[11:30:03.638] INFO: enter 'restricted' command line mode
[11:30:03.638] INFO: enter test to run
[11:30:24.273] INFO: test: PixelAlive no parameter change
[11:30:24.273] INFO: running: pixelalive
[11:30:24.282] INFO: ----------------------------------------------------------------------
[11:30:24.282] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[11:30:24.282] INFO: ----------------------------------------------------------------------
[11:30:24.606] INFO: Expecting 41600 events.
[11:30:28.952] INFO: 41600 events read in total (3628ms).
[11:30:29.117] INFO: Test took 4833ms.
[11:30:29.124] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:30:29.387] INFO: PixTestAlive::aliveTest() done
[11:30:29.387] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:30:29.422] INFO: enter test to run
[11:30:56.705] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[11:30:56.705] INFO: running: highrate
[11:30:56.705] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-M-1-38_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-M-1-38_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[11:30:56.905] INFO: ----------------------------------------------------------------------
[11:30:56.905] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[11:30:56.905] INFO: ----------------------------------------------------------------------
[11:30:56.905] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[11:30:56.905] INFO: edge/corner pixel THR is adjusted
[11:30:56.905] INFO: PixTestHighRate::trimHotPixels: step 0...
[11:30:57.863] INFO: Collecting data for 5 seconds...
[11:31:02.880] INFO: Done with hot pixel readout
[11:31:14.570] INFO: PixTest:: pg_setup set to default.
[11:31:14.571] INFO: 0 hot pixels found in step 0
[11:31:14.583] INFO: 0 hot pixels could not be trimmed and have been masked.
[11:31:14.587] INFO: PixTest::trimHotPixels() done
[11:31:14.630] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-38_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C0.dat
[11:31:14.635] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-38_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C1.dat
[11:31:14.641] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-38_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C2.dat
[11:31:14.646] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-38_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C3.dat
[11:31:14.652] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-38_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C4.dat
[11:31:14.657] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-38_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C5.dat
[11:31:14.662] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-38_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C6.dat
[11:31:14.668] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-38_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C7.dat
[11:31:14.673] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-38_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C8.dat
[11:31:14.679] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-38_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C9.dat
[11:31:14.684] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-38_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C10.dat
[11:31:14.689] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-38_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C11.dat
[11:31:14.695] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-38_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C12.dat
[11:31:14.700] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-38_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C13.dat
[11:31:14.705] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-38_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C14.dat
[11:31:14.711] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-38_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C15.dat
[11:31:14.716] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-M-1-38_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//defaultMaskFile.dat
[11:31:14.726] INFO: enter test to run
[11:32:02.888] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[11:32:02.888] INFO: running: highrate
[11:32:02.892] INFO: ----------------------------------------------------------------------
[11:32:02.893] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[11:32:02.893] INFO: ----------------------------------------------------------------------
[11:32:02.893] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[11:32:02.893] INFO: edge/corner pixel THR is adjusted
[11:32:02.893] INFO: PixTestHighRate::trimHotPixels: step 0...
[11:32:03.850] INFO: Collecting data for 1 seconds...
[11:32:04.853] INFO: Done with hot pixel readout
[11:32:08.890] INFO: PixTest:: pg_setup set to default.
[11:32:08.891] INFO: 0 hot pixels found in step 0
[11:32:08.896] INFO: 0 hot pixels could not be trimmed and have been masked.
[11:32:08.988] INFO: PixTest::trimHotPixels() done
[11:32:08.988] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-38_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C0.dat
[11:32:08.000] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-38_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C1.dat
[11:32:09.006] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-38_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C2.dat
[11:32:09.012] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-38_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C3.dat
[11:32:09.017] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-38_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C4.dat
[11:32:09.023] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-38_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C5.dat
[11:32:09.028] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-38_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C6.dat
[11:32:09.033] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-38_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C7.dat
[11:32:09.039] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-38_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C8.dat
[11:32:09.044] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-38_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C9.dat
[11:32:09.049] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-38_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C10.dat
[11:32:09.055] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-38_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C11.dat
[11:32:09.060] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-38_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C12.dat
[11:32:09.066] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-38_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C13.dat
[11:32:09.071] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-38_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C14.dat
[11:32:09.077] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-38_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C15.dat
[11:32:09.082] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-M-1-38_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//defaultMaskFile.dat
[11:32:09.093] INFO: enter test to run
[11:32:43.352] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[11:32:43.352] INFO: running: xray
[11:32:43.353] INFO: ----------------------------------------------------------------------
[11:32:43.353] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[11:32:43.353] INFO: ----------------------------------------------------------------------
[11:32:44.317] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[11:32:55.780] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[11:33:25.050] INFO: Resuming triggers.
[11:33:36.515] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[11:34:05.887] INFO: Resuming triggers.
[11:34:17.351] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[11:34:46.686] INFO: Resuming triggers.
[11:34:58.151] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[11:35:27.525] INFO: Resuming triggers.
[11:35:38.992] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[11:36:07.992] INFO: Resuming triggers.
[11:36:19.460] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[11:36:48.702] INFO: Resuming triggers.
[11:37:00.170] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[11:37:29.451] INFO: Resuming triggers.
[11:37:40.917] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[11:38:10.376] INFO: Resuming triggers.
[11:38:18.978] INFO: data taking finished, elapsed time: 100 seconds.
[11:38:40.937] INFO: PixTest:: pg_setup set to default.
[11:38:40.940] INFO: PixTestXray::doPhRun() done
[11:38:41.133] INFO: enter test to run
[11:39:13.309] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[11:39:13.309] INFO: running: xray
[11:39:13.310] INFO: ----------------------------------------------------------------------
[11:39:13.310] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[11:39:13.310] INFO: ----------------------------------------------------------------------
[11:39:14.277] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[11:39:20.901] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[11:39:51.164] INFO: Resuming triggers.
[11:39:57.788] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[11:40:27.449] INFO: Resuming triggers.
[11:40:34.073] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[11:41:05.053] INFO: Resuming triggers.
[11:41:11.677] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[11:41:42.442] INFO: Resuming triggers.
[11:41:49.065] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[11:42:19.204] INFO: Resuming triggers.
[11:42:25.826] INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[11:42:55.963] INFO: Resuming triggers.
[11:43:02.587] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[11:43:32.704] INFO: Resuming triggers.
[11:43:39.326] INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[11:44:09.473] INFO: Resuming triggers.
[11:44:16.096] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[11:44:46.160] INFO: Resuming triggers.
[11:44:52.784] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[11:45:22.819] INFO: Resuming triggers.
[11:45:29.443] INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[11:45:59.505] INFO: Resuming triggers.
[11:46:06.133] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[11:46:36.219] INFO: Resuming triggers.
[11:46:42.846] INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[11:47:12.920] INFO: Resuming triggers.
[11:47:19.546] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[11:47:49.583] INFO: Resuming triggers.
[11:47:56.208] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[11:48:26.371] INFO: Resuming triggers.
[11:48:27.345] INFO: data taking finished, elapsed time: 100 seconds.
[11:48:32.115] INFO: PixTest:: pg_setup set to default.
[11:48:32.118] INFO: PixTestXray::doPhRun() done
[11:48:32.269] INFO: enter test to run
[11:49:36.600] INFO: test: HighRate no parameter change
[11:49:36.600] INFO: running: highrate
[11:49:36.601] INFO: ----------------------------------------------------------------------
[11:49:36.602] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[11:49:36.602] INFO: ----------------------------------------------------------------------
[11:49:36.742] INFO: Expecting 768 events.
[11:49:37.876] INFO: 768 events read in total (418ms).
[11:49:37.877] INFO: Test took 1269ms.
[11:49:38.680] INFO: Expecting 41600 events.
[11:49:41.758] INFO: 41600 events read in total (2551ms).
[11:49:41.759] INFO: Test took 3874ms.
[11:49:41.792] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:49:42.521] INFO: Expecting 41600 events.
[11:49:45.729] INFO: 41600 events read in total (2681ms).
[11:49:45.730] INFO: Test took 3920ms.
[11:49:45.764] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:49:46.486] INFO: Expecting 41600 events.
[11:49:49.718] INFO: 41600 events read in total (2705ms).
[11:49:49.719] INFO: Test took 3936ms.
[11:49:49.753] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:49:50.480] INFO: Expecting 41600 events.
[11:49:53.710] INFO: 41600 events read in total (2703ms).
[11:49:53.711] INFO: Test took 3939ms.
[11:49:53.744] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:49:54.467] INFO: Expecting 41600 events.
[11:49:57.695] INFO: 41600 events read in total (2701ms).
[11:49:57.696] INFO: Test took 3935ms.
[11:49:57.730] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:49:58.454] INFO: Expecting 41600 events.
[11:50:01.658] INFO: 41600 events read in total (2677ms).
[11:50:01.659] INFO: Test took 3911ms.
[11:50:01.693] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:50:02.419] INFO: Expecting 41600 events.
[11:50:05.661] INFO: 41600 events read in total (2715ms).
[11:50:05.662] INFO: Test took 3953ms.
[11:50:05.696] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:50:06.418] INFO: Expecting 41600 events.
[11:50:09.657] INFO: 41600 events read in total (2712ms).
[11:50:09.658] INFO: Test took 3944ms.
[11:50:09.691] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:50:10.414] INFO: Expecting 41600 events.
[11:50:13.655] INFO: 41600 events read in total (2714ms).
[11:50:13.656] INFO: Test took 3947ms.
[11:50:13.690] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:50:14.412] INFO: Expecting 41600 events.
[11:50:17.650] INFO: 41600 events read in total (2711ms).
[11:50:17.651] INFO: Test took 3943ms.
[11:50:17.684] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:50:18.407] INFO: Expecting 41600 events.
[11:50:21.648] INFO: 41600 events read in total (2714ms).
[11:50:21.649] INFO: Test took 3946ms.
[11:50:21.684] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:50:22.406] INFO: Expecting 41600 events.
[11:50:25.658] INFO: 41600 events read in total (2725ms).
[11:50:25.659] INFO: Test took 3958ms.
[11:50:25.694] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:50:26.419] INFO: Expecting 41600 events.
[11:50:29.675] INFO: 41600 events read in total (2729ms).
[11:50:29.676] INFO: Test took 3965ms.
[11:50:29.710] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:50:30.430] INFO: Expecting 41600 events.
[11:50:33.703] INFO: 41600 events read in total (2746ms).
[11:50:33.704] INFO: Test took 3975ms.
[11:50:33.740] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:50:34.459] INFO: Expecting 41600 events.
[11:50:37.519] INFO: 41600 events read in total (2533ms).
[11:50:37.520] INFO: Test took 3762ms.
[11:50:37.555] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:50:38.270] INFO: Expecting 41600 events.
[11:50:41.548] INFO: 41600 events read in total (2751ms).
[11:50:41.549] INFO: Test took 3975ms.
[11:50:41.583] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:50:42.306] INFO: Expecting 41600 events.
[11:50:45.589] INFO: 41600 events read in total (2757ms).
[11:50:45.590] INFO: Test took 3989ms.
[11:50:45.625] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:50:46.348] INFO: Expecting 41600 events.
[11:50:49.588] INFO: 41600 events read in total (2713ms).
[11:50:49.589] INFO: Test took 3947ms.
[11:50:49.633] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:50:50.327] INFO: Expecting 41600 events.
[11:50:53.546] INFO: 41600 events read in total (2692ms).
[11:50:53.547] INFO: Test took 3887ms.
[11:50:53.583] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:50:54.305] INFO: Expecting 41600 events.
[11:50:57.464] INFO: 41600 events read in total (2632ms).
[11:50:57.465] INFO: Test took 3863ms.
[11:50:57.499] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:50:57.861] INFO: enter test to run
[11:51:03.559] INFO: test: HighRate no parameter change
[11:51:03.560] INFO: running: highrate
[11:51:03.561] INFO: ----------------------------------------------------------------------
[11:51:03.561] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:51:03.561] INFO: ----------------------------------------------------------------------
[11:51:04.184] INFO: Expecting 208000 events.
[11:51:15.994] INFO: 208000 events read in total (11283ms).
[11:51:15.997] INFO: Test took 12430ms.
[11:51:16.143] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:51:16.395] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:51:16.395] INFO: number of red-efficiency pixels: 93 47 82 126 126 128 159 75 92 138 100 131 113 85 27 43
[11:51:16.395] INFO: number of X-ray hits detected: 67549 39586 64574 100045 108289 113493 112867 76133 75210 97590 96276 87199 91835 57525 24103 25852
[11:51:16.395] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[11:51:16.395] INFO: number of Vcal hits detected: 207905 207953 207915 207871 207871 207869 207835 207924 207907 207859 207898 207866 207884 207914 207973 207957
[11:51:16.395] 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 99.9 100.0 100.0 100.0 100.0
[11:51:16.395] 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 99.9 99.9 100.0 100.0 100.0
[11:51:16.395] INFO: X-ray hit rate [MHz/cm2]: 19.8 11.6 18.9 29.3 31.7 33.3 33.1 22.3 22.0 28.6 28.2 25.6 26.9 16.9 7.1 7.6
[11:51:16.395] INFO: PixTestHighRate::doXPixelAlive() done
[11:51:16.440] INFO: PixTest:: pg_setup set to default.
[11:51:16.457] INFO: enter test to run
[11:51:37.840] INFO: test: HighRate no parameter change
[11:51:37.840] INFO: running: highrate
[11:51:37.841] INFO: ----------------------------------------------------------------------
[11:51:37.841] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:51:37.841] INFO: ----------------------------------------------------------------------
[11:51:38.466] INFO: Expecting 208000 events.
[11:51:52.127] INFO: 208000 events read in total (13134ms).
[11:51:52.132] INFO: Test took 14283ms.
[11:51:52.438] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:51:52.744] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:51:52.744] INFO: number of red-efficiency pixels: 253 158 298 453 428 398 611 226 239 445 341 363 411 251 72 69
[11:51:52.744] INFO: number of X-ray hits detected: 142869 84153 136324 210217 227559 238860 239579 160989 158225 207068 204081 183612 194726 121905 51302 54454
[11:51:52.744] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[11:51:52.744] INFO: number of Vcal hits detected: 207735 207839 207672 207509 207535 207574 207327 207759 207754 207524 207642 207617 207565 207734 207925 207931
[11:51:52.744] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.8 99.7 99.9 99.9 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[11:51:52.745] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.8 99.8 99.8 99.7 99.9 99.9 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[11:51:52.745] INFO: X-ray hit rate [MHz/cm2]: 41.9 24.7 40.0 61.6 66.7 70.0 70.2 47.2 46.4 60.7 59.8 53.8 57.1 35.7 15.0 16.0
[11:51:52.745] INFO: PixTestHighRate::doXPixelAlive() done
[11:51:52.792] INFO: PixTest:: pg_setup set to default.
[11:51:52.808] INFO: enter test to run
[11:52:13.847] INFO: test: HighRate no parameter change
[11:52:13.847] INFO: running: highrate
[11:52:13.848] INFO: ----------------------------------------------------------------------
[11:52:13.848] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:52:13.848] INFO: ----------------------------------------------------------------------
[11:52:14.486] INFO: Expecting 208000 events.
[11:52:29.346] INFO: 208000 events read in total (14333ms).
[11:52:29.354] INFO: Test took 15498ms.
[11:52:29.860] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:52:30.244] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:52:30.244] INFO: number of red-efficiency pixels: 498 266 637 1061 960 992 1339 539 446 1055 746 844 912 587 120 105
[11:52:30.244] INFO: number of X-ray hits detected: 214198 127370 205544 318451 345447 361707 361425 244167 240136 312204 308889 278297 293333 184961 77463 83103
[11:52:30.244] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[11:52:30.244] INFO: number of Vcal hits detected: 207422 207708 207185 206700 206862 206830 206204 207371 207496 206690 207119 207005 206897 207283 207874 207894
[11:52:30.244] INFO: Vcal hit fiducial efficiency (%): 99.7 99.9 99.7 99.4 99.5 99.5 99.2 99.7 99.8 99.4 99.6 99.6 99.5 99.7 99.9 99.9
[11:52:30.244] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.6 99.4 99.5 99.4 99.1 99.7 99.8 99.4 99.6 99.5 99.5 99.7 99.9 99.9
[11:52:30.244] INFO: X-ray hit rate [MHz/cm2]: 62.8 37.3 60.2 93.3 101.3 106.0 105.9 71.6 70.4 91.5 90.5 81.6 86.0 54.2 22.7 24.4
[11:52:30.244] INFO: PixTestHighRate::doXPixelAlive() done
[11:52:30.290] INFO: PixTest:: pg_setup set to default.
[11:52:30.307] INFO: enter test to run
[11:52:33.951] INFO: test: exit no parameter change
[11:52:34.257] QUIET: Connection to board 33 closed.
[11:52:34.257] INFO: pXar: this is the end, my friend