[15:15:25.965] INFO: *** Welcome to pxar ***
[15:15:25.965] INFO: *** Today: 2016/07/06
[15:15:26.791] INFO: *** Version: v1.9.0-814-g7497
[15:15:26.791] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-5-34_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-5-34_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//dacParameters35_C15.dat
[15:15:26.816] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-5-34_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-5-34_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//tbmParameters_C0b.dat
[15:15:26.816] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-5-34_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//defaultMaskFile.dat
[15:15:26.816] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-5-34_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-5-34_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C15.dat
[15:15:26.922] INFO: clk: 4
[15:15:26.922] INFO: ctr: 4
[15:15:26.922] INFO: sda: 19
[15:15:26.922] INFO: tin: 9
[15:15:26.922] INFO: level: 15
[15:15:26.922] INFO: triggerdelay: 0
[15:15:26.922] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[15:15:26.922] INFO: Log level: INFO
[15:15:26.940] QUIET: Connection to board DTB_WREKRL opened.
[15:15:26.944] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 33
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREKRL
MAC address: 40D855118021
Hostname: pixelDTB033
Comment:
------------------------------------------------------
[15:15:26.966] INFO: RPC call hashes of host and DTB match: 398089610
[15:15:28.499] INFO: DUT info:
[15:15:28.499] INFO: The DUT currently contains the following objects:
[15:15:28.499] INFO: 2 TBM Cores tbm08c (2 ON)
[15:15:28.499] INFO: TBM Core alpha (0): 7 registers set
[15:15:28.499] INFO: TBM Core beta (1): 7 registers set
[15:15:28.499] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[15:15:28.499] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[15:15:28.499] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[15:15:28.499] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[15:15:28.499] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[15:15:28.499] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[15:15:28.499] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[15:15:28.499] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[15:15:28.500] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[15:15:28.500] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[15:15:28.500] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[15:15:28.500] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[15:15:28.500] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[15:15:28.500] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[15:15:28.500] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[15:15:28.500] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[15:15:28.500] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[15:15:28.914] INFO: enter 'restricted' command line mode
[15:15:28.914] INFO: enter test to run
[15:15:30.063] INFO: test: PixelAlive no parameter change
[15:15:30.063] INFO: running: pixelalive
[15:15:30.095] INFO: ----------------------------------------------------------------------
[15:15:30.095] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[15:15:30.095] INFO: ----------------------------------------------------------------------
[15:15:30.415] INFO: Expecting 41600 events.
[15:15:34.757] INFO: 41600 events read in total (3623ms).
[15:15:34.926] INFO: Test took 4827ms.
[15:15:34.936] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:15:35.227] INFO: PixTestAlive::aliveTest() done
[15:15:35.227] INFO: number of dead pixels (per ROC): 0 0 1 0 0 0 0 6 1 0 0 0 0 0 0 0
[15:15:35.257] INFO: enter test to run
[15:16:03.215] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[15:16:03.215] INFO: running: highrate
[15:16:03.215] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-5-34_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-5-34_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[15:16:03.507] INFO: ----------------------------------------------------------------------
[15:16:03.507] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[15:16:03.507] INFO: ----------------------------------------------------------------------
[15:16:03.507] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[15:16:03.507] INFO: edge/corner pixel THR is adjusted
[15:16:03.507] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:16:04.466] INFO: Collecting data for 5 seconds...
[15:16:09.483] INFO: Done with hot pixel readout
[15:16:21.733] INFO: PixTest:: pg_setup set to default.

[15:16:21.734] INFO: 36 hot pixels found in step 0
[15:16:22.725] INFO: Collecting data for 5 seconds...
[15:16:27.742] INFO: Done with hot pixel readout
[15:16:39.864] INFO: PixTest:: pg_setup set to default.

[15:16:39.864] INFO: 48 hot pixels found in step 1
[15:16:40.860] INFO: Collecting data for 5 seconds...
[15:16:45.876] INFO: Done with hot pixel readout
[15:16:58.056] INFO: PixTest:: pg_setup set to default.


