[13:20:53.334] INFO: *** Welcome to pxar ***
[13:20:53.335] INFO: *** Today: 2016/05/10
[13:20:53.752] INFO: *** Version: v1.9.0-796-gef167-dirty
[13:20:53.752] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Y-I-NB_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-I-NB_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//dacParameters35_C15.dat
[13:20:53.794] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Y-I-NB_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-I-NB_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//tbmParameters_C0b.dat
[13:20:53.794] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Y-I-NB_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//defaultMaskFile.dat
[13:20:53.801] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Y-I-NB_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-I-NB_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C15.dat
[13:20:53.912] INFO: clk: 4
[13:20:53.912] INFO: ctr: 4
[13:20:53.912] INFO: sda: 19
[13:20:53.912] INFO: tin: 9
[13:20:53.912] INFO: level: 15
[13:20:53.912] INFO: triggerdelay: 0
[13:20:53.912] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[13:20:53.912] INFO: Log level: INFO
[13:20:53.930] QUIET: Connection to board DTB_WREKRL opened.
[13:20:53.933] 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:
------------------------------------------------------
[13:20:53.936] INFO: RPC call hashes of host and DTB match: 398089610
[13:20:55.482] INFO: DUT info:
[13:20:55.482] INFO: The DUT currently contains the following objects:
[13:20:55.482] INFO: 2 TBM Cores tbm08c (2 ON)
[13:20:55.482] INFO: TBM Core alpha (0): 7 registers set
[13:20:55.482] INFO: TBM Core beta (1): 7 registers set
[13:20:55.482] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[13:20:55.482] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[13:20:55.482] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[13:20:55.482] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[13:20:55.483] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[13:20:55.483] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[13:20:55.483] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[13:20:55.483] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[13:20:55.483] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[13:20:55.483] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[13:20:55.483] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[13:20:55.483] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[13:20:55.483] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[13:20:55.483] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[13:20:55.483] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[13:20:55.483] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[13:20:55.483] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[13:20:55.905] INFO: enter 'restricted' command line mode
[13:20:55.905] INFO: enter test to run
[13:21:05.653] INFO: test: PixelAlive no parameter change
[13:21:05.653] INFO: running: pixelalive
[13:21:05.662] INFO: ----------------------------------------------------------------------
[13:21:05.662] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[13:21:05.662] INFO: ----------------------------------------------------------------------
[13:21:05.981] INFO: Expecting 41600 events.
[13:21:10.309] INFO: 41600 events read in total (3610ms).
[13:21:10.475] INFO: Test took 4810ms.
[13:21:10.486] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:21:10.777] INFO: PixTestAlive::aliveTest() done
[13:21:10.777] INFO: number of dead pixels (per ROC): 0 0 1 0 0 0 0 0 0 0 0 0 0 0 0 0
[13:21:10.808] INFO: enter test to run
[13:21:39.629] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[13:21:39.629] INFO: running: highrate
[13:21:39.629] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Y-I-NB_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-I-NB_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[13:21:39.831] INFO: ----------------------------------------------------------------------
[13:21:39.831] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[13:21:39.831] INFO: ----------------------------------------------------------------------
[13:21:39.831] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[13:21:39.831] INFO: edge/corner pixel THR is adjusted
[13:21:39.831] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:21:40.791] INFO: Collecting data for 5 seconds...
[13:21:45.808] INFO: Done with hot pixel readout
[13:21:58.752] INFO: PixTest:: pg_setup set to default.



[13:21:58.782] INFO: 137 hot pixels found in step 0
[13:21:59.776] INFO: Collecting data for 5 seconds...
[13:22:04.793] INFO: Done with hot pixel readout
[13:22:17.736] INFO: PixTest:: pg_setup set to default.








[13:22:17.737] INFO: 130 hot pixels found in step 1
[13:22:18.735] INFO: Collecting data for 5 seconds...
[13:22:23.752] INFO: Done with hot pixel readout
[13:22:36.629] INFO: PixTest:: pg_setup set to default.







[13:22:36.631] INFO: 107 hot pixels found in step 2
[13:22:37.629] INFO: Collecting data for 5 seconds...
[13:22:42.646] INFO: Done with hot pixel readout
[13:22:55.589] INFO: PixTest:: pg_setup set to default.






