[14:30:59.093] INFO: *** Welcome to pxar ***
[14:30:59.093] INFO: *** Today: 2016/07/01
[14:30:59.110] INFO: *** Version: v1.9.0-814-g7497
[14:30:59.110] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-1-08_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-08_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//dacParameters35_C15.dat
[14:30:59.135] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-1-08_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-08_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//tbmParameters_C0b.dat
[14:30:59.135] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-1-08_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//defaultMaskFile.dat
[14:30:59.141] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-1-08_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-08_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C15.dat
[14:30:59.295] INFO: clk: 4
[14:30:59.295] INFO: ctr: 4
[14:30:59.295] INFO: sda: 19
[14:30:59.295] INFO: tin: 9
[14:30:59.295] INFO: level: 15
[14:30:59.295] INFO: triggerdelay: 0
[14:30:59.295] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[14:30:59.295] INFO: Log level: INFO
[14:30:59.314] QUIET: Connection to board DTB_WREKRL opened.
[14:30:59.317] 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:
------------------------------------------------------
[14:30:59.320] INFO: RPC call hashes of host and DTB match: 398089610
[14:31:00.855] INFO: DUT info:
[14:31:00.855] INFO: The DUT currently contains the following objects:
[14:31:00.855] INFO: 2 TBM Cores tbm08c (2 ON)
[14:31:00.855] INFO: TBM Core alpha (0): 7 registers set
[14:31:00.855] INFO: TBM Core beta (1): 7 registers set
[14:31:00.855] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[14:31:00.855] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[14:31:00.856] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[14:31:00.856] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[14:31:00.856] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[14:31:00.856] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[14:31:00.856] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[14:31:00.856] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[14:31:00.856] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[14:31:00.856] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[14:31:00.856] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[14:31:00.856] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[14:31:00.856] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[14:31:00.856] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[14:31:00.856] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[14:31:00.856] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[14:31:00.856] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[14:31:01.260] INFO: enter 'restricted' command line mode
[14:31:01.260] INFO: enter test to run
[14:31:03.982] INFO: test: PixelAlive no parameter change
[14:31:03.982] INFO: running: pixelalive
[14:31:03.991] INFO: ----------------------------------------------------------------------
[14:31:03.991] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[14:31:03.991] INFO: ----------------------------------------------------------------------
[14:31:04.312] INFO: Expecting 41600 events.
[14:31:08.653] INFO: 41600 events read in total (3622ms).
[14:31:08.819] INFO: Test took 4825ms.
[14:31:08.833] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:31:09.097] INFO: PixTestAlive::aliveTest() done
[14:31:09.097] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 5 0 0 1 0 0 0 0 0 0
[14:31:09.129] INFO: enter test to run
[14:32:06.734] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[14:32:06.734] INFO: running: highrate
[14:32:06.734] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-1-08_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-08_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[14:32:07.007] INFO: ----------------------------------------------------------------------
[14:32:07.007] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[14:32:07.007] INFO: ----------------------------------------------------------------------
[14:32:07.007] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[14:32:07.007] INFO: edge/corner pixel THR is adjusted
[14:32:07.007] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:32:07.967] INFO: Collecting data for 5 seconds...
[14:32:12.984] INFO: Done with hot pixel readout
[14:32:24.457] INFO: PixTest:: pg_setup set to default.
[14:32:24.458] INFO: 18 hot pixels found in step 0
[14:32:25.445] INFO: Collecting data for 5 seconds...
[14:32:30.462] INFO: Done with hot pixel readout
[14:32:41.913] INFO: PixTest:: pg_setup set to default.
[14:32:41.914] INFO: 18 hot pixels found in step 1
[14:32:42.903] INFO: Collecting data for 5 seconds...
[14:32:47.920] INFO: Done with hot pixel readout
[14:32:59.363] INFO: PixTest:: pg_setup set to default.
[14:32:59.364] INFO: 16 hot pixels found in step 2
[14:33:00.354] INFO: Collecting data for 5 seconds...
[14:33:05.370] INFO: Done with hot pixel readout
[14:33:16.867] INFO: PixTest:: pg_setup set to default.
[14:33:16.868] INFO: 15 hot pixels found in step 3
[14:33:17.858] INFO: Collecting data for 5 seconds...
[14:33:22.875] INFO: Done with hot pixel readout
[14:33:34.327] INFO: PixTest:: pg_setup set to default.
[14:33:34.328] INFO: 12 hot pixels found in step 4
[14:33:35.319] INFO: Collecting data for 5 seconds...
[14:33:40.335] INFO: Done with hot pixel readout
[14:33:51.774] INFO: PixTest:: pg_setup set to default.

