[11:25:13.290] INFO: *** Welcome to pxar ***
[11:25:13.290] INFO: *** Today: 2016/05/10
[11:25:13.307] INFO: *** Version: v1.9.0-796-gef167-dirty
[11:25:13.308] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-M-4-05_FPIXTest-17C-FNAL-160505-1051_2016-05-05_10h51m_1462463477/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-M-4-05_FPIXTest-17C-FNAL-160505-1051_2016-05-05_10h51m_1462463477/000_FPIXTest_p17//dacParameters35_C15.dat
[11:25:13.341] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-M-4-05_FPIXTest-17C-FNAL-160505-1051_2016-05-05_10h51m_1462463477/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-M-4-05_FPIXTest-17C-FNAL-160505-1051_2016-05-05_10h51m_1462463477/000_FPIXTest_p17//tbmParameters_C0b.dat
[11:25:13.342] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-M-4-05_FPIXTest-17C-FNAL-160505-1051_2016-05-05_10h51m_1462463477/000_FPIXTest_p17//defaultMaskFile.dat
[11:25:13.350] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-M-4-05_FPIXTest-17C-FNAL-160505-1051_2016-05-05_10h51m_1462463477/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-M-4-05_FPIXTest-17C-FNAL-160505-1051_2016-05-05_10h51m_1462463477/000_FPIXTest_p17//trimParameters35_C15.dat
[11:25:13.458] INFO: clk: 4
[11:25:13.458] INFO: ctr: 4
[11:25:13.458] INFO: sda: 19
[11:25:13.458] INFO: tin: 9
[11:25:13.458] INFO: level: 15
[11:25:13.458] INFO: triggerdelay: 0
[11:25:13.458] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[11:25:13.458] INFO: Log level: INFO
[11:25:13.474] QUIET: Connection to board DTB_WREKRL opened.
[11:25:13.477] 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:25:13.480] INFO: RPC call hashes of host and DTB match: 398089610
[11:25:15.016] INFO: DUT info:
[11:25:15.016] INFO: The DUT currently contains the following objects:
[11:25:15.016] INFO: 2 TBM Cores tbm08c (2 ON)
[11:25:15.016] INFO: TBM Core alpha (0): 7 registers set
[11:25:15.016] INFO: TBM Core beta (1): 7 registers set
[11:25:15.016] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[11:25:15.016] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[11:25:15.017] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[11:25:15.017] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[11:25:15.017] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[11:25:15.017] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[11:25:15.017] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[11:25:15.017] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[11:25:15.017] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[11:25:15.017] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[11:25:15.017] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[11:25:15.017] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[11:25:15.017] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[11:25:15.017] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[11:25:15.017] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[11:25:15.017] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[11:25:15.017] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[11:25:15.420] INFO: enter 'restricted' command line mode
[11:25:15.420] INFO: enter test to run
[11:25:34.272] INFO: test: PixelAlive no parameter change
[11:25:34.272] INFO: running: pixelalive
[11:25:34.281] INFO: ----------------------------------------------------------------------
[11:25:34.281] 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:25:34.281] INFO: ----------------------------------------------------------------------
[11:25:34.605] INFO: Expecting 41600 events.
[11:25:38.913] INFO: 41600 events read in total (3589ms).
[11:25:39.067] INFO: Test took 4784ms.
[11:25:39.075] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:25:39.338] INFO: PixTestAlive::aliveTest() done
[11:25:39.338] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:25:39.371] INFO: enter test to run
[11:26:07.096] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[11:26:07.096] INFO: running: highrate
[11:26:07.096] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-M-4-05_FPIXTest-17C-FNAL-160505-1051_2016-05-05_10h51m_1462463477/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-M-4-05_FPIXTest-17C-FNAL-160505-1051_2016-05-05_10h51m_1462463477/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[11:26:07.351] INFO: ----------------------------------------------------------------------
[11:26:07.351] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[11:26:07.351] INFO: ----------------------------------------------------------------------
[11:26:07.351] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[11:26:07.351] INFO: edge/corner pixel THR is adjusted
[11:26:07.351] INFO: PixTestHighRate::trimHotPixels: step 0...
[11:26:08.310] INFO: Collecting data for 5 seconds...
[11:26:13.329] INFO: Done with hot pixel readout
[11:26:25.016] INFO: PixTest:: pg_setup set to default.
[11:26:25.017] INFO: 9 hot pixels found in step 0
[11:26:26.031] INFO: Collecting data for 5 seconds...
[11:26:31.050] INFO: Done with hot pixel readout
[11:26:42.834] INFO: PixTest:: pg_setup set to default.
[11:26:42.835] INFO: 6 hot pixels found in step 1
[11:26:43.825] INFO: Collecting data for 5 seconds...
[11:26:48.843] INFO: Done with hot pixel readout
[11:27:00.653] INFO: PixTest:: pg_setup set to default.
[11:27:00.654] INFO: 12 hot pixels found in step 2
[11:27:01.642] INFO: Collecting data for 5 seconds...
[11:27:06.658] INFO: Done with hot pixel readout
[11:27:18.365] INFO: PixTest:: pg_setup set to default.
[11:27:18.366] INFO: 10 hot pixels found in step 3
[11:27:19.355] INFO: Collecting data for 5 seconds...
[11:27:24.374] INFO: Done with hot pixel readout
[11:27:36.227] INFO: PixTest:: pg_setup set to default.