[13:22:55.590] INFO: 100 hot pixels found in step 3
[13:22:56.589] INFO: Collecting data for 5 seconds...
[13:23:01.606] INFO: Done with hot pixel readout
[13:23:14.570] INFO: PixTest:: pg_setup set to default.








[13:23:14.571] INFO: 104 hot pixels found in step 4
[13:23:15.571] INFO: Collecting data for 5 seconds...
[13:23:20.587] INFO: Done with hot pixel readout
[13:23:33.503] INFO: PixTest:: pg_setup set to default.














[13:23:33.504] INFO: 114 hot pixels found in step 5
[13:23:34.504] INFO: Collecting data for 5 seconds...
[13:23:39.521] INFO: Done with hot pixel readout
[13:23:52.451] INFO: PixTest:: pg_setup set to default.








[13:23:52.452] INFO: 91 hot pixels found in step 6
[13:23:53.451] INFO: Collecting data for 5 seconds...
[13:23:58.468] INFO: Done with hot pixel readout
[13:24:11.414] INFO: PixTest:: pg_setup set to default.















[13:24:11.415] INFO: 91 hot pixels found in step 7
[13:24:12.413] INFO: Collecting data for 5 seconds...
[13:24:17.430] INFO: Done with hot pixel readout
[13:24:30.359] INFO: PixTest:: pg_setup set to default.





[13:24:30.361] INFO: 76 hot pixels found in step 8
[13:24:31.359] INFO: Collecting data for 5 seconds...
[13:24:36.376] INFO: Done with hot pixel readout
[13:24:49.297] INFO: PixTest:: pg_setup set to default.








[13:24:49.298] INFO: 74 hot pixels found in step 9
[13:24:50.297] INFO: Collecting data for 5 seconds...
[13:24:55.315] INFO: Done with hot pixel readout
[13:25:08.245] INFO: PixTest:: pg_setup set to default.







[13:25:08.246] INFO: 71 hot pixels found in step 10
[13:25:09.244] INFO: Collecting data for 5 seconds...
[13:25:14.261] INFO: Done with hot pixel readout
[13:25:27.197] INFO: PixTest:: pg_setup set to default.







[13:25:27.200] INFO: 68 hot pixels found in step 11
[13:25:28.201] INFO: Collecting data for 5 seconds...
[13:25:33.218] INFO: Done with hot pixel readout
[13:25:46.198] INFO: PixTest:: pg_setup set to default.












[13:25:46.199] INFO: 69 hot pixels found in step 12
[13:25:47.197] INFO: Collecting data for 5 seconds...
[13:25:52.214] INFO: Done with hot pixel readout
[13:26:05.188] INFO: PixTest:: pg_setup set to default.









[13:26:05.189] INFO: 57 hot pixels found in step 13
[13:26:06.189] INFO: Collecting data for 5 seconds...
[13:26:11.206] INFO: Done with hot pixel readout
[13:26:24.134] INFO: PixTest:: pg_setup set to default.