[14:33:51.775] INFO: 10 hot pixels found in step 5
[14:33:52.765] INFO: Collecting data for 5 seconds...
[14:33:57.782] INFO: Done with hot pixel readout
[14:34:09.319] INFO: PixTest:: pg_setup set to default.

[14:34:09.321] INFO: 7 hot pixels found in step 6
[14:34:10.311] INFO: Collecting data for 5 seconds...
[14:34:15.329] INFO: Done with hot pixel readout
[14:34:26.824] INFO: PixTest:: pg_setup set to default.

[14:34:26.825] INFO: 6 hot pixels found in step 7
[14:34:27.815] INFO: Collecting data for 5 seconds...
[14:34:32.835] INFO: Done with hot pixel readout
[14:34:44.268] INFO: PixTest:: pg_setup set to default.
[14:34:44.269] INFO: 3 hot pixels found in step 8
[14:34:45.259] INFO: Collecting data for 5 seconds...
[14:34:50.278] INFO: Done with hot pixel readout
[14:35:01.928] INFO: PixTest:: pg_setup set to default.


[14:35:01.929] INFO: 4 hot pixels found in step 9
[14:35:02.928] INFO: Collecting data for 5 seconds...
[14:35:07.946] INFO: Done with hot pixel readout
[14:35:19.205] INFO: PixTest:: pg_setup set to default.


[14:35:19.206] INFO: 6 hot pixels found in step 10
[14:35:20.198] INFO: Collecting data for 5 seconds...
[14:35:25.217] INFO: Done with hot pixel readout
[14:35:36.750] INFO: PixTest:: pg_setup set to default.
[14:35:36.751] INFO: 5 hot pixels found in step 11
[14:35:37.740] INFO: Collecting data for 5 seconds...
[14:35:42.758] INFO: Done with hot pixel readout
[14:35:54.026] INFO: PixTest:: pg_setup set to default.
[14:35:54.027] INFO: 1 hot pixels found in step 12
[14:35:55.017] INFO: Collecting data for 5 seconds...
[14:36:00.035] INFO: Done with hot pixel readout
[14:36:11.880] INFO: PixTest:: pg_setup set to default.

[14:36:11.881] INFO: 2 hot pixels found in step 13
[14:36:12.871] INFO: Collecting data for 5 seconds...
[14:36:17.891] INFO: Done with hot pixel readout
[14:36:29.535] INFO: PixTest:: pg_setup set to default.


