[09:55:55.393] INFO: *** Welcome to pxar ***
[09:55:55.393] INFO: *** Today: 2016/04/01
[09:55:55.428] INFO: *** Version: v1.9.0-793-ge521
[09:55:55.428] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//dacParameters35_C15.dat
[09:55:55.446] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//tbmParameters_C0b.dat
[09:55:55.446] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//defaultMaskFile.dat
[09:55:55.446] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C15.dat
[09:55:55.541] INFO: clk: 4
[09:55:55.541] INFO: ctr: 4
[09:55:55.541] INFO: sda: 19
[09:55:55.541] INFO: tin: 9
[09:55:55.541] INFO: level: 15
[09:55:55.541] INFO: triggerdelay: 0
[09:55:55.541] QUIET: Instanciating API for pxar v1.9.0+788~g8b11555
[09:55:55.541] INFO: Log level: INFO
[09:55:55.560] QUIET: Connection to board DTB_WREKRL opened.
[09:55:55.563] 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:
------------------------------------------------------
[09:55:55.566] INFO: RPC call hashes of host and DTB match: 398089610
[09:55:57.094] INFO: DUT info:
[09:55:57.094] INFO: The DUT currently contains the following objects:
[09:55:57.094] INFO: 2 TBM Cores tbm08c (2 ON)
[09:55:57.094] INFO: TBM Core alpha (0): 7 registers set
[09:55:57.094] INFO: TBM Core beta (1): 7 registers set
[09:55:57.094] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[09:55:57.094] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[09:55:57.094] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[09:55:57.094] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[09:55:57.095] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[09:55:57.095] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[09:55:57.095] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[09:55:57.095] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[09:55:57.095] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[09:55:57.095] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[09:55:57.095] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[09:55:57.095] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[09:55:57.095] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[09:55:57.095] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[09:55:57.095] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[09:55:57.095] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[09:55:57.095] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[09:55:57.498] INFO: enter 'restricted' command line mode
[09:55:57.498] INFO: enter test to run
[09:56:04.514] INFO: test: PixelAlive no parameter change
[09:56:04.514] INFO: running: pixelalive
[09:56:04.524] INFO: ----------------------------------------------------------------------
[09:56:04.524] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[09:56:04.524] INFO: ----------------------------------------------------------------------
[09:56:04.844] INFO: Expecting 41600 events.
[09:56:09.174] INFO: 41600 events read in total (3611ms).
[09:56:09.342] INFO: Test took 4815ms.
[09:56:09.355] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:56:09.637] INFO: PixTestAlive::aliveTest() done
[09:56:09.637] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[09:56:09.664] INFO: enter test to run
[09:56:44.538] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[09:56:44.538] INFO: running: highrate
[09:56:44.538] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[09:56:44.741] INFO: ----------------------------------------------------------------------
[09:56:44.741] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[09:56:44.741] INFO: ----------------------------------------------------------------------
[09:56:44.741] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[09:56:44.741] INFO: edge/corner pixel THR is adjusted
[09:56:44.741] INFO: PixTestHighRate::trimHotPixels: step 0...
[09:56:45.700] INFO: Collecting data for 5 seconds...
[09:56:50.717] INFO: Done with hot pixel readout
[09:57:02.280] INFO: PixTest:: pg_setup set to default.
[09:57:02.281] INFO: 24 hot pixels found in step 0
[09:57:03.289] INFO: Collecting data for 5 seconds...
[09:57:08.305] INFO: Done with hot pixel readout
[09:57:19.864] INFO: PixTest:: pg_setup set to default.
[09:57:19.864] INFO: 23 hot pixels found in step 1
[09:57:20.851] INFO: Collecting data for 5 seconds...
[09:57:25.867] INFO: Done with hot pixel readout
[09:57:37.404] INFO: PixTest:: pg_setup set to default.
[09:57:37.405] INFO: 24 hot pixels found in step 2
[09:57:38.391] INFO: Collecting data for 5 seconds...
[09:57:43.407] INFO: Done with hot pixel readout
[09:57:54.717] INFO: PixTest:: pg_setup set to default.
[09:57:54.718] INFO: 25 hot pixels found in step 3
[09:57:55.704] INFO: Collecting data for 5 seconds...
[09:58:00.714] INFO: Done with hot pixel readout
[09:58:11.386] INFO: PixTest:: pg_setup set to default.
[09:58:11.387] INFO: 23 hot pixels found in step 4
[09:58:12.373] INFO: Collecting data for 5 seconds...
[09:58:17.390] INFO: Done with hot pixel readout
[09:58:28.924] INFO: PixTest:: pg_setup set to default.

