[13:38:36.258] INFO: *** Welcome to pxar ***
[13:38:36.258] INFO: *** Today: 2016/05/12
[13:38:36.307] INFO: *** Version: v1.9.0-796-gef167-dirty
[13:38:36.307] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Y-Q-NF_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-Q-NF_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//dacParameters35_C15.dat
[13:38:36.353] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Y-Q-NF_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-Q-NF_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//tbmParameters_C0b.dat
[13:38:36.353] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Y-Q-NF_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//defaultMaskFile.dat
[13:38:36.356] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Y-Q-NF_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-Q-NF_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C15.dat
[13:38:36.442] INFO: clk: 4
[13:38:36.442] INFO: ctr: 4
[13:38:36.442] INFO: sda: 19
[13:38:36.442] INFO: tin: 9
[13:38:36.442] INFO: level: 15
[13:38:36.442] INFO: triggerdelay: 0
[13:38:36.442] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[13:38:36.442] INFO: Log level: INFO
[13:38:36.457] QUIET: Connection to board DTB_WREKRL opened.
[13:38:36.461] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 33
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREKRL
MAC address: 40D855118021
Hostname: pixelDTB033
Comment:
------------------------------------------------------
[13:38:36.463] INFO: RPC call hashes of host and DTB match: 398089610
[13:38:37.996] INFO: DUT info:
[13:38:37.997] INFO: The DUT currently contains the following objects:
[13:38:37.997] INFO: 2 TBM Cores tbm08c (2 ON)
[13:38:37.997] INFO: TBM Core alpha (0): 7 registers set
[13:38:37.997] INFO: TBM Core beta (1): 7 registers set
[13:38:37.997] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[13:38:37.997] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[13:38:37.997] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[13:38:37.997] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[13:38:37.997] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[13:38:37.997] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[13:38:37.997] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[13:38:37.997] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[13:38:37.997] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[13:38:37.997] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[13:38:37.997] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[13:38:37.997] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[13:38:37.998] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[13:38:37.998] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[13:38:37.998] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[13:38:37.998] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[13:38:37.998] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[13:38:38.401] INFO: enter 'restricted' command line mode
[13:38:38.401] INFO: enter test to run
[13:39:16.028] INFO: test: PixelAlive no parameter change
[13:39:16.028] INFO: running: pixelalive
[13:39:16.037] INFO: ----------------------------------------------------------------------
[13:39:16.037] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[13:39:16.037] INFO: ----------------------------------------------------------------------
[13:39:16.355] INFO: Expecting 41600 events.
[13:39:20.677] INFO: 41600 events read in total (3603ms).
[13:39:20.844] INFO: Test took 4805ms.
[13:39:20.858] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:39:21.120] INFO: PixTestAlive::aliveTest() done
[13:39:21.120] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 2 0 0 0 0 0 0 0 0 0
[13:39:21.153] INFO: enter test to run
[13:40:56.587] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[13:40:56.587] INFO: running: highrate
[13:40:56.587] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Y-Q-NF_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-Q-NF_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[13:40:56.869] INFO: ----------------------------------------------------------------------
[13:40:56.870] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[13:40:56.870] INFO: ----------------------------------------------------------------------
[13:40:56.870] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[13:40:56.870] INFO: edge/corner pixel THR is adjusted
[13:40:56.870] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:40:57.828] INFO: Collecting data for 5 seconds...
[13:41:02.845] INFO: Done with hot pixel readout
[13:41:15.549] INFO: PixTest:: pg_setup set to default.

[13:41:15.577] INFO: 125 hot pixels found in step 0
[13:41:16.574] INFO: Collecting data for 5 seconds...
[13:41:21.591] INFO: Done with hot pixel readout
[13:41:34.264] INFO: PixTest:: pg_setup set to default.




[13:41:34.265] INFO: 136 hot pixels found in step 1
[13:41:35.262] INFO: Collecting data for 5 seconds...
[13:41:40.281] INFO: Done with hot pixel readout
[13:41:52.936] INFO: PixTest:: pg_setup set to default.