[11:27:36.228] INFO: 7 hot pixels found in step 4
[11:27:37.216] INFO: Collecting data for 5 seconds...
[11:27:42.232] INFO: Done with hot pixel readout
[11:27:53.918] INFO: PixTest:: pg_setup set to default.

[11:27:53.919] INFO: 8 hot pixels found in step 5
[11:27:54.907] INFO: Collecting data for 5 seconds...
[11:27:59.925] INFO: Done with hot pixel readout
[11:28:11.619] INFO: PixTest:: pg_setup set to default.
[11:28:11.620] INFO: 5 hot pixels found in step 6
[11:28:12.608] INFO: Collecting data for 5 seconds...
[11:28:17.624] INFO: Done with hot pixel readout
[11:28:29.321] INFO: PixTest:: pg_setup set to default.


[11:28:29.322] INFO: 4 hot pixels found in step 7
[11:28:30.310] INFO: Collecting data for 5 seconds...
[11:28:35.327] INFO: Done with hot pixel readout
[11:28:47.041] INFO: PixTest:: pg_setup set to default.

[11:28:47.042] INFO: 7 hot pixels found in step 8
[11:28:48.030] INFO: Collecting data for 5 seconds...
[11:28:53.046] INFO: Done with hot pixel readout
[11:29:04.717] INFO: PixTest:: pg_setup set to default.