[09:58:28.924] INFO: 28 hot pixels found in step 5
[09:58:29.912] INFO: Collecting data for 5 seconds...
[09:58:34.928] INFO: Done with hot pixel readout
[09:58:46.357] INFO: PixTest:: pg_setup set to default.



[09:58:46.357] INFO: 26 hot pixels found in step 6
[09:58:47.344] INFO: Collecting data for 5 seconds...
[09:58:52.355] INFO: Done with hot pixel readout
[09:59:03.907] INFO: PixTest:: pg_setup set to default.




[09:59:03.908] INFO: 21 hot pixels found in step 7
[09:59:04.894] INFO: Collecting data for 5 seconds...
[09:59:09.911] INFO: Done with hot pixel readout
[09:59:21.404] INFO: PixTest:: pg_setup set to default.





[09:59:21.405] INFO: 24 hot pixels found in step 8
[09:59:22.392] INFO: Collecting data for 5 seconds...
[09:59:27.409] INFO: Done with hot pixel readout
[09:59:38.937] INFO: PixTest:: pg_setup set to default.









[09:59:38.938] INFO: 19 hot pixels found in step 9
[09:59:39.925] INFO: Collecting data for 5 seconds...
[09:59:44.942] INFO: Done with hot pixel readout
[09:59:56.503] INFO: PixTest:: pg_setup set to default.













[09:59:56.504] INFO: 19 hot pixels found in step 10
[09:59:57.490] INFO: Collecting data for 5 seconds...
[10:00:02.506] INFO: Done with hot pixel readout
[10:00:13.990] INFO: PixTest:: pg_setup set to default.













[10:00:13.991] INFO: 15 hot pixels found in step 11
[10:00:14.979] INFO: Collecting data for 5 seconds...
[10:00:19.995] INFO: Done with hot pixel readout
[10:00:31.499] INFO: PixTest:: pg_setup set to default.













[10:00:31.500] INFO: 18 hot pixels found in step 12
[10:00:32.487] INFO: Collecting data for 5 seconds...
[10:00:37.503] INFO: Done with hot pixel readout
[10:00:49.088] INFO: PixTest:: pg_setup set to default.













[10:00:49.089] INFO: 17 hot pixels found in step 13
[10:00:50.077] INFO: Collecting data for 5 seconds...
[10:00:55.094] INFO: Done with hot pixel readout
[10:01:06.667] INFO: PixTest:: pg_setup set to default.