[14:36:29.536] INFO: 6 hot pixels found in step 14
[14:36:29.571] INFO: 6 hot pixels could not be trimmed and have been masked.
[14:36:29.574] INFO: PixTest::trimHotPixels() done
[14:36:29.574] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-08_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C0.dat
[14:36:29.581] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-08_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C1.dat
[14:36:29.587] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-08_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C2.dat
[14:36:29.594] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-08_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C3.dat
[14:36:29.600] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-08_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C4.dat
[14:36:29.605] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-08_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C5.dat
[14:36:29.611] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-08_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C6.dat
[14:36:29.616] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-08_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C7.dat
[14:36:29.621] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-08_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C8.dat
[14:36:29.627] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-08_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C9.dat
[14:36:29.632] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-08_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C10.dat
[14:36:29.638] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-08_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C11.dat
[14:36:29.643] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-08_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C12.dat
[14:36:29.648] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-08_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C13.dat
[14:36:29.654] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-08_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C14.dat
[14:36:29.659] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-08_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C15.dat
[14:36:29.665] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-1-08_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//defaultMaskFile.dat
[14:36:29.674] INFO: enter test to run
[14:36:54.732] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[14:36:54.732] INFO: running: highrate
[14:36:54.736] INFO: ----------------------------------------------------------------------
[14:36:54.736] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[14:36:54.736] INFO: ----------------------------------------------------------------------
[14:36:54.736] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[14:36:54.736] INFO: edge/corner pixel THR is adjusted
[14:36:54.736] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:36:55.694] INFO: Collecting data for 1 seconds...
[14:36:56.698] INFO: Done with hot pixel readout
[14:37:00.563] INFO: PixTest:: pg_setup set to default.
[14:37:00.564] INFO: 0 hot pixels found in step 0
[14:37:00.573] INFO: 0 hot pixels could not be trimmed and have been masked.
[14:37:00.645] INFO: PixTest::trimHotPixels() done
[14:37:00.646] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-08_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C0.dat
[14:37:00.663] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-08_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C1.dat
[14:37:00.672] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-08_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C2.dat
[14:37:00.681] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-08_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C3.dat
[14:37:00.687] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-08_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C4.dat
[14:37:00.692] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-08_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C5.dat
[14:37:00.697] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-08_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C6.dat
[14:37:00.703] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-08_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C7.dat
[14:37:00.708] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-08_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C8.dat
[14:37:00.713] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-08_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C9.dat
[14:37:00.719] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-08_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C10.dat
[14:37:00.724] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-08_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C11.dat
[14:37:00.730] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-08_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C12.dat
[14:37:00.735] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-08_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C13.dat
[14:37:00.740] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-08_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C14.dat
[14:37:00.746] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-08_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C15.dat
[14:37:00.751] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-1-08_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//defaultMaskFile.dat
[14:37:00.761] INFO: enter test to run
[14:37:56.651] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[14:37:56.651] INFO: running: xray
[14:37:56.653] INFO: ----------------------------------------------------------------------
[14:37:56.653] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:37:56.653] INFO: ----------------------------------------------------------------------
[14:37:57.617] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:38:09.363] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[14:38:38.704] INFO: Resuming triggers.
[14:38:50.457] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[14:39:19.673] INFO: Resuming triggers.
[14:39:31.426] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[14:40:00.587] INFO: Resuming triggers.
[14:40:12.333] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[14:40:41.553] INFO: Resuming triggers.
[14:40:53.300] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[14:41:22.585] INFO: Resuming triggers.
[14:41:34.329] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[14:42:03.644] INFO: Resuming triggers.
[14:42:15.389] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[14:42:44.470] INFO: Resuming triggers.
[14:42:56.219] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[14:43:25.452] INFO: Resuming triggers.
[14:43:31.798] INFO: data taking finished, elapsed time: 100 seconds.
[14:43:47.827] INFO: PixTest:: pg_setup set to default.
[14:43:47.830] INFO: PixTestXray::doPhRun() done
[14:43:47.964] INFO: enter test to run
[14:49:09.975] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[14:49:09.975] INFO: running: xray
[14:49:09.976] INFO: ----------------------------------------------------------------------
[14:49:09.976] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:49:09.976] INFO: ----------------------------------------------------------------------
[14:49:10.939] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:49:18.041] INFO: run duration 7 seconds, buffer almost full (81%), pausing triggers.
[14:49:48.085] INFO: Resuming triggers.
[14:49:55.190] INFO: run duration 14 seconds, buffer almost full (81%), pausing triggers.
[14:50:25.032] INFO: Resuming triggers.
[14:50:32.138] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[14:51:02.137] INFO: Resuming triggers.
[14:51:09.243] INFO: run duration 28 seconds, buffer almost full (81%), pausing triggers.
[14:51:39.349] INFO: Resuming triggers.
[14:51:46.450] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[14:52:16.569] INFO: Resuming triggers.
[14:52:23.673] INFO: run duration 42 seconds, buffer almost full (81%), pausing triggers.
[14:52:53.706] INFO: Resuming triggers.
[14:53:00.811] INFO: run duration 49 seconds, buffer almost full (81%), pausing triggers.
[14:53:30.992] INFO: Resuming triggers.
[14:53:38.094] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[14:54:08.246] INFO: Resuming triggers.
[14:54:15.348] INFO: run duration 63 seconds, buffer almost full (81%), pausing triggers.
[14:54:45.496] INFO: Resuming triggers.
[14:54:52.601] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[14:55:22.630] INFO: Resuming triggers.
[14:55:29.734] INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.
[14:55:59.950] INFO: Resuming triggers.
[14:56:07.053] INFO: run duration 84 seconds, buffer almost full (81%), pausing triggers.
[14:56:37.187] INFO: Resuming triggers.
[14:56:44.294] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[14:57:14.409] INFO: Resuming triggers.
[14:57:21.515] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[14:57:51.628] INFO: Resuming triggers.
[14:57:52.508] INFO: data taking finished, elapsed time: 100 seconds.
[14:57:56.619] INFO: PixTest:: pg_setup set to default.
[14:57:56.623] INFO: PixTestXray::doPhRun() done
[14:57:56.773] INFO: enter test to run
[14:58:24.507] INFO: test: HighRate no parameter change
[14:58:24.507] INFO: running: highrate
[14:58:24.517] INFO: ----------------------------------------------------------------------
[14:58:24.517] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[14:58:24.517] INFO: ----------------------------------------------------------------------
[14:58:24.672] INFO: Expecting 768 events.
[14:58:25.806] INFO: 768 events read in total (418ms).
[14:58:25.807] INFO: Test took 1269ms.
[14:58:26.610] INFO: Expecting 41600 events.
[14:58:29.693] INFO: 41600 events read in total (2557ms).
[14:58:29.694] INFO: Test took 3862ms.
[14:58:29.727] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:58:30.452] INFO: Expecting 41600 events.
[14:58:33.618] INFO: 41600 events read in total (2639ms).
[14:58:33.619] INFO: Test took 3876ms.
[14:58:33.651] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:58:34.378] INFO: Expecting 41600 events.
[14:58:37.568] INFO: 41600 events read in total (2663ms).
[14:58:37.569] INFO: Test took 3902ms.
[14:58:37.602] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:58:38.324] INFO: Expecting 41600 events.
[14:58:41.589] INFO: 41600 events read in total (2739ms).
[14:58:41.590] INFO: Test took 3971ms.
[14:58:41.624] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:58:42.348] INFO: Expecting 41600 events.
[14:58:45.553] INFO: 41600 events read in total (2678ms).
[14:58:45.554] INFO: Test took 3914ms.
[14:58:45.586] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:58:46.314] INFO: Expecting 41600 events.
[14:58:49.586] INFO: 41600 events read in total (2746ms).
[14:58:49.587] INFO: Test took 3983ms.
[14:58:49.621] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:58:50.348] INFO: Expecting 41600 events.
[14:58:53.624] INFO: 41600 events read in total (2750ms).
[14:58:53.625] INFO: Test took 3987ms.
[14:58:53.657] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:58:54.371] INFO: Expecting 41600 events.
[14:58:57.611] INFO: 41600 events read in total (2713ms).
[14:58:57.612] INFO: Test took 3937ms.
[14:58:57.645] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:58:58.371] INFO: Expecting 41600 events.
[14:59:01.589] INFO: 41600 events read in total (2691ms).
[14:59:01.590] INFO: Test took 3928ms.
[14:59:01.622] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:59:02.352] INFO: Expecting 41600 events.
[14:59:05.507] INFO: 41600 events read in total (2629ms).
[14:59:05.508] INFO: Test took 3869ms.
[14:59:05.540] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:59:06.265] INFO: Expecting 41600 events.
[14:59:09.477] INFO: 41600 events read in total (2685ms).
[14:59:09.478] INFO: Test took 3921ms.
[14:59:09.517] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:59:10.233] INFO: Expecting 41600 events.
[14:59:13.450] INFO: 41600 events read in total (2690ms).
[14:59:13.451] INFO: Test took 3917ms.
[14:59:13.483] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:59:14.207] INFO: Expecting 41600 events.
[14:59:17.460] INFO: 41600 events read in total (2726ms).
[14:59:17.461] INFO: Test took 3961ms.
[14:59:17.494] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:59:18.221] INFO: Expecting 41600 events.
[14:59:21.413] INFO: 41600 events read in total (2665ms).
[14:59:21.414] INFO: Test took 3902ms.
[14:59:21.447] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:59:22.171] INFO: Expecting 41600 events.
[14:59:25.404] INFO: 41600 events read in total (2706ms).
[14:59:25.405] INFO: Test took 3941ms.
[14:59:25.440] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:59:26.163] INFO: Expecting 41600 events.
[14:59:29.412] INFO: 41600 events read in total (2722ms).
[14:59:29.412] INFO: Test took 3954ms.
[14:59:29.445] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:59:30.172] INFO: Expecting 41600 events.
[14:59:33.381] INFO: 41600 events read in total (2682ms).
[14:59:33.382] INFO: Test took 3919ms.
[14:59:33.415] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:59:34.140] INFO: Expecting 41600 events.
[14:59:37.365] INFO: 41600 events read in total (2699ms).
[14:59:37.366] INFO: Test took 3934ms.
[14:59:37.398] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:59:38.118] INFO: Expecting 41600 events.
[14:59:41.335] INFO: 41600 events read in total (2690ms).
[14:59:41.335] INFO: Test took 3920ms.
[14:59:41.369] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:59:42.095] INFO: Expecting 41600 events.
[14:59:45.143] INFO: 41600 events read in total (2521ms).
[14:59:45.144] INFO: Test took 3758ms.
[14:59:45.177] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:59:45.539] INFO: enter test to run
[15:04:18.201] INFO: test: HighRate no parameter change
[15:04:18.201] INFO: running: highrate
[15:04:18.202] INFO: ----------------------------------------------------------------------
[15:04:18.202] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:04:18.202] INFO: ----------------------------------------------------------------------
[15:04:18.822] INFO: Expecting 208000 events.
[15:04:30.583] INFO: 208000 events read in total (11234ms).
[15:04:30.586] INFO: Test took 12375ms.
[15:04:30.722] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:04:30.971] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 5 0 0 1 0 0 0 0 0 0
[15:04:30.971] INFO: number of red-efficiency pixels: 70 41 85 114 121 132 131 95 120 105 123 52 85 52 19 25
[15:04:30.971] INFO: number of X-ray hits detected: 63484 40060 61337 94176 104025 106374 102769 77706 76651 93392 89694 78407 78134 47394 19040 21312
[15:04:30.971] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:04:30.971] INFO: number of Vcal hits detected: 207926 207958 207913 207885 207876 207861 207622 207904 207880 207845 207875 207947 207913 207948 207981 207975
[15:04:30.971] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 99.9 100.0 99.9 100.0 100.0 100.0 100.0 100.0
[15:04:30.971] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.8 100.0 99.9 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[15:04:30.971] INFO: X-ray hit rate [MHz/cm2]: 18.6 11.7 18.0 27.6 30.5 31.2 30.1 22.8 22.5 27.4 26.3 23.0 22.9 13.9 5.6 6.2
[15:04:30.971] INFO: PixTestHighRate::doXPixelAlive() done
[15:04:31.023] INFO: PixTest:: pg_setup set to default.
[15:04:31.036] INFO: enter test to run
[15:04:50.048] INFO: test: HighRate no parameter change
[15:04:50.048] INFO: running: highrate
[15:04:50.049] INFO: ----------------------------------------------------------------------
[15:04:50.049] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:04:50.049] INFO: ----------------------------------------------------------------------
[15:04:50.663] INFO: Expecting 208000 events.
[15:05:03.926] INFO: 208000 events read in total (12736ms).
[15:05:03.931] INFO: Test took 13870ms.
[15:05:04.198] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:05:04.489] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 4 0 0 1 0 0 0 0 0 0
[15:05:04.490] INFO: number of red-efficiency pixels: 186 109 215 332 383 419 359 287 206 305 343 236 264 125 51 47
[15:05:04.490] INFO: number of X-ray hits detected: 129134 81590 124673 190291 210477 215306 207586 157617 155691 188867 182457 157613 158557 95719 39321 43371
[15:05:04.490] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:05:04.490] INFO: number of Vcal hits detected: 207804 207888 207772 207643 207591 207547 207361 207698 207789 207636 207638 207753 207723 207870 207947 207953
[15:05:04.490] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.8 99.8 99.9 99.9 99.9 99.8 99.9 99.9 99.9 100.0 100.0
[15:05:04.490] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.8 99.7 99.9 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[15:05:04.490] INFO: X-ray hit rate [MHz/cm2]: 37.9 23.9 36.5 55.8 61.7 63.1 60.8 46.2 45.6 55.4 53.5 46.2 46.5 28.1 11.5 12.7
[15:05:04.490] INFO: PixTestHighRate::doXPixelAlive() done
[15:05:04.540] INFO: PixTest:: pg_setup set to default.
[15:05:04.554] INFO: enter test to run
[15:05:56.512] INFO: test: HighRate no parameter change
[15:05:56.512] INFO: running: highrate
[15:05:56.513] INFO: ----------------------------------------------------------------------
[15:05:56.513] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:05:56.513] INFO: ----------------------------------------------------------------------
[15:05:57.128] INFO: Expecting 208000 events.
[15:06:12.106] INFO: 208000 events read in total (14451ms).
[15:06:12.113] INFO: Test took 15590ms.
[15:06:12.506] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:06:12.841] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 5 0 0 1 0 0 0 0 0 0
[15:06:12.841] INFO: number of red-efficiency pixels: 390 231 498 816 885 974 749 643 460 644 794 603 563 258 95 93
[15:06:12.841] INFO: number of X-ray hits detected: 196173 124422 189485 288031 318559 325890 318142 238867 237093 287512 276584 241229 241353 145709 60037 66663
[15:06:12.841] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:06:12.841] INFO: number of Vcal hits detected: 207549 207751 207390 207040 206968 206803 206860 207204 207484 207228 207054 207315 207370 207714 207903 207907
[15:06:12.841] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.7 99.6 99.6 99.5 99.6 99.6 99.8 99.7 99.6 99.7 99.7 99.9 100.0 100.0
[15:06:12.841] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.7 99.5 99.5 99.4 99.5 99.6 99.8 99.6 99.5 99.7 99.7 99.9 100.0 100.0
[15:06:12.841] INFO: X-ray hit rate [MHz/cm2]: 57.5 36.5 55.5 84.4 93.4 95.5 93.2 70.0 69.5 84.3 81.1 70.7 70.7 42.7 17.6 19.5
[15:06:12.841] INFO: PixTestHighRate::doXPixelAlive() done
[15:06:12.892] INFO: PixTest:: pg_setup set to default.
[15:06:12.907] INFO: enter test to run
[15:06:21.456] INFO: test: exit no parameter change
[15:06:21.749] QUIET: Connection to board 33 closed.
[15:06:21.759] INFO: pXar: this is the end, my friend