[16:28:57.447] INFO: *** Welcome to pxar ***
[16:28:57.447] INFO: *** Today: 2016/05/16
[16:28:57.465] INFO: *** Version: v1.9.0-796-gef167-dirty
[16:28:57.465] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-N-3-33_FPIXTest-17C-FNAL-160509-0914_2016-05-09_09h14m_1462803290/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-N-3-33_FPIXTest-17C-FNAL-160509-0914_2016-05-09_09h14m_1462803290/000_FPIXTest_p17//dacParameters35_C15.dat
[16:28:57.487] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-N-3-33_FPIXTest-17C-FNAL-160509-0914_2016-05-09_09h14m_1462803290/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-N-3-33_FPIXTest-17C-FNAL-160509-0914_2016-05-09_09h14m_1462803290/000_FPIXTest_p17//tbmParameters_C0b.dat
[16:28:57.487] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-N-3-33_FPIXTest-17C-FNAL-160509-0914_2016-05-09_09h14m_1462803290/000_FPIXTest_p17//defaultMaskFile.dat
[16:28:57.494] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-N-3-33_FPIXTest-17C-FNAL-160509-0914_2016-05-09_09h14m_1462803290/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-N-3-33_FPIXTest-17C-FNAL-160509-0914_2016-05-09_09h14m_1462803290/000_FPIXTest_p17//trimParameters35_C15.dat
[16:28:57.621] INFO: clk: 4
[16:28:57.621] INFO: ctr: 4
[16:28:57.621] INFO: sda: 19
[16:28:57.621] INFO: tin: 9
[16:28:57.621] INFO: level: 15
[16:28:57.621] INFO: triggerdelay: 0
[16:28:57.621] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[16:28:57.622] INFO: Log level: INFO
[16:28:57.640] QUIET: Connection to board DTB_WREKRL opened.
[16:28:57.643] 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:
------------------------------------------------------
[16:28:57.646] INFO: RPC call hashes of host and DTB match: 398089610
[16:28:59.173] INFO: DUT info:
[16:28:59.174] INFO: The DUT currently contains the following objects:
[16:28:59.174] INFO: 2 TBM Cores tbm08c (2 ON)
[16:28:59.174] INFO: TBM Core alpha (0): 7 registers set
[16:28:59.174] INFO: TBM Core beta (1): 7 registers set
[16:28:59.174] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[16:28:59.174] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[16:28:59.174] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[16:28:59.174] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[16:28:59.174] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[16:28:59.174] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[16:28:59.174] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[16:28:59.174] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[16:28:59.174] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[16:28:59.174] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[16:28:59.174] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[16:28:59.174] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[16:28:59.174] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[16:28:59.174] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[16:28:59.174] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[16:28:59.174] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[16:28:59.174] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[16:28:59.577] INFO: enter 'restricted' command line mode
[16:28:59.577] INFO: enter test to run
[16:29:06.934] INFO: test: PixelAlive no parameter change
[16:29:06.934] INFO: running: pixelalive
[16:29:06.943] INFO: ----------------------------------------------------------------------
[16:29:06.944] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[16:29:06.944] INFO: ----------------------------------------------------------------------
[16:29:07.264] INFO: Expecting 41600 events.
[16:29:11.582] INFO: 41600 events read in total (3599ms).
[16:29:11.750] INFO: Test took 4803ms.
[16:29:11.760] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:29:12.023] INFO: PixTestAlive::aliveTest() done
[16:29:12.023] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[16:29:12.058] INFO: enter test to run
[16:29:39.918] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[16:29:39.918] INFO: running: highrate
[16:29:39.918] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-N-3-33_FPIXTest-17C-FNAL-160509-0914_2016-05-09_09h14m_1462803290/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-N-3-33_FPIXTest-17C-FNAL-160509-0914_2016-05-09_09h14m_1462803290/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[16:29:40.167] INFO: ----------------------------------------------------------------------
[16:29:40.168] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[16:29:40.168] INFO: ----------------------------------------------------------------------
[16:29:40.168] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[16:29:40.168] INFO: edge/corner pixel THR is adjusted
[16:29:40.168] INFO: PixTestHighRate::trimHotPixels: step 0...
[16:29:41.127] INFO: Collecting data for 5 seconds...
[16:29:46.142] INFO: Done with hot pixel readout
[16:29:57.132] INFO: PixTest:: pg_setup set to default.
[16:29:57.133] INFO: 0 hot pixels found in step 0
[16:29:57.145] INFO: 0 hot pixels could not be trimmed and have been masked.
[16:29:57.149] INFO: PixTest::trimHotPixels() done
[16:29:57.166] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-33_FPIXTest-17C-FNAL-160509-0914_2016-05-09_09h14m_1462803290/000_FPIXTest_p17//trimParameters35_C0.dat
[16:29:57.172] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-33_FPIXTest-17C-FNAL-160509-0914_2016-05-09_09h14m_1462803290/000_FPIXTest_p17//trimParameters35_C1.dat
[16:29:57.177] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-33_FPIXTest-17C-FNAL-160509-0914_2016-05-09_09h14m_1462803290/000_FPIXTest_p17//trimParameters35_C2.dat
[16:29:57.182] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-33_FPIXTest-17C-FNAL-160509-0914_2016-05-09_09h14m_1462803290/000_FPIXTest_p17//trimParameters35_C3.dat
[16:29:57.188] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-33_FPIXTest-17C-FNAL-160509-0914_2016-05-09_09h14m_1462803290/000_FPIXTest_p17//trimParameters35_C4.dat
[16:29:57.193] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-33_FPIXTest-17C-FNAL-160509-0914_2016-05-09_09h14m_1462803290/000_FPIXTest_p17//trimParameters35_C5.dat
[16:29:57.198] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-33_FPIXTest-17C-FNAL-160509-0914_2016-05-09_09h14m_1462803290/000_FPIXTest_p17//trimParameters35_C6.dat
[16:29:57.204] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-33_FPIXTest-17C-FNAL-160509-0914_2016-05-09_09h14m_1462803290/000_FPIXTest_p17//trimParameters35_C7.dat
[16:29:57.209] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-33_FPIXTest-17C-FNAL-160509-0914_2016-05-09_09h14m_1462803290/000_FPIXTest_p17//trimParameters35_C8.dat
[16:29:57.214] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-33_FPIXTest-17C-FNAL-160509-0914_2016-05-09_09h14m_1462803290/000_FPIXTest_p17//trimParameters35_C9.dat
[16:29:57.220] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-33_FPIXTest-17C-FNAL-160509-0914_2016-05-09_09h14m_1462803290/000_FPIXTest_p17//trimParameters35_C10.dat
[16:29:57.225] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-33_FPIXTest-17C-FNAL-160509-0914_2016-05-09_09h14m_1462803290/000_FPIXTest_p17//trimParameters35_C11.dat
[16:29:57.230] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-33_FPIXTest-17C-FNAL-160509-0914_2016-05-09_09h14m_1462803290/000_FPIXTest_p17//trimParameters35_C12.dat
[16:29:57.235] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-33_FPIXTest-17C-FNAL-160509-0914_2016-05-09_09h14m_1462803290/000_FPIXTest_p17//trimParameters35_C13.dat
[16:29:57.240] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-33_FPIXTest-17C-FNAL-160509-0914_2016-05-09_09h14m_1462803290/000_FPIXTest_p17//trimParameters35_C14.dat
[16:29:57.246] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-33_FPIXTest-17C-FNAL-160509-0914_2016-05-09_09h14m_1462803290/000_FPIXTest_p17//trimParameters35_C15.dat
[16:29:57.251] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-N-3-33_FPIXTest-17C-FNAL-160509-0914_2016-05-09_09h14m_1462803290/000_FPIXTest_p17//defaultMaskFile.dat
[16:29:57.261] INFO: enter test to run
[16:30:23.310] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[16:30:23.310] INFO: running: highrate
[16:30:23.314] INFO: ----------------------------------------------------------------------
[16:30:23.314] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[16:30:23.314] INFO: ----------------------------------------------------------------------
[16:30:23.314] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[16:30:23.314] INFO: edge/corner pixel THR is adjusted
[16:30:23.314] INFO: PixTestHighRate::trimHotPixels: step 0...
[16:30:24.272] INFO: Collecting data for 1 seconds...
[16:30:25.275] INFO: Done with hot pixel readout
[16:30:28.947] INFO: PixTest:: pg_setup set to default.
[16:30:28.948] INFO: 0 hot pixels found in step 0
[16:30:28.954] INFO: 0 hot pixels could not be trimmed and have been masked.
[16:30:29.054] INFO: PixTest::trimHotPixels() done
[16:30:29.054] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-33_FPIXTest-17C-FNAL-160509-0914_2016-05-09_09h14m_1462803290/000_FPIXTest_p17//trimParameters35_C0.dat
[16:30:29.066] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-33_FPIXTest-17C-FNAL-160509-0914_2016-05-09_09h14m_1462803290/000_FPIXTest_p17//trimParameters35_C1.dat
[16:30:29.071] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-33_FPIXTest-17C-FNAL-160509-0914_2016-05-09_09h14m_1462803290/000_FPIXTest_p17//trimParameters35_C2.dat
[16:30:29.076] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-33_FPIXTest-17C-FNAL-160509-0914_2016-05-09_09h14m_1462803290/000_FPIXTest_p17//trimParameters35_C3.dat
[16:30:29.082] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-33_FPIXTest-17C-FNAL-160509-0914_2016-05-09_09h14m_1462803290/000_FPIXTest_p17//trimParameters35_C4.dat
[16:30:29.087] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-33_FPIXTest-17C-FNAL-160509-0914_2016-05-09_09h14m_1462803290/000_FPIXTest_p17//trimParameters35_C5.dat
[16:30:29.093] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-33_FPIXTest-17C-FNAL-160509-0914_2016-05-09_09h14m_1462803290/000_FPIXTest_p17//trimParameters35_C6.dat
[16:30:29.098] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-33_FPIXTest-17C-FNAL-160509-0914_2016-05-09_09h14m_1462803290/000_FPIXTest_p17//trimParameters35_C7.dat
[16:30:29.103] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-33_FPIXTest-17C-FNAL-160509-0914_2016-05-09_09h14m_1462803290/000_FPIXTest_p17//trimParameters35_C8.dat
[16:30:29.109] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-33_FPIXTest-17C-FNAL-160509-0914_2016-05-09_09h14m_1462803290/000_FPIXTest_p17//trimParameters35_C9.dat
[16:30:29.114] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-33_FPIXTest-17C-FNAL-160509-0914_2016-05-09_09h14m_1462803290/000_FPIXTest_p17//trimParameters35_C10.dat
[16:30:29.119] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-33_FPIXTest-17C-FNAL-160509-0914_2016-05-09_09h14m_1462803290/000_FPIXTest_p17//trimParameters35_C11.dat
[16:30:29.125] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-33_FPIXTest-17C-FNAL-160509-0914_2016-05-09_09h14m_1462803290/000_FPIXTest_p17//trimParameters35_C12.dat
[16:30:29.130] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-33_FPIXTest-17C-FNAL-160509-0914_2016-05-09_09h14m_1462803290/000_FPIXTest_p17//trimParameters35_C13.dat
[16:30:29.135] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-33_FPIXTest-17C-FNAL-160509-0914_2016-05-09_09h14m_1462803290/000_FPIXTest_p17//trimParameters35_C14.dat
[16:30:29.140] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-33_FPIXTest-17C-FNAL-160509-0914_2016-05-09_09h14m_1462803290/000_FPIXTest_p17//trimParameters35_C15.dat
[16:30:29.145] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-N-3-33_FPIXTest-17C-FNAL-160509-0914_2016-05-09_09h14m_1462803290/000_FPIXTest_p17//defaultMaskFile.dat
[16:30:29.162] INFO: enter test to run
[16:30:46.198] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[16:30:46.198] INFO: running: xray
[16:30:46.199] INFO: ----------------------------------------------------------------------
[16:30:46.199] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[16:30:46.199] INFO: ----------------------------------------------------------------------
[16:30:47.162] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[16:30:59.108] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[16:31:27.346] INFO: Resuming triggers.
[16:31:39.293] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[16:32:07.506] INFO: Resuming triggers.
[16:32:19.455] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[16:32:46.854] INFO: Resuming triggers.
[16:32:58.802] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[16:33:26.523] INFO: Resuming triggers.
[16:33:38.473] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[16:34:02.853] INFO: Resuming triggers.
[16:34:14.801] INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[16:34:41.010] INFO: Resuming triggers.
[16:34:52.959] INFO: run duration 83 seconds, buffer almost full (81%), pausing triggers.
[16:35:20.208] INFO: Resuming triggers.
[16:35:32.157] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[16:36:00.732] INFO: Resuming triggers.
[16:36:05.443] INFO: data taking finished, elapsed time: 100 seconds.
[16:36:16.087] INFO: PixTest:: pg_setup set to default.
[16:36:16.091] INFO: PixTestXray::doPhRun() done
[16:36:16.225] INFO: enter test to run
[16:36:36.875] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[16:36:36.875] INFO: running: xray
[16:36:36.876] INFO: ----------------------------------------------------------------------
[16:36:36.876] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[16:36:36.876] INFO: ----------------------------------------------------------------------
[16:36:37.839] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[16:36:45.286] INFO: run duration 7 seconds, buffer almost full (81%), pausing triggers.
[16:37:14.724] INFO: Resuming triggers.
[16:37:22.171] INFO: run duration 14 seconds, buffer almost full (81%), pausing triggers.
[16:37:49.947] INFO: Resuming triggers.
[16:37:57.392] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[16:38:24.953] INFO: Resuming triggers.
[16:38:32.396] INFO: run duration 29 seconds, buffer almost full (81%), pausing triggers.
[16:39:02.034] INFO: Resuming triggers.
[16:39:09.478] INFO: run duration 37 seconds, buffer almost full (81%), pausing triggers.
[16:39:38.275] INFO: Resuming triggers.
[16:39:45.719] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[16:40:15.214] INFO: Resuming triggers.
[16:40:22.664] INFO: run duration 51 seconds, buffer almost full (81%), pausing triggers.
[16:40:52.422] INFO: Resuming triggers.
[16:40:59.867] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[16:41:29.519] INFO: Resuming triggers.
[16:41:36.963] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[16:42:06.511] INFO: Resuming triggers.
[16:42:13.961] INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[16:42:43.570] INFO: Resuming triggers.
[16:42:51.013] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[16:43:19.875] INFO: Resuming triggers.
[16:43:27.320] INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[16:43:57.108] INFO: Resuming triggers.
[16:44:04.553] INFO: run duration 96 seconds, buffer almost full (81%), pausing triggers.
[16:44:34.649] INFO: Resuming triggers.
[16:44:38.174] INFO: data taking finished, elapsed time: 100 seconds.
[16:44:52.665] INFO: PixTest:: pg_setup set to default.
[16:44:52.669] INFO: PixTestXray::doPhRun() done
[16:44:52.820] INFO: enter test to run
[16:45:22.719] INFO: test: HighRate no parameter change
[16:45:22.719] INFO: running: highrate
[16:45:22.720] INFO: ----------------------------------------------------------------------
[16:45:22.720] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[16:45:22.720] INFO: ----------------------------------------------------------------------
[16:45:22.860] INFO: Expecting 768 events.
[16:45:24.003] INFO: 768 events read in total (425ms).
[16:45:24.004] INFO: Test took 1278ms.
[16:45:24.807] INFO: Expecting 41600 events.
[16:45:27.761] INFO: 41600 events read in total (2428ms).
[16:45:27.762] INFO: Test took 3750ms.
[16:45:27.792] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:45:28.526] INFO: Expecting 41600 events.
[16:45:31.640] INFO: 41600 events read in total (2587ms).
[16:45:31.641] INFO: Test took 3834ms.
[16:45:31.672] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:45:32.400] INFO: Expecting 41600 events.
[16:45:35.611] INFO: 41600 events read in total (2684ms).
[16:45:35.612] INFO: Test took 3924ms.
[16:45:35.643] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:45:36.369] INFO: Expecting 41600 events.
[16:45:39.513] INFO: 41600 events read in total (2617ms).
[16:45:39.514] INFO: Test took 3854ms.
[16:45:39.544] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:45:40.272] INFO: Expecting 41600 events.
[16:45:43.370] INFO: 41600 events read in total (2571ms).
[16:45:43.371] INFO: Test took 3810ms.
[16:45:43.402] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:45:44.124] INFO: Expecting 41600 events.
[16:45:47.315] INFO: 41600 events read in total (2664ms).
[16:45:47.316] INFO: Test took 3898ms.
[16:45:47.346] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:45:48.079] INFO: Expecting 41600 events.
[16:45:51.260] INFO: 41600 events read in total (2654ms).
[16:45:51.261] INFO: Test took 3898ms.
[16:45:51.292] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:45:52.021] INFO: Expecting 41600 events.
[16:45:55.218] INFO: 41600 events read in total (2670ms).
[16:45:55.219] INFO: Test took 3912ms.
[16:45:55.250] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:45:55.978] INFO: Expecting 41600 events.
[16:45:59.168] INFO: 41600 events read in total (2663ms).
[16:45:59.169] INFO: Test took 3902ms.
[16:45:59.199] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:45:59.930] INFO: Expecting 41600 events.
[16:46:03.141] INFO: 41600 events read in total (2684ms).
[16:46:03.142] INFO: Test took 3922ms.
[16:46:03.173] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:46:03.902] INFO: Expecting 41600 events.
[16:46:07.109] INFO: 41600 events read in total (2680ms).
[16:46:07.110] INFO: Test took 3920ms.
[16:46:07.141] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:46:07.875] INFO: Expecting 41600 events.
[16:46:11.063] INFO: 41600 events read in total (2661ms).
[16:46:11.064] INFO: Test took 3905ms.
[16:46:11.095] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:46:11.829] INFO: Expecting 41600 events.
[16:46:15.009] INFO: 41600 events read in total (2653ms).
[16:46:15.010] INFO: Test took 3898ms.
[16:46:15.040] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:46:15.772] INFO: Expecting 41600 events.
[16:46:18.955] INFO: 41600 events read in total (2656ms).
[16:46:18.955] INFO: Test took 3897ms.
[16:46:18.985] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:46:19.717] INFO: Expecting 41600 events.
[16:46:22.904] INFO: 41600 events read in total (2660ms).
[16:46:22.905] INFO: Test took 3902ms.
[16:46:22.935] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:46:23.665] INFO: Expecting 41600 events.
[16:46:26.864] INFO: 41600 events read in total (2672ms).
[16:46:26.864] INFO: Test took 3912ms.
[16:46:26.896] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:46:27.629] INFO: Expecting 41600 events.
[16:46:30.631] INFO: 41600 events read in total (2475ms).
[16:46:30.632] INFO: Test took 3719ms.
[16:46:30.663] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:46:31.396] INFO: Expecting 41600 events.
[16:46:34.643] INFO: 41600 events read in total (2661ms).
[16:46:34.644] INFO: Test took 3963ms.
[16:46:34.674] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:46:35.407] INFO: Expecting 41600 events.
[16:46:38.561] INFO: 41600 events read in total (2627ms).
[16:46:38.562] INFO: Test took 3870ms.
[16:46:38.592] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:46:39.321] INFO: Expecting 41600 events.
[16:46:42.344] INFO: 41600 events read in total (2496ms).
[16:46:42.345] INFO: Test took 3735ms.
[16:46:42.373] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:46:42.745] INFO: enter test to run
[16:46:48.863] INFO: test: HighRate no parameter change
[16:46:48.863] INFO: running: highrate
[16:46:48.864] INFO: ----------------------------------------------------------------------
[16:46:48.864] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:46:48.864] INFO: ----------------------------------------------------------------------
[16:46:49.474] INFO: Expecting 208000 events.
[16:47:00.969] INFO: 208000 events read in total (10968ms).
[16:47:00.972] INFO: Test took 12101ms.
[16:47:01.097] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:47:01.342] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[16:47:01.342] INFO: number of red-efficiency pixels: 78 40 67 100 110 121 122 94 71 86 98 99 75 68 20 20
[16:47:01.342] INFO: number of X-ray hits detected: 59679 41284 58570 88065 95747 97845 104397 71523 66628 78755 78731 69099 68743 44496 20406 22382
[16:47:01.342] 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:47:01.342] INFO: number of Vcal hits detected: 207920 207959 207931 207899 207888 207876 207874 207904 207927 207912 207899 207901 207924 207932 207980 207980
[16:47:01.342] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 100.0 99.9 99.9 99.9 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0
[16:47:01.342] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 100.0 99.9 99.9 99.9 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0
[16:47:01.342] INFO: X-ray hit rate [MHz/cm2]: 17.5 12.1 17.2 25.8 28.1 28.7 30.6 21.0 19.5 23.1 23.1 20.3 20.1 13.0 6.0 6.6
[16:47:01.342] INFO: PixTestHighRate::doXPixelAlive() done
[16:47:01.388] INFO: PixTest:: pg_setup set to default.
[16:47:01.405] INFO: enter test to run
[16:47:17.638] INFO: test: HighRate no parameter change
[16:47:17.638] INFO: running: highrate
[16:47:17.639] INFO: ----------------------------------------------------------------------
[16:47:17.639] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:47:17.639] INFO: ----------------------------------------------------------------------
[16:47:18.250] INFO: Expecting 208000 events.
[16:47:31.215] INFO: 208000 events read in total (12439ms).
[16:47:31.220] INFO: Test took 13571ms.
[16:47:31.483] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:47:31.767] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[16:47:31.767] INFO: number of red-efficiency pixels: 150 96 232 309 344 373 332 253 222 239 255 220 166 130 39 53
[16:47:31.767] INFO: number of X-ray hits detected: 121952 84362 118807 179496 195821 198300 212669 145226 136255 159727 160251 141498 140491 90641 42106 46089
[16:47:31.767] 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:47:31.767] INFO: number of Vcal hits detected: 207847 207903 207749 207682 207635 207600 207654 207731 207772 207749 207728 207768 207832 207864 207959 207947
[16:47:31.767] INFO: Vcal hit fiducial efficiency (%): 99.9 100.0 99.9 99.9 99.8 99.8 99.8 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0
[16:47:31.767] INFO: Vcal hit overall efficiency (%): 99.9 100.0 99.9 99.8 99.8 99.8 99.8 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0
[16:47:31.767] INFO: X-ray hit rate [MHz/cm2]: 35.7 24.7 34.8 52.6 57.4 58.1 62.3 42.6 39.9 46.8 47.0 41.5 41.2 26.6 12.3 13.5
[16:47:31.767] INFO: PixTestHighRate::doXPixelAlive() done
[16:47:31.815] INFO: PixTest:: pg_setup set to default.
[16:47:31.829] INFO: enter test to run
[16:47:46.470] INFO: test: HighRate no parameter change
[16:47:46.470] INFO: running: highrate
[16:47:46.471] INFO: ----------------------------------------------------------------------
[16:47:46.471] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:47:46.471] INFO: ----------------------------------------------------------------------
[16:47:47.093] INFO: Expecting 208000 events.
[16:48:01.594] INFO: 208000 events read in total (13974ms).
[16:48:01.600] INFO: Test took 15119ms.
[16:48:01.977] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:48:02.301] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[16:48:02.301] INFO: number of red-efficiency pixels: 312 207 458 639 899 895 738 596 459 560 580 474 330 325 69 78
[16:48:02.301] INFO: number of X-ray hits detected: 183023 126802 179598 269728 295183 299635 320710 218754 204975 239988 243584 213775 211831 136548 62974 69831
[16:48:02.301] 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:48:02.301] INFO: number of Vcal hits detected: 207655 207775 207468 207260 206955 206957 207153 207305 207491 207384 207355 207485 207656 207645 207930 207921
[16:48:02.301] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.8 99.7 99.5 99.5 99.6 99.7 99.8 99.7 99.7 99.8 99.8 99.8 100.0 100.0
[16:48:02.301] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.7 99.6 99.5 99.5 99.6 99.7 99.8 99.7 99.7 99.8 99.8 99.8 100.0 100.0
[16:48:02.301] INFO: X-ray hit rate [MHz/cm2]: 53.6 37.2 52.6 79.1 86.5 87.8 94.0 64.1 60.1 70.3 71.4 62.7 62.1 40.0 18.5 20.5
[16:48:02.301] INFO: PixTestHighRate::doXPixelAlive() done
[16:48:02.350] INFO: PixTest:: pg_setup set to default.
[16:48:02.369] INFO: enter test to run
[16:48:45.014] INFO: test: exit no parameter change
[16:48:45.341] QUIET: Connection to board 33 closed.
[16:48:45.343] INFO: pXar: this is the end, my friend