[11:29:04.718] INFO: 1 hot pixels found in step 9
[11:29:04.750] INFO: 1 hot pixels could not be trimmed and have been masked.
[11:29:04.754] INFO: PixTest::trimHotPixels() done
[11:29:04.758] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-05_FPIXTest-17C-FNAL-160505-1051_2016-05-05_10h51m_1462463477/000_FPIXTest_p17//trimParameters35_C0.dat
[11:29:04.764] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-05_FPIXTest-17C-FNAL-160505-1051_2016-05-05_10h51m_1462463477/000_FPIXTest_p17//trimParameters35_C1.dat
[11:29:04.769] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-05_FPIXTest-17C-FNAL-160505-1051_2016-05-05_10h51m_1462463477/000_FPIXTest_p17//trimParameters35_C2.dat
[11:29:04.775] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-05_FPIXTest-17C-FNAL-160505-1051_2016-05-05_10h51m_1462463477/000_FPIXTest_p17//trimParameters35_C3.dat
[11:29:04.780] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-05_FPIXTest-17C-FNAL-160505-1051_2016-05-05_10h51m_1462463477/000_FPIXTest_p17//trimParameters35_C4.dat
[11:29:04.785] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-05_FPIXTest-17C-FNAL-160505-1051_2016-05-05_10h51m_1462463477/000_FPIXTest_p17//trimParameters35_C5.dat
[11:29:04.790] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-05_FPIXTest-17C-FNAL-160505-1051_2016-05-05_10h51m_1462463477/000_FPIXTest_p17//trimParameters35_C6.dat
[11:29:04.795] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-05_FPIXTest-17C-FNAL-160505-1051_2016-05-05_10h51m_1462463477/000_FPIXTest_p17//trimParameters35_C7.dat
[11:29:04.801] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-05_FPIXTest-17C-FNAL-160505-1051_2016-05-05_10h51m_1462463477/000_FPIXTest_p17//trimParameters35_C8.dat
[11:29:04.806] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-05_FPIXTest-17C-FNAL-160505-1051_2016-05-05_10h51m_1462463477/000_FPIXTest_p17//trimParameters35_C9.dat
[11:29:04.811] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-05_FPIXTest-17C-FNAL-160505-1051_2016-05-05_10h51m_1462463477/000_FPIXTest_p17//trimParameters35_C10.dat
[11:29:04.816] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-05_FPIXTest-17C-FNAL-160505-1051_2016-05-05_10h51m_1462463477/000_FPIXTest_p17//trimParameters35_C11.dat
[11:29:04.821] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-05_FPIXTest-17C-FNAL-160505-1051_2016-05-05_10h51m_1462463477/000_FPIXTest_p17//trimParameters35_C12.dat
[11:29:04.826] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-05_FPIXTest-17C-FNAL-160505-1051_2016-05-05_10h51m_1462463477/000_FPIXTest_p17//trimParameters35_C13.dat
[11:29:04.832] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-05_FPIXTest-17C-FNAL-160505-1051_2016-05-05_10h51m_1462463477/000_FPIXTest_p17//trimParameters35_C14.dat
[11:29:04.837] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-05_FPIXTest-17C-FNAL-160505-1051_2016-05-05_10h51m_1462463477/000_FPIXTest_p17//trimParameters35_C15.dat
[11:29:04.842] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-M-4-05_FPIXTest-17C-FNAL-160505-1051_2016-05-05_10h51m_1462463477/000_FPIXTest_p17//defaultMaskFile.dat
[11:29:04.852] INFO: enter test to run
[11:29:39.638] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[11:29:39.638] INFO: running: highrate
[11:29:39.642] INFO: ----------------------------------------------------------------------
[11:29:39.642] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[11:29:39.642] INFO: ----------------------------------------------------------------------
[11:29:39.642] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[11:29:39.642] INFO: edge/corner pixel THR is adjusted
[11:29:39.642] INFO: PixTestHighRate::trimHotPixels: step 0...
[11:29:40.600] INFO: Collecting data for 1 seconds...
[11:29:41.604] INFO: Done with hot pixel readout
[11:29:45.637] INFO: PixTest:: pg_setup set to default.
[11:29:45.638] INFO: 0 hot pixels found in step 0
[11:29:45.643] INFO: 0 hot pixels could not be trimmed and have been masked.
[11:29:45.731] INFO: PixTest::trimHotPixels() done
[11:29:45.731] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-05_FPIXTest-17C-FNAL-160505-1051_2016-05-05_10h51m_1462463477/000_FPIXTest_p17//trimParameters35_C0.dat
[11:29:45.743] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-05_FPIXTest-17C-FNAL-160505-1051_2016-05-05_10h51m_1462463477/000_FPIXTest_p17//trimParameters35_C1.dat
[11:29:45.750] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-05_FPIXTest-17C-FNAL-160505-1051_2016-05-05_10h51m_1462463477/000_FPIXTest_p17//trimParameters35_C2.dat
[11:29:45.755] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-05_FPIXTest-17C-FNAL-160505-1051_2016-05-05_10h51m_1462463477/000_FPIXTest_p17//trimParameters35_C3.dat
[11:29:45.760] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-05_FPIXTest-17C-FNAL-160505-1051_2016-05-05_10h51m_1462463477/000_FPIXTest_p17//trimParameters35_C4.dat
[11:29:45.765] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-05_FPIXTest-17C-FNAL-160505-1051_2016-05-05_10h51m_1462463477/000_FPIXTest_p17//trimParameters35_C5.dat
[11:29:45.770] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-05_FPIXTest-17C-FNAL-160505-1051_2016-05-05_10h51m_1462463477/000_FPIXTest_p17//trimParameters35_C6.dat
[11:29:45.775] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-05_FPIXTest-17C-FNAL-160505-1051_2016-05-05_10h51m_1462463477/000_FPIXTest_p17//trimParameters35_C7.dat
[11:29:45.781] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-05_FPIXTest-17C-FNAL-160505-1051_2016-05-05_10h51m_1462463477/000_FPIXTest_p17//trimParameters35_C8.dat
[11:29:45.786] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-05_FPIXTest-17C-FNAL-160505-1051_2016-05-05_10h51m_1462463477/000_FPIXTest_p17//trimParameters35_C9.dat
[11:29:45.791] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-05_FPIXTest-17C-FNAL-160505-1051_2016-05-05_10h51m_1462463477/000_FPIXTest_p17//trimParameters35_C10.dat
[11:29:45.796] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-05_FPIXTest-17C-FNAL-160505-1051_2016-05-05_10h51m_1462463477/000_FPIXTest_p17//trimParameters35_C11.dat
[11:29:45.802] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-05_FPIXTest-17C-FNAL-160505-1051_2016-05-05_10h51m_1462463477/000_FPIXTest_p17//trimParameters35_C12.dat
[11:29:45.807] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-05_FPIXTest-17C-FNAL-160505-1051_2016-05-05_10h51m_1462463477/000_FPIXTest_p17//trimParameters35_C13.dat
[11:29:45.812] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-05_FPIXTest-17C-FNAL-160505-1051_2016-05-05_10h51m_1462463477/000_FPIXTest_p17//trimParameters35_C14.dat
[11:29:45.817] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-05_FPIXTest-17C-FNAL-160505-1051_2016-05-05_10h51m_1462463477/000_FPIXTest_p17//trimParameters35_C15.dat
[11:29:45.822] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-M-4-05_FPIXTest-17C-FNAL-160505-1051_2016-05-05_10h51m_1462463477/000_FPIXTest_p17//defaultMaskFile.dat
[11:29:45.832] INFO: enter test to run
[11:30:21.614] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[11:30:21.614] INFO: running: xray
[11:30:21.615] INFO: ----------------------------------------------------------------------
[11:30:21.615] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[11:30:21.615] INFO: ----------------------------------------------------------------------
[11:30:22.579] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[11:30:34.007] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[11:31:03.299] INFO: Resuming triggers.
[11:31:14.734] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[11:31:43.002] INFO: Resuming triggers.
[11:31:55.435] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[11:32:24.831] INFO: Resuming triggers.
[11:32:36.268] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[11:33:05.647] INFO: Resuming triggers.
[11:33:17.080] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[11:33:46.468] INFO: Resuming triggers.
[11:33:57.901] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[11:34:27.190] INFO: Resuming triggers.
[11:34:38.623] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[11:35:07.976] INFO: Resuming triggers.
[11:35:19.409] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[11:35:49.033] INFO: Resuming triggers.
[11:35:57.900] INFO: data taking finished, elapsed time: 100 seconds.
[11:36:20.781] INFO: PixTest:: pg_setup set to default.
[11:36:20.784] INFO: PixTestXray::doPhRun() done
[11:36:20.967] INFO: enter test to run
[11:36:42.947] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[11:36:42.947] INFO: running: xray
[11:36:42.948] INFO: ----------------------------------------------------------------------
[11:36:42.948] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[11:36:42.948] INFO: ----------------------------------------------------------------------
[11:36:43.913] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[11:36:50.496] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[11:37:21.777] INFO: Resuming triggers.
[11:37:28.361] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[11:37:59.687] INFO: Resuming triggers.
[11:38:06.270] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[11:38:36.687] INFO: Resuming triggers.
[11:38:43.270] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[11:39:13.419] INFO: Resuming triggers.
[11:39:19.002] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[11:39:49.977] INFO: Resuming triggers.
[11:39:56.559] INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[11:40:26.566] INFO: Resuming triggers.
[11:40:33.150] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[11:41:03.284] INFO: Resuming triggers.
[11:41:09.867] INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[11:41:40.028] INFO: Resuming triggers.
[11:41:46.609] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[11:42:16.760] INFO: Resuming triggers.
[11:42:23.344] INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[11:42:53.472] INFO: Resuming triggers.
[11:43:00.057] INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[11:43:30.144] INFO: Resuming triggers.
[11:43:36.730] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[11:44:06.898] INFO: Resuming triggers.
[11:44:13.484] INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[11:44:43.591] INFO: Resuming triggers.
[11:44:50.175] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[11:45:20.216] INFO: Resuming triggers.
[11:45:26.800] INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[11:45:56.904] INFO: Resuming triggers.
[11:45:58.487] INFO: data taking finished, elapsed time: 100 seconds.
[11:46:06.032] INFO: PixTest:: pg_setup set to default.
[11:46:06.035] INFO: PixTestXray::doPhRun() done
[11:46:06.185] INFO: enter test to run
[11:47:14.606] INFO: test: HighRate no parameter change
[11:47:14.606] INFO: running: highrate
[11:47:14.607] INFO: ----------------------------------------------------------------------
[11:47:14.608] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[11:47:14.608] INFO: ----------------------------------------------------------------------
[11:47:14.747] INFO: Expecting 768 events.
[11:47:15.882] INFO: 768 events read in total (419ms).
[11:47:15.883] INFO: Test took 1269ms.
[11:47:16.685] INFO: Expecting 41600 events.
[11:47:19.819] INFO: 41600 events read in total (2607ms).
[11:47:19.820] INFO: Test took 3931ms.
[11:47:19.855] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:47:20.576] INFO: Expecting 41600 events.
[11:47:23.758] INFO: 41600 events read in total (2655ms).
[11:47:23.759] INFO: Test took 3887ms.
[11:47:23.794] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:47:24.503] INFO: Expecting 41600 events.
[11:47:27.736] INFO: 41600 events read in total (2706ms).
[11:47:27.737] INFO: Test took 3924ms.
[11:47:27.772] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:47:28.489] INFO: Expecting 41600 events.
[11:47:31.719] INFO: 41600 events read in total (2703ms).
[11:47:31.720] INFO: Test took 3930ms.
[11:47:31.755] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:47:32.480] INFO: Expecting 41600 events.
[11:47:35.675] INFO: 41600 events read in total (2668ms).
[11:47:35.676] INFO: Test took 3903ms.
[11:47:35.711] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:47:36.431] INFO: Expecting 41600 events.
[11:47:39.707] INFO: 41600 events read in total (2749ms).
[11:47:39.708] INFO: Test took 3979ms.
[11:47:39.743] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:47:40.463] INFO: Expecting 41600 events.
[11:47:43.762] INFO: 41600 events read in total (2773ms).
[11:47:43.763] INFO: Test took 4001ms.
[11:47:43.799] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:47:44.516] INFO: Expecting 41600 events.
[11:47:47.783] INFO: 41600 events read in total (2740ms).
[11:47:47.784] INFO: Test took 3968ms.
[11:47:47.821] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:47:48.534] INFO: Expecting 41600 events.
[11:47:51.405] INFO: 41600 events read in total (2345ms).
[11:47:51.406] INFO: Test took 3567ms.
[11:47:51.441] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:47:52.165] INFO: Expecting 41600 events.
[11:47:55.015] INFO: 41600 events read in total (2323ms).
[11:47:55.016] INFO: Test took 3556ms.
[11:47:55.052] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:47:55.775] INFO: Expecting 41600 events.
[11:47:58.619] INFO: 41600 events read in total (2317ms).
[11:47:58.620] INFO: Test took 3550ms.
[11:47:58.656] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:47:59.380] INFO: Expecting 41600 events.
[11:48:02.249] INFO: 41600 events read in total (2343ms).
[11:48:02.250] INFO: Test took 3577ms.
[11:48:02.286] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:48:03.010] INFO: Expecting 41600 events.
[11:48:05.856] INFO: 41600 events read in total (2319ms).
[11:48:05.857] INFO: Test took 3552ms.
[11:48:05.893] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:48:06.617] INFO: Expecting 41600 events.
[11:48:09.616] INFO: 41600 events read in total (2473ms).
[11:48:09.617] INFO: Test took 3706ms.
[11:48:09.652] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:48:10.376] INFO: Expecting 41600 events.
[11:48:13.356] INFO: 41600 events read in total (2454ms).
[11:48:13.357] INFO: Test took 3686ms.
[11:48:13.393] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:48:14.111] INFO: Expecting 41600 events.
[11:48:17.165] INFO: 41600 events read in total (2528ms).
[11:48:17.166] INFO: Test took 3754ms.
[11:48:17.202] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:48:17.922] INFO: Expecting 41600 events.
[11:48:21.037] INFO: 41600 events read in total (2588ms).
[11:48:21.038] INFO: Test took 3818ms.
[11:48:21.073] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:48:21.799] INFO: Expecting 41600 events.
[11:48:24.997] INFO: 41600 events read in total (2671ms).
[11:48:24.999] INFO: Test took 3908ms.
[11:48:25.034] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:48:25.756] INFO: Expecting 41600 events.
[11:48:28.977] INFO: 41600 events read in total (2694ms).
[11:48:28.978] INFO: Test took 3927ms.
[11:48:29.013] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:48:29.730] INFO: Expecting 41600 events.
[11:48:32.671] INFO: 41600 events read in total (2414ms).
[11:48:32.672] INFO: Test took 3641ms.
[11:48:32.707] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:48:33.058] INFO: enter test to run
[11:48:40.749] INFO: test: HighRate no parameter change
[11:48:40.749] INFO: running: highrate
[11:48:40.751] INFO: ----------------------------------------------------------------------
[11:48:40.751] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:48:40.751] INFO: ----------------------------------------------------------------------
[11:48:41.373] INFO: Expecting 208000 events.
[11:48:52.778] INFO: 208000 events read in total (10878ms).
[11:48:52.781] INFO: Test took 12024ms.
[11:48:52.932] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:48:53.187] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:48:53.187] INFO: number of red-efficiency pixels: 65 45 87 146 151 124 102 121 102 120 126 92 116 63 23 28
[11:48:53.187] INFO: number of X-ray hits detected: 65475 43968 70397 113358 116370 109048 114193 80729 74771 97559 97756 88774 93123 55061 21251 26946
[11:48:53.187] 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:48:53.187] INFO: number of Vcal hits detected: 207933 207955 207911 207852 207848 207875 207894 207876 207894 207872 207874 207905 207883 207937 207977 207972
[11:48:53.187] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 100.0 99.9 100.0 99.9 99.9 100.0 99.9 100.0 100.0 100.0
[11:48:53.187] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 99.9 100.0 100.0 100.0
[11:48:53.187] INFO: X-ray hit rate [MHz/cm2]: 19.2 12.9 20.6 33.2 34.1 32.0 33.5 23.7 21.9 28.6 28.7 26.0 27.3 16.1 6.2 7.9
[11:48:53.187] INFO: PixTestHighRate::doXPixelAlive() done
[11:48:53.233] INFO: PixTest:: pg_setup set to default.
[11:48:53.248] INFO: enter test to run
[11:49:13.861] INFO: test: HighRate no parameter change
[11:49:13.861] INFO: running: highrate
[11:49:13.863] INFO: ----------------------------------------------------------------------
[11:49:13.863] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:49:13.863] INFO: ----------------------------------------------------------------------
[11:49:14.478] INFO: Expecting 208000 events.
[11:49:28.072] INFO: 208000 events read in total (13067ms).
[11:49:28.077] INFO: Test took 14204ms.
[11:49:28.374] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:49:28.676] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:49:28.676] INFO: number of red-efficiency pixels: 266 121 246 547 501 371 432 344 263 353 400 324 365 188 54 71
[11:49:28.676] INFO: number of X-ray hits detected: 136075 91398 145783 235698 241998 226612 237348 166452 155778 203066 203646 185052 193386 114607 44477 55939
[11:49:28.676] 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:49:28.676] INFO: number of Vcal hits detected: 207716 207874 207723 207401 207454 207602 207514 207611 207726 207601 207577 207659 207607 207804 207945 207927
[11:49:28.676] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.7 99.8 99.8 99.8 99.8 99.9 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[11:49:28.676] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.7 99.7 99.8 99.8 99.8 99.9 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[11:49:28.676] INFO: X-ray hit rate [MHz/cm2]: 39.9 26.8 42.7 69.1 70.9 66.4 69.6 48.8 45.7 59.5 59.7 54.2 56.7 33.6 13.0 16.4
[11:49:28.676] INFO: PixTestHighRate::doXPixelAlive() done
[11:49:28.723] INFO: PixTest:: pg_setup set to default.
[11:49:28.736] INFO: enter test to run
[11:49:52.549] INFO: test: HighRate no parameter change
[11:49:52.549] INFO: running: highrate
[11:49:52.550] INFO: ----------------------------------------------------------------------
[11:49:52.550] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:49:52.550] INFO: ----------------------------------------------------------------------
[11:49:53.159] INFO: Expecting 208000 events.
[11:50:08.720] INFO: 208000 events read in total (15034ms).
[11:50:08.728] INFO: Test took 16169ms.
[11:50:09.193] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:50:09.547] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:50:09.547] INFO: number of red-efficiency pixels: 501 275 600 1386 1214 853 998 773 552 801 956 764 871 421 89 116
[11:50:09.547] INFO: number of X-ray hits detected: 208675 140371 221646 359646 368747 344069 359924 254623 238375 309338 308476 281793 294206 176262 68337 85189
[11:50:09.547] 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:50:09.547] INFO: number of Vcal hits detected: 207384 207692 207228 206118 206413 206999 206712 206998 207382 206967 206825 207104 206992 207511 207908 207882
[11:50:09.547] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.7 99.2 99.3 99.6 99.4 99.6 99.7 99.5 99.5 99.6 99.6 99.8 100.0 99.9
[11:50:09.547] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.6 99.1 99.2 99.5 99.4 99.5 99.7 99.5 99.4 99.6 99.5 99.8 100.0 99.9
[11:50:09.547] INFO: X-ray hit rate [MHz/cm2]: 61.2 41.1 65.0 105.4 108.1 100.8 105.5 74.6 69.9 90.7 90.4 82.6 86.2 51.7 20.0 25.0
[11:50:09.547] INFO: PixTestHighRate::doXPixelAlive() done
[11:50:09.595] INFO: PixTest:: pg_setup set to default.
[11:50:09.608] INFO: enter test to run
[11:50:13.421] INFO: test: exit no parameter change
[11:50:13.915] QUIET: Connection to board 33 closed.
[11:50:13.916] INFO: pXar: this is the end, my friend