[15:16:58.057] INFO: 39 hot pixels found in step 2
[15:16:59.050] INFO: Collecting data for 5 seconds...
[15:17:04.067] INFO: Done with hot pixel readout
[15:17:16.236] INFO: PixTest:: pg_setup set to default.
[15:17:16.237] INFO: 40 hot pixels found in step 3
[15:17:17.231] INFO: Collecting data for 5 seconds...
[15:17:22.247] INFO: Done with hot pixel readout
[15:17:34.452] INFO: PixTest:: pg_setup set to default.
[15:17:34.453] INFO: 37 hot pixels found in step 4
[15:17:35.448] INFO: Collecting data for 5 seconds...
[15:17:40.464] INFO: Done with hot pixel readout
[15:17:52.783] INFO: PixTest:: pg_setup set to default.



[15:17:52.784] INFO: 31 hot pixels found in step 5
[15:17:53.778] INFO: Collecting data for 5 seconds...
[15:17:58.797] INFO: Done with hot pixel readout
[15:18:11.177] INFO: PixTest:: pg_setup set to default.

[15:18:11.178] INFO: 25 hot pixels found in step 6
[15:18:12.173] INFO: Collecting data for 5 seconds...
[15:18:17.190] INFO: Done with hot pixel readout
[15:18:29.189] INFO: PixTest:: pg_setup set to default.
[15:18:29.190] INFO: 26 hot pixels found in step 7
[15:18:30.184] INFO: Collecting data for 5 seconds...
[15:18:35.202] INFO: Done with hot pixel readout
[15:18:47.294] INFO: PixTest:: pg_setup set to default.


[15:18:47.295] INFO: 32 hot pixels found in step 8
[15:18:48.290] INFO: Collecting data for 5 seconds...
[15:18:53.309] INFO: Done with hot pixel readout
[15:19:05.398] INFO: PixTest:: pg_setup set to default.
[15:19:05.399] INFO: 27 hot pixels found in step 9
[15:19:06.393] INFO: Collecting data for 5 seconds...
[15:19:11.413] INFO: Done with hot pixel readout
[15:19:23.250] INFO: PixTest:: pg_setup set to default.


[15:19:23.251] INFO: 40 hot pixels found in step 10
[15:19:24.245] INFO: Collecting data for 5 seconds...
[15:19:29.264] INFO: Done with hot pixel readout
[15:19:41.318] INFO: PixTest:: pg_setup set to default.

[15:19:41.319] INFO: 27 hot pixels found in step 11
[15:19:42.314] INFO: Collecting data for 5 seconds...
[15:19:47.332] INFO: Done with hot pixel readout
[15:19:59.608] INFO: PixTest:: pg_setup set to default.

[15:19:59.609] INFO: 24 hot pixels found in step 12
[15:20:00.605] INFO: Collecting data for 5 seconds...
[15:20:05.623] INFO: Done with hot pixel readout
[15:20:17.436] INFO: PixTest:: pg_setup set to default.


[15:20:17.437] INFO: 22 hot pixels found in step 13
[15:20:18.435] INFO: Collecting data for 5 seconds...
[15:20:23.453] INFO: Done with hot pixel readout
[15:20:35.186] INFO: PixTest:: pg_setup set to default.