[13:41:52.937] INFO: 129 hot pixels found in step 2
[13:41:53.937] INFO: Collecting data for 5 seconds...
[13:41:58.954] INFO: Done with hot pixel readout
[13:42:11.681] INFO: PixTest:: pg_setup set to default.







[13:42:11.682] INFO: 117 hot pixels found in step 3
[13:42:12.683] INFO: Collecting data for 5 seconds...
[13:42:17.700] INFO: Done with hot pixel readout
[13:42:30.387] INFO: PixTest:: pg_setup set to default.






[13:42:30.388] INFO: 112 hot pixels found in step 4
[13:42:31.389] INFO: Collecting data for 5 seconds...
[13:42:36.406] INFO: Done with hot pixel readout
[13:42:49.111] INFO: PixTest:: pg_setup set to default.







[13:42:49.112] INFO: 103 hot pixels found in step 5
[13:42:50.112] INFO: Collecting data for 5 seconds...
[13:42:55.129] INFO: Done with hot pixel readout
[13:43:07.839] INFO: PixTest:: pg_setup set to default.





[13:43:07.840] INFO: 90 hot pixels found in step 6
[13:43:08.842] INFO: Collecting data for 5 seconds...
[13:43:13.859] INFO: Done with hot pixel readout
[13:43:26.533] INFO: PixTest:: pg_setup set to default.







[13:43:26.534] INFO: 85 hot pixels found in step 7
[13:43:27.535] INFO: Collecting data for 5 seconds...
[13:43:32.551] INFO: Done with hot pixel readout
[13:43:45.246] INFO: PixTest:: pg_setup set to default.







[13:43:45.247] INFO: 76 hot pixels found in step 8
[13:43:46.248] INFO: Collecting data for 5 seconds...
[13:43:51.264] INFO: Done with hot pixel readout
[13:44:03.963] INFO: PixTest:: pg_setup set to default.




[13:44:03.964] INFO: 68 hot pixels found in step 9
[13:44:04.964] INFO: Collecting data for 5 seconds...
[13:44:09.981] INFO: Done with hot pixel readout
[13:44:22.684] INFO: PixTest:: pg_setup set to default.







[13:44:22.685] INFO: 79 hot pixels found in step 10
[13:44:23.686] INFO: Collecting data for 5 seconds...
[13:44:28.703] INFO: Done with hot pixel readout
[13:44:41.421] INFO: PixTest:: pg_setup set to default.
















[13:44:41.422] INFO: 79 hot pixels found in step 11
[13:44:42.424] INFO: Collecting data for 5 seconds...
[13:44:47.441] INFO: Done with hot pixel readout
[13:45:00.160] INFO: PixTest:: pg_setup set to default.











[13:45:00.161] INFO: 69 hot pixels found in step 12
[13:45:01.162] INFO: Collecting data for 5 seconds...
[13:45:06.179] INFO: Done with hot pixel readout
[13:45:18.870] INFO: PixTest:: pg_setup set to default.












[13:45:18.871] INFO: 78 hot pixels found in step 13
[13:45:19.872] INFO: Collecting data for 5 seconds...
[13:45:24.890] INFO: Done with hot pixel readout
[13:45:37.561] INFO: PixTest:: pg_setup set to default.











