[15:46:22.829] INFO: *** Welcome to pxar ***
[15:46:22.829] INFO: *** Today: 2016/04/01
[15:46:22.848] INFO: *** Version: v1.9.0-793-ge521-dirty
[15:46:22.848] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-I-4-13_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17/dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-I-4-13_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17/dacParameters35_C15.dat
[15:46:22.863] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-I-4-13_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17/tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-I-4-13_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17/tbmParameters_C0b.dat
[15:46:22.864] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-I-4-13_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17/defaultMaskFile.dat
[15:46:22.864] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-I-4-13_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17/trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-I-4-13_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17/trimParameters35_C15.dat
[15:46:22.943] INFO: clk: 4
[15:46:22.943] INFO: ctr: 4
[15:46:22.943] INFO: sda: 19
[15:46:22.943] INFO: tin: 9
[15:46:22.943] INFO: level: 15
[15:46:22.943] INFO: triggerdelay: 0
[15:46:22.943] QUIET: Instanciating API for pxar v1.9.0+793~ge5211a7
[15:46:22.943] INFO: Log level: INFO
[15:46:22.962] QUIET: Connection to board DTB_WREKRL opened.
[15:46:22.965] 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:46:22.968] INFO: RPC call hashes of host and DTB match: 398089610
[15:46:24.498] INFO: DUT info:
[15:46:24.498] INFO: The DUT currently contains the following objects:
[15:46:24.498] INFO: 2 TBM Cores tbm08c (2 ON)
[15:46:24.498] INFO: TBM Core alpha (0): 7 registers set
[15:46:24.498] INFO: TBM Core beta (1): 7 registers set
[15:46:24.498] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[15:46:24.498] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[15:46:24.498] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[15:46:24.498] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[15:46:24.498] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[15:46:24.498] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[15:46:24.499] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[15:46:24.499] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[15:46:24.499] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[15:46:24.499] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[15:46:24.499] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[15:46:24.499] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[15:46:24.499] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[15:46:24.499] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[15:46:24.499] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[15:46:24.499] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[15:46:24.499] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[15:46:24.902] INFO: enter 'restricted' command line mode
[15:46:24.902] INFO: enter test to run
[15:46:32.776] INFO: test: PixelAlive no parameter change
[15:46:32.776] INFO: running: pixelalive
[15:46:32.786] INFO: ----------------------------------------------------------------------
[15:46:32.786] 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:46:32.786] INFO: ----------------------------------------------------------------------
[15:46:33.105] INFO: Expecting 41600 events.
[15:46:37.435] INFO: 41600 events read in total (3612ms).
[15:46:37.604] INFO: Test took 4816ms.
[15:46:37.618] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:46:37.885] INFO: PixTestAlive::aliveTest() done
[15:46:37.885] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 1 0 0 0 1 4 0 0 1
[15:46:37.919] INFO: enter test to run
[15:47:17.975] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[15:47:17.976] INFO: running: highrate
[15:47:17.976] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-I-4-13_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17/phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-I-4-13_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17/phCalibrationFitErr35_C15.dat
[15:47:18.180] INFO: ----------------------------------------------------------------------
[15:47:18.180] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[15:47:18.180] INFO: ----------------------------------------------------------------------
[15:47:18.180] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[15:47:18.180] INFO: edge/corner pixel THR is adjusted
[15:47:18.180] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:47:19.140] INFO: Collecting data for 5 seconds...
[15:47:24.156] INFO: Done with hot pixel readout
[15:47:36.100] INFO: PixTest:: pg_setup set to default.
[15:47:36.101] INFO: 17 hot pixels found in step 0
[15:47:37.113] INFO: Collecting data for 5 seconds...
[15:47:42.130] INFO: Done with hot pixel readout
[15:47:54.084] INFO: PixTest:: pg_setup set to default.
[15:47:54.085] INFO: 13 hot pixels found in step 1
[15:47:55.075] INFO: Collecting data for 5 seconds...
[15:48:00.092] INFO: Done with hot pixel readout
[15:48:11.999] INFO: PixTest:: pg_setup set to default.
[15:48:11.000] INFO: 13 hot pixels found in step 2
[15:48:12.990] INFO: Collecting data for 5 seconds...
[15:48:18.006] INFO: Done with hot pixel readout
[15:48:29.908] INFO: PixTest:: pg_setup set to default.
[15:48:29.909] INFO: 19 hot pixels found in step 3
[15:48:30.899] INFO: Collecting data for 5 seconds...
[15:48:35.915] INFO: Done with hot pixel readout
[15:48:47.869] INFO: PixTest:: pg_setup set to default.
[15:48:47.870] INFO: 16 hot pixels found in step 4
[15:48:48.861] INFO: Collecting data for 5 seconds...
[15:48:53.877] INFO: Done with hot pixel readout
[15:49:05.849] INFO: PixTest:: pg_setup set to default.
[15:49:05.850] INFO: 19 hot pixels found in step 5
[15:49:06.840] INFO: Collecting data for 5 seconds...
[15:49:11.857] INFO: Done with hot pixel readout
[15:49:23.785] INFO: PixTest:: pg_setup set to default.
[15:49:23.785] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:49:23.786] INFO: 19 hot pixels found in step 6
[15:49:24.776] INFO: Collecting data for 5 seconds...
[15:49:29.793] INFO: Done with hot pixel readout
[15:49:41.728] INFO: PixTest:: pg_setup set to default.
[15:49:41.729] INFO: 14 hot pixels found in step 7
[15:49:42.719] INFO: Collecting data for 5 seconds...
[15:49:47.735] INFO: Done with hot pixel readout
[15:49:59.681] INFO: PixTest:: pg_setup set to default.
[15:49:59.682] INFO: 19 hot pixels found in step 8
[15:50:00.672] INFO: Collecting data for 5 seconds...
[15:50:05.688] INFO: Done with hot pixel readout
[15:50:17.620] INFO: PixTest:: pg_setup set to default.
[15:50:17.621] INFO: 19 hot pixels found in step 9
[15:50:18.610] INFO: Collecting data for 5 seconds...
[15:50:23.626] INFO: Done with hot pixel readout
[15:50:35.546] INFO: PixTest:: pg_setup set to default.
[15:50:35.547] INFO: 16 hot pixels found in step 10
[15:50:36.537] INFO: Collecting data for 5 seconds...
[15:50:41.553] INFO: Done with hot pixel readout
[15:50:53.500] INFO: PixTest:: pg_setup set to default.
[15:50:53.501] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:50:53.501] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:50:53.501] INFO: 16 hot pixels found in step 11
[15:50:54.491] INFO: Collecting data for 5 seconds...
[15:50:59.508] INFO: Done with hot pixel readout
[15:51:11.471] INFO: PixTest:: pg_setup set to default.
[15:51:11.472] INFO: 17 hot pixels found in step 12
[15:51:12.461] INFO: Collecting data for 5 seconds...
[15:51:17.478] INFO: Done with hot pixel readout
[15:51:26.405] INFO: PixTest:: pg_setup set to default.
[15:51:26.405] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:51:26.405] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:51:26.406] INFO: 12 hot pixels found in step 13
[15:51:27.396] INFO: Collecting data for 5 seconds...
[15:51:32.412] INFO: Done with hot pixel readout
[15:51:43.897] INFO: PixTest:: pg_setup set to default.
[15:51:43.898] INFO: 9 hot pixels found in step 14
[15:51:43.932] INFO: 9 hot pixels could not be trimmed and have been masked.
[15:51:43.936] INFO: PixTest::trimHotPixels() done
[15:51:43.940] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-13_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17/trimParameters35_C0.dat
[15:51:43.946] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-13_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17/trimParameters35_C1.dat
[15:51:43.951] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-13_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17/trimParameters35_C2.dat
[15:51:43.957] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-13_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17/trimParameters35_C3.dat
[15:51:43.963] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-13_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17/trimParameters35_C4.dat
[15:51:43.968] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-13_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17/trimParameters35_C5.dat
[15:51:43.973] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-13_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17/trimParameters35_C6.dat
[15:51:43.979] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-13_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17/trimParameters35_C7.dat
[15:51:43.984] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-13_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17/trimParameters35_C8.dat
[15:51:43.990] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-13_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17/trimParameters35_C9.dat
[15:51:43.996] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-13_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17/trimParameters35_C10.dat
[15:51:43.001] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-13_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17/trimParameters35_C11.dat
[15:51:44.006] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-13_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17/trimParameters35_C12.dat
[15:51:44.012] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-13_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17/trimParameters35_C13.dat
[15:51:44.018] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-13_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17/trimParameters35_C14.dat
[15:51:44.023] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-13_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17/trimParameters35_C15.dat
[15:51:44.029] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-I-4-13_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17/defaultMaskFile.dat
[15:51:44.039] INFO: enter test to run
[15:53:03.669] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[15:53:03.669] INFO: running: highrate
[15:53:03.674] INFO: ----------------------------------------------------------------------
[15:53:03.674] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[15:53:03.674] INFO: ----------------------------------------------------------------------
[15:53:03.674] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[15:53:03.674] INFO: edge/corner pixel THR is adjusted
[15:53:03.674] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:53:04.631] INFO: Collecting data for 1 seconds...
[15:53:05.635] INFO: Done with hot pixel readout
[15:53:09.576] INFO: PixTest:: pg_setup set to default.
[15:53:09.577] INFO: 0 hot pixels found in step 0
[15:53:09.582] INFO: 0 hot pixels could not be trimmed and have been masked.
[15:53:09.672] INFO: PixTest::trimHotPixels() done
[15:53:09.673] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-13_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17/trimParameters35_C0.dat
[15:53:09.680] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-13_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17/trimParameters35_C1.dat
[15:53:09.685] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-13_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17/trimParameters35_C2.dat
[15:53:09.691] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-13_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17/trimParameters35_C3.dat
[15:53:09.696] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-13_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17/trimParameters35_C4.dat
[15:53:09.701] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-13_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17/trimParameters35_C5.dat
[15:53:09.706] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-13_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17/trimParameters35_C6.dat
[15:53:09.712] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-13_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17/trimParameters35_C7.dat
[15:53:09.717] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-13_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17/trimParameters35_C8.dat
[15:53:09.722] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-13_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17/trimParameters35_C9.dat
[15:53:09.728] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-13_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17/trimParameters35_C10.dat
[15:53:09.733] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-13_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17/trimParameters35_C11.dat
[15:53:09.738] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-13_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17/trimParameters35_C12.dat
[15:53:09.743] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-13_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17/trimParameters35_C13.dat
[15:53:09.749] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-13_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17/trimParameters35_C14.dat
[15:53:09.754] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-13_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17/trimParameters35_C15.dat
[15:53:09.759] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-I-4-13_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17/defaultMaskFile.dat
[15:53:09.776] INFO: enter test to run
[15:53:33.173] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[15:53:33.173] INFO: running: xray
[15:53:33.174] INFO: ----------------------------------------------------------------------
[15:53:33.174] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:53:33.174] INFO: ----------------------------------------------------------------------
[15:53:34.137] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:53:45.427] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[15:54:14.882] INFO: Resuming triggers.
[15:54:26.175] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[15:54:55.727] INFO: Resuming triggers.
[15:55:07.016] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[15:55:36.310] INFO: Resuming triggers.
[15:55:47.601] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[15:56:17.016] INFO: Resuming triggers.
[15:56:28.308] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[15:56:57.778] INFO: Resuming triggers.
[15:57:09.071] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[15:57:38.578] INFO: Resuming triggers.
[15:57:49.868] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[15:58:19.278] INFO: Resuming triggers.
[15:58:30.570] INFO: run duration 90 seconds, buffer almost full (81%), pausing triggers.
[15:58:59.972] INFO: Resuming triggers.
[15:59:09.972] INFO: data taking finished, elapsed time: 100 seconds.
[15:59:36.132] INFO: PixTest:: pg_setup set to default.
[15:59:36.135] INFO: PixTestXray::doPhRun() done
[15:59:36.314] INFO: enter test to run
[15:59:57.562] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[15:59:57.562] INFO: running: xray
[15:59:57.563] INFO: ----------------------------------------------------------------------
[15:59:57.563] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:59:57.563] INFO: ----------------------------------------------------------------------
[15:59:58.542] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[16:00:05.322] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[16:00:35.475] INFO: Resuming triggers.
[16:00:42.259] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[16:01:12.434] INFO: Resuming triggers.
[16:01:19.216] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[16:01:46.605] INFO: Resuming triggers.
[16:01:53.388] INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[16:02:23.353] INFO: Resuming triggers.
[16:02:30.132] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[16:03:00.349] INFO: Resuming triggers.
[16:03:07.131] INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[16:03:37.333] INFO: Resuming triggers.
[16:03:44.118] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[16:04:14.325] INFO: Resuming triggers.
[16:04:21.108] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[16:04:51.231] INFO: Resuming triggers.
[16:04:58.009] INFO: run duration 60 seconds, buffer almost full (81%), pausing triggers.
[16:05:28.182] INFO: Resuming triggers.
[16:05:34.963] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[16:06:05.120] INFO: Resuming triggers.
[16:06:11.900] INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[16:06:41.993] INFO: Resuming triggers.
[16:06:48.774] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[16:07:18.982] INFO: Resuming triggers.
[16:07:25.763] INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[16:07:55.934] INFO: Resuming triggers.
[16:08:02.709] INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[16:08:32.874] INFO: Resuming triggers.
[16:08:38.257] INFO: data taking finished, elapsed time: 100 seconds.
[16:09:02.448] INFO: PixTest:: pg_setup set to default.
[16:09:02.451] INFO: PixTestXray::doPhRun() done
[16:09:02.599] INFO: enter test to run
[16:10:44.445] INFO: test: HighRate no parameter change
[16:10:44.445] INFO: running: highrate
[16:10:44.447] INFO: ----------------------------------------------------------------------
[16:10:44.447] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[16:10:44.447] INFO: ----------------------------------------------------------------------
[16:10:44.587] INFO: Expecting 768 events.
[16:10:45.721] INFO: 768 events read in total (418ms).
[16:10:45.721] INFO: Test took 1268ms.
[16:10:46.525] INFO: Expecting 41600 events.
[16:10:49.560] INFO: 41600 events read in total (2509ms).
[16:10:49.561] INFO: Test took 3833ms.
[16:10:49.591] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:10:50.328] INFO: Expecting 41600 events.
[16:10:53.496] INFO: 41600 events read in total (2641ms).
[16:10:53.497] INFO: Test took 3888ms.
[16:10:53.529] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:10:54.256] INFO: Expecting 41600 events.
[16:10:57.458] INFO: 41600 events read in total (2675ms).
[16:10:57.459] INFO: Test took 3914ms.
[16:10:57.490] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:10:58.220] INFO: Expecting 41600 events.
[16:11:01.440] INFO: 41600 events read in total (2693ms).
[16:11:01.441] INFO: Test took 3932ms.
[16:11:01.472] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:11:02.199] INFO: Expecting 41600 events.
[16:11:05.415] INFO: 41600 events read in total (2689ms).
[16:11:05.416] INFO: Test took 3926ms.
[16:11:05.447] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:11:06.177] INFO: Expecting 41600 events.
[16:11:09.409] INFO: 41600 events read in total (2705ms).
[16:11:09.410] INFO: Test took 3945ms.
[16:11:09.442] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:11:10.169] INFO: Expecting 41600 events.
[16:11:13.381] INFO: 41600 events read in total (2685ms).
[16:11:13.382] INFO: Test took 3923ms.
[16:11:13.413] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:11:14.140] INFO: Expecting 41600 events.
[16:11:17.368] INFO: 41600 events read in total (2701ms).
[16:11:17.369] INFO: Test took 3939ms.
[16:11:17.400] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:11:18.130] INFO: Expecting 41600 events.
[16:11:21.363] INFO: 41600 events read in total (2706ms).
[16:11:21.364] INFO: Test took 3948ms.
[16:11:21.396] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:11:22.126] INFO: Expecting 41600 events.
[16:11:25.346] INFO: 41600 events read in total (2693ms).
[16:11:25.347] INFO: Test took 3935ms.
[16:11:25.379] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:11:26.108] INFO: Expecting 41600 events.
[16:11:29.328] INFO: 41600 events read in total (2693ms).
[16:11:29.329] INFO: Test took 3932ms.
[16:11:29.362] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:11:30.088] INFO: Expecting 41600 events.
[16:11:32.878] INFO: 41600 events read in total (2263ms).
[16:11:32.878] INFO: Test took 3499ms.
[16:11:32.911] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:11:33.642] INFO: Expecting 41600 events.
[16:11:36.628] INFO: 41600 events read in total (2459ms).
[16:11:36.629] INFO: Test took 3700ms.
[16:11:36.661] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:11:37.391] INFO: Expecting 41600 events.
[16:11:40.333] INFO: 41600 events read in total (2415ms).
[16:11:40.334] INFO: Test took 3653ms.
[16:11:40.366] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:11:41.094] INFO: Expecting 41600 events.
[16:11:44.306] INFO: 41600 events read in total (2685ms).
[16:11:44.307] INFO: Test took 3923ms.
[16:11:44.339] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:11:45.069] INFO: Expecting 41600 events.
[16:11:48.278] INFO: 41600 events read in total (2682ms).
[16:11:48.279] INFO: Test took 3923ms.
[16:11:48.310] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:11:49.038] INFO: Expecting 41600 events.
[16:11:52.249] INFO: 41600 events read in total (2684ms).
[16:11:52.250] INFO: Test took 3922ms.
[16:11:52.282] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:11:53.010] INFO: Expecting 41600 events.
[16:11:56.125] INFO: 41600 events read in total (2588ms).
[16:11:56.126] INFO: Test took 3826ms.
[16:11:56.159] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:11:56.889] INFO: Expecting 41600 events.
[16:11:59.681] INFO: 41600 events read in total (2265ms).
[16:11:59.681] INFO: Test took 3505ms.
[16:11:59.714] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:12:00.446] INFO: Expecting 41600 events.
[16:12:03.563] INFO: 41600 events read in total (2590ms).
[16:12:03.564] INFO: Test took 3832ms.
[16:12:03.594] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:12:03.960] INFO: enter test to run
[16:13:09.404] INFO: test: HighRate no parameter change
[16:13:09.404] INFO: running: highrate
[16:13:09.405] INFO: ----------------------------------------------------------------------
[16:13:09.405] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:13:09.405] INFO: ----------------------------------------------------------------------
[16:13:10.020] INFO: Expecting 208000 events.
[16:13:21.788] INFO: 208000 events read in total (11241ms).
[16:13:21.791] INFO: Test took 12375ms.
[16:13:21.925] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:13:22.172] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 1 0 0 0 1 4 0 0 1
[16:13:22.172] INFO: number of red-efficiency pixels: 70 46 67 116 105 123 145 107 92 113 104 93 96 51 27 43
[16:13:22.172] INFO: number of X-ray hits detected: 59989 38184 58005 92473 98246 107363 109223 76152 71348 91274 88799 76844 79795 49624 21699 24706
[16:13:22.173] 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:13:22.173] INFO: number of Vcal hits detected: 207930 207953 207932 207881 207893 207875 207849 207840 207907 207885 207895 207857 207704 207948 207973 207908
[16:13:22.173] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 100.0 99.9 99.9 100.0 100.0 99.9 100.0 100.0 100.0 100.0 100.0 100.0
[16:13:22.173] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[16:13:22.173] INFO: X-ray hit rate [MHz/cm2]: 17.6 11.2 17.0 27.1 28.8 31.5 32.0 22.3 20.9 26.8 26.0 22.5 23.4 14.5 6.4 7.2
[16:13:22.173] INFO: PixTestHighRate::doXPixelAlive() done
[16:13:22.224] INFO: PixTest:: pg_setup set to default.
[16:13:22.241] INFO: enter test to run
[16:14:42.108] INFO: test: HighRate no parameter change
[16:14:42.108] INFO: running: highrate
[16:14:42.109] INFO: ----------------------------------------------------------------------
[16:14:42.109] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:14:42.109] INFO: ----------------------------------------------------------------------
[16:14:42.731] INFO: Expecting 208000 events.
[16:14:56.364] INFO: 208000 events read in total (13107ms).
[16:14:56.369] INFO: Test took 14250ms.
[16:14:56.669] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:14:56.969] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 1 0 0 0 1 4 0 0 1
[16:14:56.969] INFO: number of red-efficiency pixels: 221 116 262 418 377 448 481 352 281 307 413 355 293 175 62 69
[16:14:56.969] INFO: number of X-ray hits detected: 134772 85685 132844 209545 222623 242497 248359 174584 162132 206335 200983 173800 182152 111977 49025 56743
[16:14:56.969] 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:14:56.969] INFO: number of Vcal hits detected: 207761 207879 207716 207555 207577 207508 207466 207582 207705 207679 207555 207569 207496 207816 207936 207879
[16:14:56.969] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.8 99.8 99.8 99.9 99.9 99.8 99.8 99.9 99.9 100.0 100.0
[16:14:56.969] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.8 99.7 99.8 99.9 99.8 99.8 99.8 99.8 99.9 100.0 99.9
[16:14:56.969] INFO: X-ray hit rate [MHz/cm2]: 39.5 25.1 38.9 61.4 65.3 71.1 72.8 51.2 47.5 60.5 58.9 50.9 53.4 32.8 14.4 16.6
[16:14:56.969] INFO: PixTestHighRate::doXPixelAlive() done
[16:14:57.020] INFO: PixTest:: pg_setup set to default.
[16:14:57.034] INFO: enter test to run
[16:15:34.995] INFO: test: HighRate no parameter change
[16:15:34.995] INFO: running: highrate
[16:15:34.996] INFO: ----------------------------------------------------------------------
[16:15:34.996] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:15:34.996] INFO: ----------------------------------------------------------------------
[16:15:35.615] INFO: Expecting 208000 events.
[16:15:51.041] INFO: 208000 events read in total (14899ms).
[16:15:51.048] INFO: Test took 16043ms.
[16:15:51.485] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:15:51.829] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 1 0 0 0 1 4 0 0 1
[16:15:51.829] INFO: number of red-efficiency pixels: 465 206 560 1010 845 1056 1056 793 577 730 967 728 602 376 80 121
[16:15:51.830] INFO: number of X-ray hits detected: 202193 129013 198277 313712 332748 361098 369352 259462 243146 307411 299539 260859 269869 167816 72998 84081
[16:15:51.830] 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:15:51.830] INFO: number of Vcal hits detected: 207463 207774 207317 206771 206962 206714 206647 206930 207354 207152 206836 207087 207113 207583 207918 207828
[16:15:51.830] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.7 99.5 99.5 99.4 99.4 99.6 99.7 99.6 99.5 99.6 99.7 99.8 100.0 99.9
[16:15:51.830] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.7 99.4 99.5 99.4 99.3 99.5 99.7 99.6 99.4 99.6 99.6 99.8 100.0 99.9
[16:15:51.830] INFO: X-ray hit rate [MHz/cm2]: 59.3 37.8 58.1 92.0 97.5 105.8 108.3 76.1 71.3 90.1 87.8 76.5 79.1 49.2 21.4 24.6
[16:15:51.830] INFO: PixTestHighRate::doXPixelAlive() done
[16:15:51.877] INFO: PixTest:: pg_setup set to default.
[16:15:51.889] INFO: enter test to run
[16:16:11.179] INFO: test: exit no parameter change
[16:16:11.557] QUIET: Connection to board 33 closed.
[16:16:11.558] INFO: pXar: this is the end, my friend