[15:20:35.187] INFO: 35 hot pixels found in step 14
[15:20:35.229] INFO: 35 hot pixels could not be trimmed and have been masked.
[15:20:35.233] INFO: PixTest::trimHotPixels() done
[15:20:35.233] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-34_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C0.dat
[15:20:35.254] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-34_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C1.dat
[15:20:35.260] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-34_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C2.dat
[15:20:35.266] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-34_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C3.dat
[15:20:35.272] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-34_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C4.dat
[15:20:35.277] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-34_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C5.dat
[15:20:35.283] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-34_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C6.dat
[15:20:35.289] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-34_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C7.dat
[15:20:35.294] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-34_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C8.dat
[15:20:35.300] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-34_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C9.dat
[15:20:35.305] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-34_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C10.dat
[15:20:35.311] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-34_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C11.dat
[15:20:35.316] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-34_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C12.dat
[15:20:35.322] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-34_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C13.dat
[15:20:35.327] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-34_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C14.dat
[15:20:35.332] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-34_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C15.dat
[15:20:35.338] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-5-34_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//defaultMaskFile.dat
[15:20:35.349] INFO: enter test to run
[15:23:43.115] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[15:23:43.115] INFO: running: highrate
[15:23:43.116] INFO: command -> highrate<- not known, ignored
[15:23:43.116] INFO: enter test to run
[15:24:28.131] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[15:24:28.131] INFO: running: highrate
[15:24:28.136] INFO: ----------------------------------------------------------------------
[15:24:28.136] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[15:24:28.136] INFO: ----------------------------------------------------------------------
[15:24:28.136] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[15:24:28.136] INFO: edge/corner pixel THR is adjusted
[15:24:28.136] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:24:29.095] INFO: Collecting data for 1 seconds...
[15:24:30.098] INFO: Done with hot pixel readout
[15:24:34.277] INFO: PixTest:: pg_setup set to default.
[15:24:34.278] INFO: 0 hot pixels found in step 0
[15:24:34.283] INFO: 0 hot pixels could not be trimmed and have been masked.
[15:24:34.367] INFO: PixTest::trimHotPixels() done
[15:24:34.367] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-34_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C0.dat
[15:24:34.379] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-34_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C1.dat
[15:24:34.386] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-34_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C2.dat
[15:24:34.391] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-34_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C3.dat
[15:24:34.396] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-34_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C4.dat
[15:24:34.402] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-34_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C5.dat
[15:24:34.408] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-34_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C6.dat
[15:24:34.414] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-34_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C7.dat
[15:24:34.419] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-34_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C8.dat
[15:24:34.425] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-34_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C9.dat
[15:24:34.431] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-34_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C10.dat
[15:24:34.436] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-34_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C11.dat
[15:24:34.441] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-34_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C12.dat
[15:24:34.447] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-34_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C13.dat
[15:24:34.452] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-34_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C14.dat
[15:24:34.457] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-34_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//trimParameters35_C15.dat
[15:24:34.463] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-5-34_FPIXTest-17C-FNAL-160705-1230_2016-07-05_12h30m_1467739830/000_FPIXTest_p17//defaultMaskFile.dat
[15:24:34.472] INFO: enter test to run
[15:24:50.939] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[15:24:50.939] INFO: running: xray
[15:24:50.940] INFO: ----------------------------------------------------------------------
[15:24:50.940] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:24:50.940] INFO: ----------------------------------------------------------------------
[15:24:51.904] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:25:02.996] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[15:25:32.703] INFO: Resuming triggers.
[15:25:43.800] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[15:26:13.567] INFO: Resuming triggers.
[15:26:24.660] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[15:26:54.372] INFO: Resuming triggers.
[15:27:05.464] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[15:27:35.075] INFO: Resuming triggers.
[15:27:46.170] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[15:28:15.922] INFO: Resuming triggers.
[15:28:27.012] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[15:28:56.812] INFO: Resuming triggers.
[15:29:07.907] INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.
[15:29:37.461] INFO: Resuming triggers.
[15:29:48.550] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[15:30:18.578] INFO: Resuming triggers.
[15:30:29.669] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[15:30:59.071] INFO: Resuming triggers.
[15:30:59.574] INFO: data taking finished, elapsed time: 100 seconds.
[15:31:01.277] INFO: PixTest:: pg_setup set to default.
[15:31:01.280] INFO: PixTestXray::doPhRun() done
[15:31:01.460] INFO: enter test to run
[15:31:18.288] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[15:31:18.289] INFO: running: xray
[15:31:18.290] INFO: ----------------------------------------------------------------------
[15:31:18.290] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:31:18.290] INFO: ----------------------------------------------------------------------
[15:31:19.271] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:31:25.624] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[15:31:56.739] INFO: Resuming triggers.
[15:32:03.093] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[15:32:35.036] INFO: Resuming triggers.
[15:32:41.392] INFO: run duration 18 seconds, buffer almost full (81%), pausing triggers.
[15:33:13.168] INFO: Resuming triggers.
[15:33:19.518] INFO: run duration 25 seconds, buffer almost full (81%), pausing triggers.
[15:33:50.874] INFO: Resuming triggers.
[15:33:57.229] INFO: run duration 31 seconds, buffer almost full (81%), pausing triggers.
[15:34:28.311] INFO: Resuming triggers.
[15:34:34.668] INFO: run duration 37 seconds, buffer almost full (81%), pausing triggers.
[15:35:05.166] INFO: Resuming triggers.
[15:35:11.521] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[15:35:41.896] INFO: Resuming triggers.
[15:35:48.250] INFO: run duration 50 seconds, buffer almost full (81%), pausing triggers.
[15:36:18.558] INFO: Resuming triggers.
[15:36:24.912] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[15:36:55.423] INFO: Resuming triggers.
[15:37:01.777] INFO: run duration 63 seconds, buffer almost full (81%), pausing triggers.
[15:37:32.294] INFO: Resuming triggers.
[15:37:38.651] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[15:38:08.966] INFO: Resuming triggers.
[15:38:15.318] INFO: run duration 75 seconds, buffer almost full (81%), pausing triggers.
[15:38:45.714] INFO: Resuming triggers.
[15:38:52.066] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[15:39:22.409] INFO: Resuming triggers.
[15:39:28.761] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[15:39:59.210] INFO: Resuming triggers.
[15:40:05.565] INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[15:40:35.957] INFO: Resuming triggers.
[15:40:40.998] INFO: data taking finished, elapsed time: 100 seconds.
[15:41:05.133] INFO: PixTest:: pg_setup set to default.
[15:41:05.136] INFO: PixTestXray::doPhRun() done
[15:41:05.294] INFO: enter test to run
[15:44:02.715] INFO: test: HighRate no parameter change
[15:44:02.715] INFO: running: highrate
[15:44:02.729] INFO: ----------------------------------------------------------------------
[15:44:02.729] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[15:44:02.729] INFO: ----------------------------------------------------------------------
[15:44:02.884] INFO: Expecting 768 events.
[15:44:04.018] INFO: 768 events read in total (418ms).
[15:44:04.018] INFO: Test took 1268ms.
[15:44:04.821] INFO: Expecting 41600 events.
[15:44:08.009] INFO: 41600 events read in total (2661ms).
[15:44:08.010] INFO: Test took 3973ms.
[15:44:08.046] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:44:08.772] INFO: Expecting 41600 events.
[15:44:12.025] INFO: 41600 events read in total (2726ms).
[15:44:12.026] INFO: Test took 3962ms.
[15:44:12.063] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:44:12.778] INFO: Expecting 41600 events.
[15:44:16.074] INFO: 41600 events read in total (2770ms).
[15:44:16.075] INFO: Test took 3993ms.
[15:44:16.120] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:44:16.821] INFO: Expecting 41600 events.
[15:44:20.125] INFO: 41600 events read in total (2777ms).
[15:44:20.126] INFO: Test took 3988ms.
[15:44:20.163] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:44:20.873] INFO: Expecting 41600 events.
[15:44:24.114] INFO: 41600 events read in total (2714ms).
[15:44:24.115] INFO: Test took 3933ms.
[15:44:24.153] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:44:24.871] INFO: Expecting 41600 events.
[15:44:28.178] INFO: 41600 events read in total (2780ms).
[15:44:28.179] INFO: Test took 4006ms.
[15:44:28.217] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:44:28.931] INFO: Expecting 41600 events.
[15:44:32.208] INFO: 41600 events read in total (2750ms).
[15:44:32.209] INFO: Test took 3972ms.
[15:44:32.246] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:44:32.964] INFO: Expecting 41600 events.
[15:44:36.326] INFO: 41600 events read in total (2836ms).
[15:44:36.327] INFO: Test took 4062ms.
[15:44:36.366] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:44:37.079] INFO: Expecting 41600 events.
[15:44:40.423] INFO: 41600 events read in total (2817ms).
[15:44:40.423] INFO: Test took 4039ms.
[15:44:40.462] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:44:41.177] INFO: Expecting 41600 events.
[15:44:44.454] INFO: 41600 events read in total (2750ms).
[15:44:44.455] INFO: Test took 3974ms.
[15:44:44.493] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:44:45.211] INFO: Expecting 41600 events.
[15:44:48.597] INFO: 41600 events read in total (2859ms).
[15:44:48.598] INFO: Test took 4086ms.
[15:44:48.639] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:44:49.347] INFO: Expecting 41600 events.
[15:44:52.632] INFO: 41600 events read in total (2759ms).
[15:44:52.633] INFO: Test took 3975ms.
[15:44:52.672] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:44:53.367] INFO: Expecting 41600 events.
[15:44:56.761] INFO: 41600 events read in total (2868ms).
[15:44:56.762] INFO: Test took 4072ms.
[15:44:56.801] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:44:57.507] INFO: Expecting 41600 events.
[15:45:00.824] INFO: 41600 events read in total (2790ms).
[15:45:00.825] INFO: Test took 4002ms.
[15:45:00.863] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:45:01.571] INFO: Expecting 41600 events.
[15:45:05.006] INFO: 41600 events read in total (2908ms).
[15:45:05.007] INFO: Test took 4125ms.
[15:45:05.045] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:45:05.759] INFO: Expecting 41600 events.
[15:45:09.142] INFO: 41600 events read in total (2856ms).
[15:45:09.143] INFO: Test took 4079ms.
[15:45:09.182] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:45:09.886] INFO: Expecting 41600 events.
[15:45:13.206] INFO: 41600 events read in total (2793ms).
[15:45:13.207] INFO: Test took 4006ms.
[15:45:13.244] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:45:13.962] INFO: Expecting 41600 events.
[15:45:17.384] INFO: 41600 events read in total (2895ms).
[15:45:17.384] INFO: Test took 4121ms.
[15:45:17.422] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:45:18.138] INFO: Expecting 41600 events.
[15:45:21.509] INFO: 41600 events read in total (2844ms).
[15:45:21.510] INFO: Test took 4069ms.
[15:45:21.554] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:45:22.266] INFO: Expecting 41600 events.
[15:45:25.498] INFO: 41600 events read in total (2705ms).
[15:45:25.499] INFO: Test took 3926ms.
[15:45:25.537] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:45:25.902] INFO: enter test to run
[15:45:41.059] INFO: test: HighRate no parameter change
[15:45:41.059] INFO: running: highrate
[15:45:41.060] INFO: ----------------------------------------------------------------------
[15:45:41.060] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:45:41.060] INFO: ----------------------------------------------------------------------
[15:45:41.680] INFO: Expecting 208000 events.
[15:45:54.016] INFO: 208000 events read in total (11809ms).
[15:45:54.020] INFO: Test took 12950ms.
[15:45:54.185] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:45:54.444] INFO: number of dead pixels (per ROC): 0 0 1 0 0 0 0 6 1 0 0 0 0 0 0 0
[15:45:54.444] INFO: number of red-efficiency pixels: 78 90 93 165 159 188 179 142 80 166 131 125 115 72 31 32
[15:45:54.444] INFO: number of X-ray hits detected: 74153 48283 74535 114402 124294 128722 135334 96772 84349 111375 104374 92773 91236 54465 24734 25000
[15:45:54.444] 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:45:54.444] INFO: number of Vcal hits detected: 207921 207907 207855 207832 207830 207807 207815 207560 207870 207828 207867 207869 207884 207924 207969 207967
[15:45:54.444] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 100.0 100.0 100.0 100.0
[15:45:54.444] INFO: Vcal hit overall efficiency (%): 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.8 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[15:45:54.444] INFO: X-ray hit rate [MHz/cm2]: 21.7 14.2 21.8 33.5 36.4 37.7 39.7 28.4 24.7 32.6 30.6 27.2 26.7 16.0 7.2 7.3
[15:45:54.444] INFO: PixTestHighRate::doXPixelAlive() done
[15:45:54.489] INFO: PixTest:: pg_setup set to default.
[15:45:54.507] INFO: enter test to run
[15:46:18.490] INFO: test: HighRate no parameter change
[15:46:18.490] INFO: running: highrate
[15:46:18.492] INFO: ----------------------------------------------------------------------
[15:46:18.492] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:46:18.492] INFO: ----------------------------------------------------------------------
[15:46:19.115] INFO: Expecting 208000 events.
[15:46:33.404] INFO: 208000 events read in total (13762ms).
[15:46:33.410] INFO: Test took 14908ms.
[15:46:33.751] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:46:34.067] INFO: number of dead pixels (per ROC): 0 0 1 0 0 0 0 6 1 0 0 0 0 0 0 0
[15:46:34.068] INFO: number of red-efficiency pixels: 226 199 292 411 489 578 548 450 231 535 335 325 369 206 68 79
[15:46:34.068] INFO: number of X-ray hits detected: 150046 98668 152098 233282 254135 262015 273768 197736 171480 226088 212701 189136 186594 110409 50974 51230
[15:46:34.068] 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:46:34.068] INFO: number of Vcal hits detected: 207751 207787 207632 207556 207454 207361 207402 207217 207708 207419 207638 207658 207615 207781 207932 207921
[15:46:34.068] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.7 99.7 99.8 99.9 99.7 99.8 99.9 99.8 99.9 100.0 100.0
[15:46:34.068] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.8 99.7 99.7 99.7 99.6 99.9 99.7 99.8 99.8 99.8 99.9 100.0 100.0
[15:46:34.068] INFO: X-ray hit rate [MHz/cm2]: 44.0 28.9 44.6 68.4 74.5 76.8 80.2 58.0 50.3 66.3 62.3 55.4 54.7 32.4 14.9 15.0
[15:46:34.068] INFO: PixTestHighRate::doXPixelAlive() done
[15:46:34.114] INFO: PixTest:: pg_setup set to default.
[15:46:34.131] INFO: enter test to run
[15:47:30.594] INFO: test: HighRate no parameter change
[15:47:30.594] INFO: running: highrate
[15:47:30.595] INFO: ----------------------------------------------------------------------
[15:47:30.595] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:47:30.595] INFO: ----------------------------------------------------------------------
[15:47:31.217] INFO: Expecting 208000 events.
[15:47:47.305] INFO: 208000 events read in total (15561ms).
[15:47:47.312] INFO: Test took 16706ms.
[15:47:47.792] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:47:48.153] INFO: number of dead pixels (per ROC): 0 0 1 0 0 0 0 6 1 0 0 0 0 0 0 0
[15:47:48.153] INFO: number of red-efficiency pixels: 451 404 737 939 1189 1344 1327 1025 525 1218 793 741 855 466 119 114
[15:47:48.153] INFO: number of X-ray hits detected: 225189 147550 229618 350072 381185 394277 412333 296385 259034 338890 319702 283161 280681 166828 76176 77831
[15:47:48.153] 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:47:48.153] INFO: number of Vcal hits detected: 207466 207533 207027 206835 206466 206164 206227 206277 207365 206441 207078 207127 206997 207449 207879 207884
[15:47:48.153] INFO: Vcal hit fiducial efficiency (%): 99.8 99.8 99.6 99.5 99.3 99.2 99.2 99.4 99.7 99.3 99.6 99.6 99.6 99.8 99.9 99.9
[15:47:48.154] INFO: Vcal hit overall efficiency (%): 99.7 99.8 99.5 99.4 99.3 99.1 99.1 99.2 99.7 99.3 99.6 99.6 99.5 99.7 99.9 99.9
[15:47:48.154] INFO: X-ray hit rate [MHz/cm2]: 66.0 43.2 67.3 102.6 111.7 115.6 120.9 86.9 75.9 99.3 93.7 83.0 82.3 48.9 22.3 22.8
[15:47:48.154] INFO: PixTestHighRate::doXPixelAlive() done
[15:47:48.204] INFO: PixTest:: pg_setup set to default.
[15:47:48.220] INFO: enter test to run
[15:48:33.465] INFO: test: exit no parameter change
[15:48:33.875] QUIET: Connection to board 33 closed.
[15:48:33.891] INFO: pXar: this is the end, my friend