[13:45:37.562] INFO: 62 hot pixels found in step 14
[13:45:37.607] INFO: 62 hot pixels could not be trimmed and have been masked.
[13:45:37.610] INFO: PixTest::trimHotPixels() done
[13:45:37.610] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-Q-NF_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C0.dat
[13:45:37.622] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-Q-NF_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C1.dat
[13:45:37.627] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-Q-NF_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C2.dat
[13:45:37.632] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-Q-NF_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C3.dat
[13:45:37.637] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-Q-NF_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C4.dat
[13:45:37.642] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-Q-NF_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C5.dat
[13:45:37.648] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-Q-NF_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C6.dat
[13:45:37.653] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-Q-NF_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C7.dat
[13:45:37.658] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-Q-NF_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C8.dat
[13:45:37.663] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-Q-NF_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C9.dat
[13:45:37.668] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-Q-NF_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C10.dat
[13:45:37.673] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-Q-NF_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C11.dat
[13:45:37.678] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-Q-NF_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C12.dat
[13:45:37.684] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-Q-NF_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C13.dat
[13:45:37.689] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-Q-NF_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C14.dat
[13:45:37.694] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-Q-NF_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C15.dat
[13:45:37.699] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Y-Q-NF_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//defaultMaskFile.dat
[13:45:37.709] INFO: enter test to run
[13:46:18.688] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[13:46:18.689] INFO: running: highrate
[13:46:18.693] INFO: ----------------------------------------------------------------------
[13:46:18.693] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[13:46:18.693] INFO: ----------------------------------------------------------------------
[13:46:18.693] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[13:46:18.693] INFO: edge/corner pixel THR is adjusted
[13:46:18.693] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:46:19.650] INFO: Collecting data for 1 seconds...
[13:46:20.654] INFO: Done with hot pixel readout
[13:46:25.283] INFO: PixTest:: pg_setup set to default.
[13:46:25.283] INFO: 0 hot pixels found in step 0
[13:46:25.289] INFO: 0 hot pixels could not be trimmed and have been masked.
[13:46:25.356] INFO: PixTest::trimHotPixels() done
[13:46:25.356] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-Q-NF_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C0.dat
[13:46:25.367] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-Q-NF_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C1.dat
[13:46:25.374] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-Q-NF_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C2.dat
[13:46:25.379] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-Q-NF_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C3.dat
[13:46:25.384] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-Q-NF_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C4.dat
[13:46:25.389] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-Q-NF_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C5.dat
[13:46:25.395] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-Q-NF_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C6.dat
[13:46:25.400] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-Q-NF_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C7.dat
[13:46:25.405] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-Q-NF_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C8.dat
[13:46:25.410] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-Q-NF_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C9.dat
[13:46:25.415] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-Q-NF_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C10.dat
[13:46:25.420] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-Q-NF_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C11.dat
[13:46:25.425] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-Q-NF_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C12.dat
[13:46:25.430] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-Q-NF_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C13.dat
[13:46:25.435] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-Q-NF_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C14.dat
[13:46:25.441] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-Q-NF_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C15.dat
[13:46:25.446] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Y-Q-NF_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//defaultMaskFile.dat
[13:46:25.455] INFO: enter test to run
[13:47:07.928] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[13:47:07.928] INFO: running: xray
[13:47:07.929] INFO: ----------------------------------------------------------------------
[13:47:07.929] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:47:07.929] INFO: ----------------------------------------------------------------------
[13:47:08.893] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:47:19.207] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[13:47:49.050] INFO: Resuming triggers.
[13:47:59.369] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[13:48:28.303] INFO: Resuming triggers.
[13:48:38.624] INFO: run duration 30 seconds, buffer almost full (81%), pausing triggers.
[13:49:08.978] INFO: Resuming triggers.
[13:49:19.298] INFO: run duration 41 seconds, buffer almost full (81%), pausing triggers.
[13:49:49.826] INFO: Resuming triggers.
[13:50:00.150] INFO: run duration 51 seconds, buffer almost full (81%), pausing triggers.
[13:50:29.886] INFO: Resuming triggers.
[13:50:40.216] INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[13:51:09.941] INFO: Resuming triggers.
[13:51:20.272] INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[13:51:49.868] INFO: Resuming triggers.
[13:52:00.197] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[13:52:29.777] INFO: Resuming triggers.
[13:52:40.107] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[13:53:09.685] INFO: Resuming triggers.
[13:53:17.132] INFO: data taking finished, elapsed time: 100 seconds.
[13:53:38.781] INFO: PixTest:: pg_setup set to default.
[13:53:38.784] INFO: PixTestXray::doPhRun() done
[13:53:38.925] INFO: enter test to run
[13:54:16.917] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[13:54:16.917] INFO: running: xray
[13:54:16.918] INFO: ----------------------------------------------------------------------
[13:54:16.918] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:54:16.918] INFO: ----------------------------------------------------------------------
[13:54:17.882] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:54:23.514] INFO: run duration 5 seconds, buffer almost full (81%), pausing triggers.
[13:54:53.658] INFO: Resuming triggers.
[13:54:59.290] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[13:55:29.415] INFO: Resuming triggers.
[13:55:35.051] INFO: run duration 16 seconds, buffer almost full (81%), pausing triggers.
[13:56:05.263] INFO: Resuming triggers.
[13:56:10.899] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[13:56:40.847] INFO: Resuming triggers.
[13:56:46.485] INFO: run duration 28 seconds, buffer almost full (81%), pausing triggers.
[13:57:16.746] INFO: Resuming triggers.
[13:57:22.384] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[13:57:52.639] INFO: Resuming triggers.
[13:57:58.278] INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[13:58:28.577] INFO: Resuming triggers.
[13:58:34.219] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[13:59:04.985] INFO: Resuming triggers.
[13:59:10.628] INFO: run duration 50 seconds, buffer almost full (81%), pausing triggers.
[13:59:41.505] INFO: Resuming triggers.
[13:59:47.148] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[14:00:18.342] INFO: Resuming triggers.
[14:00:23.985] INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[14:00:55.297] INFO: Resuming triggers.
[14:01:00.944] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[14:01:31.233] INFO: Resuming triggers.
[14:01:36.881] INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[14:02:07.008] INFO: Resuming triggers.
[14:02:12.655] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[14:02:42.787] INFO: Resuming triggers.
[14:02:48.437] INFO: run duration 84 seconds, buffer almost full (81%), pausing triggers.
[14:03:18.600] INFO: Resuming triggers.
[14:03:24.248] INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[14:03:54.513] INFO: Resuming triggers.
[14:04:00.164] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[14:04:30.329] INFO: Resuming triggers.
[14:04:34.770] INFO: data taking finished, elapsed time: 100 seconds.
[14:04:58.656] INFO: PixTest:: pg_setup set to default.
[14:04:58.659] INFO: PixTestXray::doPhRun() done
[14:04:58.807] INFO: enter test to run
[14:05:22.624] INFO: test: HighRate no parameter change
[14:05:22.624] INFO: running: highrate
[14:05:22.625] INFO: ----------------------------------------------------------------------
[14:05:22.625] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[14:05:22.625] INFO: ----------------------------------------------------------------------
[14:05:22.767] INFO: Expecting 768 events.
[14:05:23.900] INFO: 768 events read in total (418ms).
[14:05:23.901] INFO: Test took 1268ms.
[14:05:24.704] INFO: Expecting 41600 events.
[14:05:27.939] INFO: 41600 events read in total (2708ms).
[14:05:27.940] INFO: Test took 4033ms.
[14:05:27.982] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:05:28.694] INFO: Expecting 41600 events.
[14:05:31.978] INFO: 41600 events read in total (2758ms).
[14:05:31.979] INFO: Test took 3976ms.
[14:05:32.021] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:05:32.732] INFO: Expecting 41600 events.
[14:05:36.033] INFO: 41600 events read in total (2775ms).
[14:05:36.034] INFO: Test took 3992ms.
[14:05:36.075] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:05:36.787] INFO: Expecting 41600 events.
[14:05:40.100] INFO: 41600 events read in total (2786ms).
[14:05:40.101] INFO: Test took 4004ms.
[14:05:40.143] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:05:40.852] INFO: Expecting 41600 events.
[14:05:44.176] INFO: 41600 events read in total (2797ms).
[14:05:44.177] INFO: Test took 4014ms.
[14:05:44.220] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:05:44.926] INFO: Expecting 41600 events.
[14:05:48.249] INFO: 41600 events read in total (2796ms).
[14:05:48.250] INFO: Test took 4008ms.
[14:05:48.293] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:05:48.003] INFO: Expecting 41600 events.
[14:05:52.316] INFO: 41600 events read in total (2786ms).
[14:05:52.317] INFO: Test took 4004ms.
[14:05:52.359] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:05:53.070] INFO: Expecting 41600 events.
[14:05:56.395] INFO: 41600 events read in total (2798ms).
[14:05:56.396] INFO: Test took 4015ms.
[14:05:56.438] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:05:57.148] INFO: Expecting 41600 events.
[14:06:00.470] INFO: 41600 events read in total (2795ms).
[14:06:00.471] INFO: Test took 4013ms.
[14:06:00.514] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:06:01.225] INFO: Expecting 41600 events.
[14:06:04.544] INFO: 41600 events read in total (2792ms).
[14:06:04.545] INFO: Test took 4008ms.
[14:06:04.587] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:06:05.296] INFO: Expecting 41600 events.
[14:06:08.621] INFO: 41600 events read in total (2798ms).
[14:06:08.622] INFO: Test took 4013ms.
[14:06:08.664] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:06:09.371] INFO: Expecting 41600 events.
[14:06:12.702] INFO: 41600 events read in total (2804ms).
[14:06:12.703] INFO: Test took 4017ms.
[14:06:12.745] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:06:13.452] INFO: Expecting 41600 events.
[14:06:16.782] INFO: 41600 events read in total (2803ms).
[14:06:16.783] INFO: Test took 4017ms.
[14:06:16.825] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:06:17.533] INFO: Expecting 41600 events.
[14:06:20.860] INFO: 41600 events read in total (2801ms).
[14:06:20.861] INFO: Test took 4015ms.
[14:06:20.902] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:06:21.609] INFO: Expecting 41600 events.
[14:06:24.941] INFO: 41600 events read in total (2805ms).
[14:06:24.943] INFO: Test took 4020ms.
[14:06:24.985] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:06:25.692] INFO: Expecting 41600 events.
[14:06:29.013] INFO: 41600 events read in total (2794ms).
[14:06:29.014] INFO: Test took 4007ms.
[14:06:29.056] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:06:29.767] INFO: Expecting 41600 events.
[14:06:33.088] INFO: 41600 events read in total (2794ms).
[14:06:33.089] INFO: Test took 4012ms.
[14:06:33.131] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:06:33.838] INFO: Expecting 41600 events.
[14:06:37.159] INFO: 41600 events read in total (2794ms).
[14:06:37.160] INFO: Test took 4008ms.
[14:06:37.202] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:06:37.910] INFO: Expecting 41600 events.
[14:06:41.203] INFO: 41600 events read in total (2766ms).
[14:06:41.204] INFO: Test took 3980ms.
[14:06:41.245] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:06:41.956] INFO: Expecting 41600 events.
[14:06:45.059] INFO: 41600 events read in total (2576ms).
[14:06:45.060] INFO: Test took 3793ms.
[14:06:45.101] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:06:45.454] INFO: enter test to run
[14:07:16.759] INFO: test: HighRate no parameter change
[14:07:16.759] INFO: running: highrate
[14:07:16.760] INFO: ----------------------------------------------------------------------
[14:07:16.761] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:07:16.761] INFO: ----------------------------------------------------------------------
[14:07:17.379] INFO: Expecting 208000 events.
[14:07:29.740] INFO: 208000 events read in total (11834ms).
[14:07:29.743] INFO: Test took 12974ms.
[14:07:29.929] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:07:30.192] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 2 0 0 0 0 0 0 0 0 0
[14:07:30.192] INFO: number of red-efficiency pixels: 78 61 117 168 212 219 242 168 117 157 123 144 117 77 35 29
[14:07:30.192] INFO: number of X-ray hits detected: 79705 55639 91211 142656 155994 154327 156081 108854 99377 119723 116918 105953 105960 65040 30609 33644
[14:07:30.192] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:07:30.192] INFO: number of Vcal hits detected: 207922 207937 207878 207829 207781 207771 207646 207823 207879 207837 207871 207852 207882 207901 207965 207971
[14:07:30.192] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[14:07:30.192] INFO: Vcal hit overall efficiency (%): 100.0 100.0 99.9 99.9 99.9 99.9 99.8 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[14:07:30.193] INFO: X-ray hit rate [MHz/cm2]: 23.4 16.3 26.7 41.8 45.7 45.2 45.7 31.9 29.1 35.1 34.3 31.1 31.1 19.1 9.0 9.9
[14:07:30.193] INFO: PixTestHighRate::doXPixelAlive() done
[14:07:30.242] INFO: PixTest:: pg_setup set to default.
[14:07:30.256] INFO: enter test to run
[14:08:14.783] INFO: test: HighRate no parameter change
[14:08:14.783] INFO: running: highrate
[14:08:14.784] INFO: ----------------------------------------------------------------------
[14:08:14.784] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:08:14.784] INFO: ----------------------------------------------------------------------
[14:08:15.404] INFO: Expecting 208000 events.
[14:08:30.113] INFO: 208000 events read in total (14182ms).
[14:08:30.119] INFO: Test took 15326ms.
[14:08:30.505] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:08:30.836] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 2 0 0 0 0 0 0 0 0 0
[14:08:30.836] INFO: number of red-efficiency pixels: 253 195 447 649 996 788 1022 621 339 582 448 495 471 235 98 70
[14:08:30.836] INFO: number of X-ray hits detected: 166716 117337 192619 299661 327179 321808 327173 230211 210235 252060 248296 221573 222746 136699 64300 71733
[14:08:30.836] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:08:30.836] INFO: number of Vcal hits detected: 207730 207789 207476 207268 206772 207086 206659 207269 207637 207357 207520 207451 207479 207709 207898 207929
[14:08:30.836] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.8 99.7 99.5 99.6 99.4 99.7 99.8 99.7 99.8 99.8 99.8 99.9 100.0 100.0
[14:08:30.836] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.7 99.6 99.4 99.6 99.4 99.6 99.8 99.7 99.8 99.7 99.7 99.9 100.0 100.0
[14:08:30.836] INFO: X-ray hit rate [MHz/cm2]: 48.9 34.4 56.5 87.8 95.9 94.3 95.9 67.5 61.6 73.9 72.8 64.9 65.3 40.1 18.8 21.0
[14:08:30.837] INFO: PixTestHighRate::doXPixelAlive() done
[14:08:30.887] INFO: PixTest:: pg_setup set to default.
[14:08:30.904] INFO: enter test to run
[14:09:21.006] INFO: test: HighRate no parameter change
[14:09:21.006] INFO: running: highrate
[14:09:21.007] INFO: ----------------------------------------------------------------------
[14:09:21.008] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:09:21.008] INFO: ----------------------------------------------------------------------
[14:09:21.630] INFO: Expecting 208000 events.
[14:09:39.392] INFO: 208000 events read in total (17235ms).
[14:09:39.401] INFO: Test took 18383ms.
[14:09:39.993] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:09:40.392] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 2 0 0 0 0 0 0 0 0 0
[14:09:40.392] INFO: number of red-efficiency pixels: 578 455 927 1531 2200 1828 2472 1351 696 1412 1126 1193 1090 529 169 151
[14:09:40.392] INFO: number of X-ray hits detected: 251446 176468 289683 451820 494519 486602 493151 346974 318311 382440 374068 337778 336835 207817 97383 108579
[14:09:40.392] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:09:40.392] INFO: number of Vcal hits detected: 207304 207477 206510 205830 204184 205154 203596 205857 207181 206084 206597 206386 206633 207286 207825 207843
[14:09:40.392] INFO: Vcal hit fiducial efficiency (%): 99.7 99.8 99.4 99.1 98.4 98.8 98.1 99.1 99.7 99.2 99.4 99.3 99.4 99.7 99.9 99.9
[14:09:40.392] INFO: Vcal hit overall efficiency (%): 99.7 99.7 99.3 99.0 98.2 98.6 97.9 99.0 99.6 99.1 99.3 99.2 99.3 99.7 99.9 99.9
[14:09:40.392] INFO: X-ray hit rate [MHz/cm2]: 73.7 51.7 84.9 132.4 144.9 142.6 144.5 101.7 93.3 112.1 109.6 99.0 98.7 60.9 28.5 31.8
[14:09:40.392] INFO: PixTestHighRate::doXPixelAlive() done
[14:09:40.437] INFO: PixTest:: pg_setup set to default.
[14:09:40.449] INFO: enter test to run
[14:09:59.782] INFO: test: exit no parameter change
[14:10:00.099] QUIET: Connection to board 33 closed.
[14:10:00.100] INFO: pXar: this is the end, my friend