[13:26:24.135] INFO: 56 hot pixels found in step 14
[13:26:24.177] INFO: 56 hot pixels could not be trimmed and have been masked.
[13:26:24.181] INFO: PixTest::trimHotPixels() done
[13:26:24.181] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-I-NB_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C0.dat
[13:26:24.187] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-I-NB_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C1.dat
[13:26:24.194] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-I-NB_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C2.dat
[13:26:24.199] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-I-NB_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C3.dat
[13:26:24.204] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-I-NB_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C4.dat
[13:26:24.209] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-I-NB_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C5.dat
[13:26:24.214] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-I-NB_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C6.dat
[13:26:24.219] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-I-NB_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C7.dat
[13:26:24.224] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-I-NB_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C8.dat
[13:26:24.230] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-I-NB_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C9.dat
[13:26:24.235] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-I-NB_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C10.dat
[13:26:24.240] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-I-NB_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C11.dat
[13:26:24.245] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-I-NB_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C12.dat
[13:26:24.250] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-I-NB_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C13.dat
[13:26:24.256] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-I-NB_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C14.dat
[13:26:24.261] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-I-NB_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C15.dat
[13:26:24.266] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Y-I-NB_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//defaultMaskFile.dat
[13:26:24.276] INFO: enter test to run
[13:27:01.154] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[13:27:01.154] INFO: running: highrate
[13:27:01.159] INFO: ----------------------------------------------------------------------
[13:27:01.159] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[13:27:01.159] INFO: ----------------------------------------------------------------------
[13:27:01.159] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[13:27:01.159] INFO: edge/corner pixel THR is adjusted
[13:27:01.159] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:27:02.116] INFO: Collecting data for 1 seconds...
[13:27:03.120] INFO: Done with hot pixel readout
[13:27:07.808] INFO: PixTest:: pg_setup set to default.
[13:27:07.809] INFO: 0 hot pixels found in step 0
[13:27:07.815] INFO: 0 hot pixels could not be trimmed and have been masked.
[13:27:07.876] INFO: PixTest::trimHotPixels() done
[13:27:07.876] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-I-NB_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C0.dat
[13:27:07.888] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-I-NB_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C1.dat
[13:27:07.899] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-I-NB_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C2.dat
[13:27:07.904] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-I-NB_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C3.dat
[13:27:07.909] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-I-NB_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C4.dat
[13:27:07.915] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-I-NB_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C5.dat
[13:27:07.920] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-I-NB_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C6.dat
[13:27:07.925] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-I-NB_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C7.dat
[13:27:07.931] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-I-NB_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C8.dat
[13:27:07.936] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-I-NB_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C9.dat
[13:27:07.942] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-I-NB_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C10.dat
[13:27:07.947] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-I-NB_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C11.dat
[13:27:07.952] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-I-NB_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C12.dat
[13:27:07.958] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-I-NB_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C13.dat
[13:27:07.963] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-I-NB_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C14.dat
[13:27:07.968] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-I-NB_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//trimParameters35_C15.dat
[13:27:07.973] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Y-I-NB_FPIXTest-17C-FNAL-160503-1254_2016-05-03_12h54m_1462298098/000_FPIXTest_p17//defaultMaskFile.dat
[13:27:07.983] INFO: enter test to run
[13:27:37.730] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[13:27:37.730] INFO: running: xray
[13:27:37.751] INFO: ----------------------------------------------------------------------
[13:27:37.751] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:27:37.751] INFO: ----------------------------------------------------------------------
[13:27:38.712] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:27:48.912] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[13:28:18.771] INFO: Resuming triggers.
[13:28:28.971] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[13:28:59.232] INFO: Resuming triggers.
[13:29:09.432] INFO: run duration 30 seconds, buffer almost full (81%), pausing triggers.
[13:29:39.793] INFO: Resuming triggers.
[13:29:49.993] INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[13:30:19.306] INFO: Resuming triggers.
[13:30:29.506] INFO: run duration 50 seconds, buffer almost full (81%), pausing triggers.
[13:30:59.065] INFO: Resuming triggers.
[13:31:09.268] INFO: run duration 60 seconds, buffer almost full (81%), pausing triggers.
[13:31:38.729] INFO: Resuming triggers.
[13:31:48.932] INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[13:32:18.472] INFO: Resuming triggers.
[13:32:28.674] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[13:32:58.260] INFO: Resuming triggers.
[13:33:08.468] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[13:33:37.959] INFO: Resuming triggers.
[13:33:46.500] INFO: data taking finished, elapsed time: 100 seconds.
[13:34:11.505] INFO: PixTest:: pg_setup set to default.
[13:34:11.508] INFO: PixTestXray::doPhRun() done
[13:34:11.649] INFO: enter test to run
[13:34:54.527] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[13:34:54.527] INFO: running: xray
[13:34:54.528] INFO: ----------------------------------------------------------------------
[13:34:54.528] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:34:54.528] INFO: ----------------------------------------------------------------------
[13:34:55.501] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:35:00.895] INFO: run duration 5 seconds, buffer almost full (81%), pausing triggers.
[13:35:30.983] INFO: Resuming triggers.
[13:35:36.380] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[13:36:06.549] INFO: Resuming triggers.
[13:36:11.945] INFO: run duration 16 seconds, buffer almost full (81%), pausing triggers.
[13:36:42.159] INFO: Resuming triggers.
[13:36:47.551] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[13:37:17.597] INFO: Resuming triggers.
[13:37:22.992] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[13:37:53.158] INFO: Resuming triggers.
[13:37:58.549] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[13:38:29.748] INFO: Resuming triggers.
[13:38:35.138] INFO: run duration 37 seconds, buffer almost full (81%), pausing triggers.
[13:39:05.669] INFO: Resuming triggers.
[13:39:11.059] INFO: run duration 42 seconds, buffer almost full (81%), pausing triggers.
[13:39:42.280] INFO: Resuming triggers.
[13:39:47.672] INFO: run duration 48 seconds, buffer almost full (81%), pausing triggers.
[13:40:18.906] INFO: Resuming triggers.
[13:40:24.299] INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[13:40:54.758] INFO: Resuming triggers.
[13:41:00.149] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[13:41:30.377] INFO: Resuming triggers.
[13:41:35.774] INFO: run duration 64 seconds, buffer almost full (81%), pausing triggers.
[13:42:05.878] INFO: Resuming triggers.
[13:42:11.275] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[13:42:41.446] INFO: Resuming triggers.
[13:42:46.844] INFO: run duration 75 seconds, buffer almost full (81%), pausing triggers.
[13:43:16.971] INFO: Resuming triggers.
[13:43:22.369] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[13:43:52.462] INFO: Resuming triggers.
[13:43:57.859] INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[13:44:27.004] INFO: Resuming triggers.
[13:44:33.399] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[13:45:03.564] INFO: Resuming triggers.
[13:45:08.958] INFO: run duration 96 seconds, buffer almost full (81%), pausing triggers.
[13:45:38.003] INFO: Resuming triggers.
[13:45:42.252] INFO: data taking finished, elapsed time: 100 seconds.
[13:46:00.613] INFO: PixTest:: pg_setup set to default.
[13:46:00.616] INFO: PixTestXray::doPhRun() done
[13:46:00.766] INFO: enter test to run
[13:46:23.538] INFO: test: HighRate no parameter change
[13:46:23.538] INFO: running: highrate
[13:46:23.539] INFO: ----------------------------------------------------------------------
[13:46:23.539] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[13:46:23.539] INFO: ----------------------------------------------------------------------
[13:46:23.691] INFO: Expecting 768 events.
[13:46:24.825] INFO: 768 events read in total (419ms).
[13:46:24.825] INFO: Test took 1278ms.
[13:46:25.628] INFO: Expecting 41600 events.
[13:46:28.777] INFO: 41600 events read in total (2622ms).
[13:46:28.778] INFO: Test took 3906ms.
[13:46:28.820] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:46:29.532] INFO: Expecting 41600 events.
[13:46:32.835] INFO: 41600 events read in total (2776ms).
[13:46:32.836] INFO: Test took 3995ms.
[13:46:32.880] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:46:33.582] INFO: Expecting 41600 events.
[13:46:36.907] INFO: 41600 events read in total (2798ms).
[13:46:36.908] INFO: Test took 4006ms.
[13:46:36.951] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:46:37.658] INFO: Expecting 41600 events.
[13:46:40.974] INFO: 41600 events read in total (2790ms).
[13:46:40.975] INFO: Test took 4002ms.
[13:46:41.019] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:46:41.724] INFO: Expecting 41600 events.
[13:46:45.055] INFO: 41600 events read in total (2804ms).
[13:46:45.056] INFO: Test took 4016ms.
[13:46:45.100] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:46:45.806] INFO: Expecting 41600 events.
[13:46:49.134] INFO: 41600 events read in total (2801ms).
[13:46:49.135] INFO: Test took 4013ms.
[13:46:49.179] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:46:49.883] INFO: Expecting 41600 events.
[13:46:53.214] INFO: 41600 events read in total (2804ms).
[13:46:53.215] INFO: Test took 4015ms.
[13:46:53.258] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:46:53.963] INFO: Expecting 41600 events.
[13:46:57.306] INFO: 41600 events read in total (2816ms).
[13:46:57.307] INFO: Test took 4028ms.
[13:46:57.350] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:46:58.055] INFO: Expecting 41600 events.
[13:47:01.397] INFO: 41600 events read in total (2815ms).
[13:47:01.399] INFO: Test took 4028ms.
[13:47:01.442] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:47:02.144] INFO: Expecting 41600 events.
[13:47:05.478] INFO: 41600 events read in total (2807ms).
[13:47:05.479] INFO: Test took 4017ms.
[13:47:05.523] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:47:06.229] INFO: Expecting 41600 events.
[13:47:09.562] INFO: 41600 events read in total (2806ms).
[13:47:09.563] INFO: Test took 4019ms.
[13:47:09.605] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:47:10.315] INFO: Expecting 41600 events.
[13:47:13.667] INFO: 41600 events read in total (2826ms).
[13:47:13.668] INFO: Test took 4042ms.
[13:47:13.711] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:47:14.420] INFO: Expecting 41600 events.
[13:47:17.755] INFO: 41600 events read in total (2808ms).
[13:47:17.756] INFO: Test took 4024ms.
[13:47:17.799] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:47:18.505] INFO: Expecting 41600 events.
[13:47:21.835] INFO: 41600 events read in total (2803ms).
[13:47:21.836] INFO: Test took 4015ms.
[13:47:21.880] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:47:22.585] INFO: Expecting 41600 events.
[13:47:25.939] INFO: 41600 events read in total (2827ms).
[13:47:25.940] INFO: Test took 4037ms.
[13:47:25.984] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:47:26.688] INFO: Expecting 41600 events.
[13:47:30.029] INFO: 41600 events read in total (2814ms).
[13:47:30.030] INFO: Test took 4024ms.
[13:47:30.073] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:47:30.777] INFO: Expecting 41600 events.
[13:47:34.110] INFO: 41600 events read in total (2806ms).
[13:47:34.111] INFO: Test took 4017ms.
[13:47:34.154] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:47:34.859] INFO: Expecting 41600 events.
[13:47:38.192] INFO: 41600 events read in total (2806ms).
[13:47:38.193] INFO: Test took 4016ms.
[13:47:38.236] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:47:38.944] INFO: Expecting 41600 events.
[13:47:42.282] INFO: 41600 events read in total (2811ms).
[13:47:42.283] INFO: Test took 4026ms.
[13:47:42.326] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:47:43.031] INFO: Expecting 41600 events.
[13:47:46.217] INFO: 41600 events read in total (2659ms).
[13:47:46.218] INFO: Test took 3869ms.
[13:47:46.261] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:47:46.609] INFO: enter test to run
[13:47:55.545] INFO: test: HighRate no parameter change
[13:47:55.545] INFO: running: highrate
[13:47:55.546] INFO: ----------------------------------------------------------------------
[13:47:55.546] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:47:55.547] INFO: ----------------------------------------------------------------------
[13:47:56.157] INFO: Expecting 208000 events.
[13:48:08.554] INFO: 208000 events read in total (11870ms).
[13:48:08.558] INFO: Test took 13004ms.
[13:48:08.744] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:48:09.012] INFO: number of dead pixels (per ROC): 0 0 1 0 0 0 0 0 0 0 0 0 0 0 0 0
[13:48:09.012] INFO: number of red-efficiency pixels: 116 70 125 185 174 176 209 138 142 181 206 199 148 110 31 38
[13:48:09.012] INFO: number of X-ray hits detected: 84646 58065 88839 133603 141648 146822 142378 103506 106193 143443 143596 124622 125242 76220 30402 29460
[13:48:09.012] 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:48:09.012] INFO: number of Vcal hits detected: 207882 207928 207821 207809 207823 207818 207784 207861 207854 207810 207788 207799 207847 207887 207969 207962
[13:48:09.012] INFO: Vcal hit fiducial efficiency (%): 99.9 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0
[13:48:09.012] INFO: Vcal hit overall efficiency (%): 99.9 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0
[13:48:09.012] INFO: X-ray hit rate [MHz/cm2]: 24.8 17.0 26.0 39.2 41.5 43.0 41.7 30.3 31.1 42.0 42.1 36.5 36.7 22.3 8.9 8.6
[13:48:09.012] INFO: PixTestHighRate::doXPixelAlive() done
[13:48:09.062] INFO: PixTest:: pg_setup set to default.
[13:48:09.076] INFO: enter test to run
[13:48:31.913] INFO: test: HighRate no parameter change
[13:48:31.913] INFO: running: highrate
[13:48:31.914] INFO: ----------------------------------------------------------------------
[13:48:31.914] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:48:31.914] INFO: ----------------------------------------------------------------------
[13:48:32.528] INFO: Expecting 208000 events.
[13:48:47.643] INFO: 208000 events read in total (14588ms).
[13:48:47.650] INFO: Test took 15727ms.
[13:48:48.045] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:48:48.380] INFO: number of dead pixels (per ROC): 0 0 1 0 0 0 0 0 0 0 0 0 0 0 0 0
[13:48:48.380] INFO: number of red-efficiency pixels: 390 161 436 723 660 854 902 501 508 698 843 786 590 425 84 74
[13:48:48.380] INFO: number of X-ray hits detected: 182490 125234 191978 286603 305498 314779 307231 223083 229492 306603 308758 269987 270227 164431 65336 63879
[13:48:48.380] 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:48:48.380] INFO: number of Vcal hits detected: 207561 207835 207444 207175 207242 206973 206941 207432 207424 207190 206996 207082 207343 207490 207913 207924
[13:48:48.380] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.8 99.6 99.7 99.6 99.5 99.7 99.7 99.6 99.6 99.6 99.7 99.8 100.0 100.0
[13:48:48.380] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.7 99.6 99.6 99.5 99.5 99.7 99.7 99.6 99.5 99.6 99.7 99.8 100.0 100.0
[13:48:48.380] INFO: X-ray hit rate [MHz/cm2]: 53.5 36.7 56.3 84.0 89.5 92.3 90.1 65.4 67.3 89.9 90.5 79.1 79.2 48.2 19.2 18.7
[13:48:48.380] INFO: PixTestHighRate::doXPixelAlive() done
[13:48:48.428] INFO: PixTest:: pg_setup set to default.
[13:48:48.440] INFO: enter test to run
[13:49:09.593] INFO: test: HighRate no parameter change
[13:49:09.593] INFO: running: highrate
[13:49:09.594] INFO: ----------------------------------------------------------------------
[13:49:09.594] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:49:09.594] INFO: ----------------------------------------------------------------------
[13:49:10.213] INFO: Expecting 208000 events.
[13:49:28.392] INFO: 208000 events read in total (17652ms).
[13:49:28.404] INFO: Test took 18801ms.
[13:49:29.052] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:49:29.461] INFO: number of dead pixels (per ROC): 0 0 1 0 0 0 0 0 0 0 0 0 0 0 0 0
[13:49:29.461] INFO: number of red-efficiency pixels: 879 394 889 1632 1600 1910 2078 1066 1139 1638 1885 1715 1291 982 171 112
[13:49:29.461] INFO: number of X-ray hits detected: 274134 187802 287949 427695 455831 471057 458220 335121 344884 459375 461361 404345 402753 246269 98593 95921
[13:49:29.461] 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:49:29.461] INFO: number of Vcal hits detected: 206772 207548 206590 205603 205754 205028 204660 206452 206375 205531 204984 205319 206256 206515 207820 207885
[13:49:29.461] INFO: Vcal hit fiducial efficiency (%): 99.5 99.8 99.4 99.0 99.0 98.7 98.6 99.3 99.3 98.9 98.7 98.9 99.3 99.4 99.9 99.9
[13:49:29.461] INFO: Vcal hit overall efficiency (%): 99.4 99.8 99.3 98.8 98.9 98.6 98.4 99.3 99.2 98.8 98.6 98.7 99.2 99.3 99.9 99.9
[13:49:29.461] INFO: X-ray hit rate [MHz/cm2]: 80.4 55.0 84.4 125.4 133.6 138.1 134.3 98.2 101.1 134.6 135.2 118.5 118.0 72.2 28.9 28.1
[13:49:29.461] INFO: PixTestHighRate::doXPixelAlive() done
[13:49:29.506] INFO: PixTest:: pg_setup set to default.
[13:49:29.525] INFO: enter test to run
[13:49:35.112] INFO: test: exit no parameter change
[13:49:35.436] QUIET: Connection to board 33 closed.
[13:49:35.436] INFO: pXar: this is the end, my friend