[10:01:06.668] INFO: 15 hot pixels found in step 14
[10:01:06.699] INFO: 15 hot pixels could not be trimmed and have been masked.
[10:01:06.703] INFO: PixTest::trimHotPixels() done
[10:01:06.706] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C0.dat
[10:01:06.712] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C1.dat
[10:01:06.717] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C2.dat
[10:01:06.723] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C3.dat
[10:01:06.728] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C4.dat
[10:01:06.733] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C5.dat
[10:01:06.738] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C6.dat
[10:01:06.744] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C7.dat
[10:01:06.749] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C8.dat
[10:01:06.754] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C9.dat
[10:01:06.759] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C10.dat
[10:01:06.765] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C11.dat
[10:01:06.770] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C12.dat
[10:01:06.775] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C13.dat
[10:01:06.780] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C14.dat
[10:01:06.785] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C15.dat
[10:01:06.790] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//defaultMaskFile.dat
[10:01:06.808] INFO: enter test to run
[10:01:41.063] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[10:01:41.063] INFO: running: highrate
[10:01:41.068] INFO: ----------------------------------------------------------------------
[10:01:41.068] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[10:01:41.068] INFO: ----------------------------------------------------------------------
[10:01:41.068] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[10:01:41.068] INFO: edge/corner pixel THR is adjusted
[10:01:41.068] INFO: PixTestHighRate::trimHotPixels: step 0...
[10:01:42.026] INFO: Collecting data for 1 seconds...
[10:01:43.029] INFO: Done with hot pixel readout
[10:01:47.074] INFO: PixTest:: pg_setup set to default.
[10:01:47.075] INFO: 0 hot pixels found in step 0
[10:01:47.080] INFO: 0 hot pixels could not be trimmed and have been masked.
[10:01:47.171] INFO: PixTest::trimHotPixels() done
[10:01:47.171] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C0.dat
[10:01:47.180] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C1.dat
[10:01:47.185] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C2.dat
[10:01:47.191] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C3.dat
[10:01:47.196] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C4.dat
[10:01:47.201] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C5.dat
[10:01:47.206] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C6.dat
[10:01:47.212] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C7.dat
[10:01:47.217] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C8.dat
[10:01:47.222] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C9.dat
[10:01:47.227] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C10.dat
[10:01:47.233] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C11.dat
[10:01:47.238] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C12.dat
[10:01:47.243] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C13.dat
[10:01:47.248] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C14.dat
[10:01:47.254] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//trimParameters35_C15.dat
[10:01:47.259] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-I-2-44_FPIXTest-17C-FNAL-160328-0918_2016-03-28_09h18m_1459174687/000_FPIXTest_p17//defaultMaskFile.dat
[10:01:47.274] INFO: enter test to run
[10:02:07.303] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[10:02:07.303] INFO: running: xray
[10:02:07.304] INFO: ----------------------------------------------------------------------
[10:02:07.304] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[10:02:07.305] INFO: ----------------------------------------------------------------------
[10:02:08.268] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[10:02:19.815] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[10:02:48.930] INFO: Resuming triggers.
[10:03:00.480] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[10:03:29.737] INFO: Resuming triggers.
[10:03:41.285] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[10:04:10.374] INFO: Resuming triggers.
[10:04:21.926] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[10:04:51.065] INFO: Resuming triggers.
[10:05:02.618] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[10:05:31.749] INFO: Resuming triggers.
[10:05:43.302] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[10:06:12.361] INFO: Resuming triggers.
[10:06:23.916] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[10:06:52.937] INFO: Resuming triggers.
[10:07:04.487] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[10:07:33.514] INFO: Resuming triggers.
[10:07:41.431] INFO: data taking finished, elapsed time: 100 seconds.
[10:08:01.569] INFO: PixTest:: pg_setup set to default.
[10:08:01.572] INFO: PixTestXray::doPhRun() done
[10:08:01.704] INFO: enter test to run
[10:08:50.780] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[10:08:50.780] INFO: running: xray
[10:08:50.781] INFO: ----------------------------------------------------------------------
[10:08:50.781] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[10:08:50.781] INFO: ----------------------------------------------------------------------
[10:08:51.749] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[10:08:58.363] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[10:09:27.920] INFO: Resuming triggers.
[10:09:34.538] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[10:10:04.024] INFO: Resuming triggers.
[10:10:10.639] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[10:10:40.098] INFO: Resuming triggers.
[10:10:46.711] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[10:11:16.183] INFO: Resuming triggers.
[10:11:22.793] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[10:11:52.365] INFO: Resuming triggers.
[10:11:58.978] INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[10:12:28.524] INFO: Resuming triggers.
[10:12:35.135] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[10:13:04.664] INFO: Resuming triggers.
[10:13:11.273] INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[10:13:40.783] INFO: Resuming triggers.
[10:13:47.392] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[10:14:16.914] INFO: Resuming triggers.
[10:14:23.524] INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[10:14:53.059] INFO: Resuming triggers.
[10:14:59.670] INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[10:15:29.188] INFO: Resuming triggers.
[10:15:35.802] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[10:16:05.321] INFO: Resuming triggers.
[10:16:11.933] INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[10:16:41.450] INFO: Resuming triggers.
[10:16:48.061] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[10:17:17.566] INFO: Resuming triggers.
[10:17:24.180] INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[10:17:53.804] INFO: Resuming triggers.
[10:17:54.940] INFO: data taking finished, elapsed time: 100 seconds.
[10:18:00.349] INFO: PixTest:: pg_setup set to default.
[10:18:00.352] INFO: PixTestXray::doPhRun() done
[10:18:00.498] INFO: enter test to run
[10:18:25.160] INFO: test: HighRate no parameter change
[10:18:25.160] INFO: running: highrate
[10:18:25.161] INFO: ----------------------------------------------------------------------
[10:18:25.161] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[10:18:25.161] INFO: ----------------------------------------------------------------------
[10:18:25.303] INFO: Expecting 768 events.
[10:18:26.438] INFO: 768 events read in total (419ms).
[10:18:26.438] INFO: Test took 1269ms.
[10:18:27.241] INFO: Expecting 41600 events.
[10:18:30.349] INFO: 41600 events read in total (2581ms).
[10:18:30.350] INFO: Test took 3903ms.
[10:18:30.383] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:18:31.110] INFO: Expecting 41600 events.
[10:18:34.327] INFO: 41600 events read in total (2690ms).
[10:18:34.328] INFO: Test took 3928ms.
[10:18:34.361] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:18:35.088] INFO: Expecting 41600 events.
[10:18:38.320] INFO: 41600 events read in total (2705ms).
[10:18:38.321] INFO: Test took 3941ms.
[10:18:38.355] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:18:39.081] INFO: Expecting 41600 events.
[10:18:42.330] INFO: 41600 events read in total (2722ms).
[10:18:42.331] INFO: Test took 3959ms.
[10:18:42.365] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:18:43.091] INFO: Expecting 41600 events.
[10:18:46.336] INFO: 41600 events read in total (2718ms).
[10:18:46.337] INFO: Test took 3954ms.
[10:18:46.371] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:18:47.095] INFO: Expecting 41600 events.
[10:18:50.333] INFO: 41600 events read in total (2711ms).
[10:18:50.334] INFO: Test took 3946ms.
[10:18:50.368] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:18:51.094] INFO: Expecting 41600 events.
[10:18:54.355] INFO: 41600 events read in total (2734ms).
[10:18:54.356] INFO: Test took 3970ms.
[10:18:54.390] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:18:55.116] INFO: Expecting 41600 events.
[10:18:57.933] INFO: 41600 events read in total (2291ms).
[10:18:57.934] INFO: Test took 3527ms.
[10:18:57.968] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:18:58.694] INFO: Expecting 41600 events.
[10:19:01.950] INFO: 41600 events read in total (2729ms).
[10:19:01.950] INFO: Test took 3964ms.
[10:19:01.984] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:19:02.710] INFO: Expecting 41600 events.
[10:19:05.967] INFO: 41600 events read in total (2731ms).
[10:19:05.968] INFO: Test took 3967ms.
[10:19:05.001] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:19:06.725] INFO: Expecting 41600 events.
[10:19:09.966] INFO: 41600 events read in total (2714ms).
[10:19:09.967] INFO: Test took 3946ms.
[10:19:09.001] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:19:10.727] INFO: Expecting 41600 events.
[10:19:13.982] INFO: 41600 events read in total (2729ms).
[10:19:13.983] INFO: Test took 3963ms.
[10:19:14.018] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:19:14.739] INFO: Expecting 41600 events.
[10:19:17.995] INFO: 41600 events read in total (2729ms).
[10:19:17.996] INFO: Test took 3959ms.
[10:19:18.030] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:19:18.756] INFO: Expecting 41600 events.
[10:19:22.011] INFO: 41600 events read in total (2728ms).
[10:19:22.012] INFO: Test took 3963ms.
[10:19:22.046] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:19:22.769] INFO: Expecting 41600 events.
[10:19:26.022] INFO: 41600 events read in total (2726ms).
[10:19:26.023] INFO: Test took 3958ms.
[10:19:26.057] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:19:26.783] INFO: Expecting 41600 events.
[10:19:30.029] INFO: 41600 events read in total (2719ms).
[10:19:30.030] INFO: Test took 3954ms.
[10:19:30.064] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:19:30.788] INFO: Expecting 41600 events.
[10:19:34.047] INFO: 41600 events read in total (2732ms).
[10:19:34.048] INFO: Test took 3966ms.
[10:19:34.081] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:19:34.806] INFO: Expecting 41600 events.
[10:19:38.061] INFO: 41600 events read in total (2728ms).
[10:19:38.062] INFO: Test took 3962ms.
[10:19:38.096] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:19:38.824] INFO: Expecting 41600 events.
[10:19:42.038] INFO: 41600 events read in total (2688ms).
[10:19:42.039] INFO: Test took 3925ms.
[10:19:42.073] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:19:42.794] INFO: Expecting 41600 events.
[10:19:45.878] INFO: 41600 events read in total (2557ms).
[10:19:45.879] INFO: Test took 3789ms.
[10:19:45.912] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:19:46.275] INFO: enter test to run
[10:20:25.807] INFO: test: HighRate no parameter change
[10:20:25.807] INFO: running: highrate
[10:20:25.808] INFO: ----------------------------------------------------------------------
[10:20:25.808] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:20:25.808] INFO: ----------------------------------------------------------------------
[10:20:26.423] INFO: Expecting 208000 events.
[10:20:38.275] INFO: 208000 events read in total (11325ms).
[10:20:38.278] INFO: Test took 12460ms.
[10:20:38.422] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:20:38.674] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[10:20:38.674] INFO: number of red-efficiency pixels: 74 58 89 128 145 149 124 99 88 121 114 104 112 52 34 30
[10:20:38.674] INFO: number of X-ray hits detected: 72203 47248 70832 107003 111724 118563 115758 76551 64652 93536 97763 82820 86552 52727 23376 24716
[10:20:38.674] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:20:38.674] INFO: number of Vcal hits detected: 207924 207942 207910 207866 207851 207848 207871 207899 207912 207876 207885 207896 207884 207947 207965 207970
[10:20:38.674] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 99.9 100.0 99.9 100.0 100.0 100.0
[10:20:38.674] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 99.9 100.0 99.9 100.0 100.0 100.0
[10:20:38.674] INFO: X-ray hit rate [MHz/cm2]: 21.2 13.8 20.8 31.4 32.7 34.8 33.9 22.4 18.9 27.4 28.7 24.3 25.4 15.5 6.9 7.2
[10:20:38.674] INFO: PixTestHighRate::doXPixelAlive() done
[10:20:38.723] INFO: PixTest:: pg_setup set to default.
[10:20:38.733] INFO: enter test to run
[10:21:03.287] INFO: test: HighRate no parameter change
[10:21:03.287] INFO: running: highrate
[10:21:03.288] INFO: ----------------------------------------------------------------------
[10:21:03.288] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:21:03.288] INFO: ----------------------------------------------------------------------
[10:21:03.908] INFO: Expecting 208000 events.
[10:21:17.567] INFO: 208000 events read in total (13132ms).
[10:21:17.572] INFO: Test took 14276ms.
[10:21:17.878] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:21:18.180] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[10:21:18.180] INFO: number of red-efficiency pixels: 240 176 312 455 475 522 435 348 221 391 453 275 292 161 64 54
[10:21:18.180] INFO: number of X-ray hits detected: 151493 97834 149281 222807 232370 249639 242235 161426 136413 195741 203535 172952 180240 109900 49817 52169
[10:21:18.180] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:21:18.180] INFO: number of Vcal hits detected: 207727 207810 207661 207506 207484 207429 207527 207631 207770 207577 207510 207712 207687 207835 207933 207944
[10:21:18.180] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.8 99.8 99.8 99.7 99.8 99.8 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[10:21:18.180] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.8 99.8 99.7 99.8 99.8 99.9 99.8 99.8 99.9 99.8 99.9 100.0 100.0
[10:21:18.180] INFO: X-ray hit rate [MHz/cm2]: 44.4 28.7 43.8 65.3 68.1 73.2 71.0 47.3 40.0 57.4 59.7 50.7 52.8 32.2 14.6 15.3
[10:21:18.180] INFO: PixTestHighRate::doXPixelAlive() done
[10:21:18.235] INFO: PixTest:: pg_setup set to default.
[10:21:18.250] INFO: enter test to run
[10:21:48.494] INFO: test: HighRate no parameter change
[10:21:48.495] INFO: running: highrate
[10:21:48.496] INFO: ----------------------------------------------------------------------
[10:21:48.496] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:21:48.496] INFO: ----------------------------------------------------------------------
[10:21:49.113] INFO: Expecting 208000 events.
[10:22:04.747] INFO: 208000 events read in total (15107ms).
[10:22:04.755] INFO: Test took 16250ms.
[10:22:05.216] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:22:05.567] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[10:22:05.567] INFO: number of red-efficiency pixels: 481 329 778 1141 1206 1280 1052 719 526 875 1037 549 615 350 91 95
[10:22:05.567] INFO: number of X-ray hits detected: 229976 149479 226673 340316 352981 377422 367950 245541 208590 297537 309033 262481 274617 168048 76329 79414
[10:22:05.568] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:22:05.568] INFO: number of Vcal hits detected: 207382 207632 206958 206578 206486 206362 206669 207085 207398 206958 206712 207370 207305 207609 207907 207904
[10:22:05.568] INFO: Vcal hit fiducial efficiency (%): 99.7 99.8 99.6 99.4 99.3 99.3 99.4 99.6 99.7 99.5 99.4 99.7 99.7 99.8 100.0 100.0
[10:22:05.568] INFO: Vcal hit overall efficiency (%): 99.7 99.8 99.5 99.3 99.3 99.2 99.4 99.6 99.7 99.5 99.4 99.7 99.7 99.8 100.0 100.0
[10:22:05.568] INFO: X-ray hit rate [MHz/cm2]: 67.4 43.8 66.4 99.7 103.5 110.6 107.8 72.0 61.1 87.2 90.6 76.9 80.5 49.3 22.4 23.3
[10:22:05.568] INFO: PixTestHighRate::doXPixelAlive() done
[10:22:05.619] INFO: PixTest:: pg_setup set to default.
[10:22:05.637] INFO: enter test to run
[10:22:22.646] INFO: test: exit no parameter change
[10:22:22.963] QUIET: Connection to board 33 closed.
[10:22:22.964] INFO: pXar: this is the end, my friend