[12:38:42.477] INFO: *** Welcome to pxar ***
[12:38:42.477] INFO: *** Today: 2016/05/16
[12:38:42.969] INFO: *** Version: v1.9.0-796-gef167-dirty
[12:38:42.969] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Y-P-NW_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-P-NW_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//dacParameters35_C15.dat
[12:38:43.017] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Y-P-NW_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-P-NW_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//tbmParameters_C0b.dat
[12:38:43.017] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Y-P-NW_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//defaultMaskFile.dat
[12:38:43.018] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Y-P-NW_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-P-NW_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C15.dat
[12:38:43.125] INFO: clk: 4
[12:38:43.125] INFO: ctr: 4
[12:38:43.125] INFO: sda: 19
[12:38:43.125] INFO: tin: 9
[12:38:43.125] INFO: level: 15
[12:38:43.125] INFO: triggerdelay: 0
[12:38:43.125] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[12:38:43.125] INFO: Log level: INFO
[12:38:43.142] QUIET: Connection to board DTB_WREKRL opened.
[12:38:43.145] 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:
------------------------------------------------------
[12:38:43.148] INFO: RPC call hashes of host and DTB match: 398089610
[12:38:44.700] INFO: DUT info:
[12:38:44.700] INFO: The DUT currently contains the following objects:
[12:38:44.700] INFO: 2 TBM Cores tbm08c (2 ON)
[12:38:44.714] INFO: TBM Core alpha (0): 7 registers set
[12:38:44.714] INFO: TBM Core beta (1): 7 registers set
[12:38:44.714] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[12:38:44.714] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[12:38:44.714] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[12:38:44.714] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[12:38:44.714] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[12:38:44.715] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[12:38:44.715] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[12:38:44.715] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[12:38:44.715] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[12:38:44.715] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[12:38:44.715] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[12:38:44.715] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[12:38:44.715] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[12:38:44.715] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[12:38:44.715] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[12:38:44.715] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[12:38:44.715] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[12:38:45.160] INFO: enter 'restricted' command line mode
[12:38:45.160] INFO: enter test to run
[12:38:52.979] INFO: test: PixelAlive no parameter change
[12:38:52.979] INFO: running: pixelalive
[12:38:53.045] INFO: ----------------------------------------------------------------------
[12:38:53.045] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[12:38:53.045] INFO: ----------------------------------------------------------------------
[12:38:53.361] INFO: Expecting 41600 events.
[12:38:57.708] INFO: 41600 events read in total (3629ms).
[12:38:57.871] INFO: Test took 4824ms.
[12:38:57.880] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:38:58.423] INFO: PixTestAlive::aliveTest() done
[12:38:58.423] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[12:38:58.576] INFO: enter test to run
[12:39:24.347] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[12:39:24.347] INFO: running: highrate
[12:39:24.348] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Y-P-NW_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-P-NW_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[12:39:24.634] INFO: ----------------------------------------------------------------------
[12:39:24.634] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[12:39:24.634] INFO: ----------------------------------------------------------------------
[12:39:24.634] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[12:39:24.634] INFO: edge/corner pixel THR is adjusted
[12:39:24.634] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:39:25.593] INFO: Collecting data for 5 seconds...
[12:39:30.611] INFO: Done with hot pixel readout
[12:39:43.156] INFO: PixTest:: pg_setup set to default.
[12:39:43.157] INFO: 5 hot pixels found in step 0
[12:39:44.150] INFO: Collecting data for 5 seconds...
[12:39:49.167] INFO: Done with hot pixel readout
[12:40:01.362] INFO: PixTest:: pg_setup set to default.
[12:40:01.363] INFO: 3 hot pixels found in step 1
[12:40:02.363] INFO: Collecting data for 5 seconds...
[12:40:07.384] INFO: Done with hot pixel readout
[12:40:19.828] INFO: PixTest:: pg_setup set to default.
[12:40:19.829] INFO: 4 hot pixels found in step 2
[12:40:20.826] INFO: Collecting data for 5 seconds...
[12:40:25.845] INFO: Done with hot pixel readout
[12:40:38.443] INFO: PixTest:: pg_setup set to default.
[12:40:38.444] INFO: 6 hot pixels found in step 3
[12:40:39.441] INFO: Collecting data for 5 seconds...
[12:40:44.460] INFO: Done with hot pixel readout
[12:40:56.858] INFO: PixTest:: pg_setup set to default.
[12:40:56.859] INFO: 6 hot pixels found in step 4
[12:40:57.856] INFO: Collecting data for 5 seconds...
[12:41:02.874] INFO: Done with hot pixel readout
[12:41:15.142] INFO: PixTest:: pg_setup set to default.
[12:41:15.143] INFO: 1 hot pixels found in step 5
[12:41:16.139] INFO: Collecting data for 5 seconds...
[12:41:21.156] INFO: Done with hot pixel readout
[12:41:33.436] INFO: PixTest:: pg_setup set to default.
[12:41:33.437] INFO: 3 hot pixels found in step 6
[12:41:34.435] INFO: Collecting data for 5 seconds...
[12:41:39.451] INFO: Done with hot pixel readout
[12:41:51.734] INFO: PixTest:: pg_setup set to default.
[12:41:51.734] INFO: 3 hot pixels found in step 7
[12:41:52.729] INFO: Collecting data for 5 seconds...
[12:41:57.747] INFO: Done with hot pixel readout
[12:42:10.037] INFO: PixTest:: pg_setup set to default.
[12:42:10.037] INFO: 3 hot pixels found in step 8
[12:42:11.035] INFO: Collecting data for 5 seconds...
[12:42:16.052] INFO: Done with hot pixel readout
[12:42:28.372] INFO: PixTest:: pg_setup set to default.
[12:42:28.373] INFO: 2 hot pixels found in step 9
[12:42:29.370] INFO: Collecting data for 5 seconds...
[12:42:34.387] INFO: Done with hot pixel readout
[12:42:46.681] INFO: PixTest:: pg_setup set to default.

[12:42:46.682] INFO: 3 hot pixels found in step 10
[12:42:47.678] INFO: Collecting data for 5 seconds...
[12:42:52.695] INFO: Done with hot pixel readout
[12:43:04.962] INFO: PixTest:: pg_setup set to default.
[12:43:04.963] INFO: 2 hot pixels found in step 11
[12:43:05.959] INFO: Collecting data for 5 seconds...
[12:43:10.976] INFO: Done with hot pixel readout
[12:43:23.261] INFO: PixTest:: pg_setup set to default.

[12:43:23.262] INFO: 3 hot pixels found in step 12
[12:43:24.258] INFO: Collecting data for 5 seconds...
[12:43:29.275] INFO: Done with hot pixel readout
[12:43:41.546] INFO: PixTest:: pg_setup set to default.
[12:43:41.547] INFO: 4 hot pixels found in step 13
[12:43:42.543] INFO: Collecting data for 5 seconds...
[12:43:47.560] INFO: Done with hot pixel readout
[12:43:59.844] INFO: PixTest:: pg_setup set to default.


[12:43:59.847] INFO: 6 hot pixels found in step 14
[12:43:59.892] INFO: 6 hot pixels could not be trimmed and have been masked.
[12:43:59.919] INFO: PixTest::trimHotPixels() done
[12:43:59.920] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NW_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C0.dat
[12:43:59.930] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NW_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C1.dat
[12:43:59.935] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NW_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C2.dat
[12:43:59.941] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NW_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C3.dat
[12:43:59.946] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NW_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C4.dat
[12:43:59.951] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NW_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C5.dat
[12:43:59.956] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NW_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C6.dat
[12:43:59.962] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NW_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C7.dat
[12:43:59.967] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NW_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C8.dat
[12:43:59.972] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NW_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C9.dat
[12:43:59.977] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NW_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C10.dat
[12:43:59.982] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NW_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C11.dat
[12:43:59.988] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NW_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C12.dat
[12:43:59.993] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NW_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C13.dat
[12:43:59.998] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NW_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C14.dat
[12:44:00.003] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NW_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C15.dat
[12:44:00.009] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Y-P-NW_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//defaultMaskFile.dat
[12:44:00.020] INFO: enter test to run
[12:44:30.025] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[12:44:30.025] INFO: running: highrate
[12:44:30.030] INFO: ----------------------------------------------------------------------
[12:44:30.030] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[12:44:30.030] INFO: ----------------------------------------------------------------------
[12:44:30.030] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[12:44:30.030] INFO: edge/corner pixel THR is adjusted
[12:44:30.030] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:44:30.987] INFO: Collecting data for 1 seconds...
[12:44:31.991] INFO: Done with hot pixel readout
[12:44:36.263] INFO: PixTest:: pg_setup set to default.
[12:44:36.264] INFO: 0 hot pixels found in step 0
[12:44:36.269] INFO: 0 hot pixels could not be trimmed and have been masked.
[12:44:36.349] INFO: PixTest::trimHotPixels() done
[12:44:36.349] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NW_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C0.dat
[12:44:36.361] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NW_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C1.dat
[12:44:36.367] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NW_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C2.dat
[12:44:36.372] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NW_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C3.dat
[12:44:36.377] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NW_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C4.dat
[12:44:36.382] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NW_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C5.dat
[12:44:36.388] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NW_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C6.dat
[12:44:36.393] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NW_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C7.dat
[12:44:36.398] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NW_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C8.dat
[12:44:36.403] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NW_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C9.dat
[12:44:36.409] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NW_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C10.dat
[12:44:36.414] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NW_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C11.dat
[12:44:36.419] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NW_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C12.dat
[12:44:36.424] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NW_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C13.dat
[12:44:36.430] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NW_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C14.dat
[12:44:36.435] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NW_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C15.dat
[12:44:36.440] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Y-P-NW_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//defaultMaskFile.dat
[12:44:36.450] INFO: enter test to run
[12:46:04.384] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[12:46:04.384] INFO: running: xray
[12:46:04.386] INFO: ----------------------------------------------------------------------
[12:46:04.386] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:46:04.386] INFO: ----------------------------------------------------------------------
[12:46:05.386] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:46:16.246] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[12:46:45.921] INFO: Resuming triggers.
[12:46:56.781] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[12:47:26.604] INFO: Resuming triggers.
[12:47:37.464] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[12:48:07.132] INFO: Resuming triggers.
[12:48:17.993] INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[12:48:47.672] INFO: Resuming triggers.
[12:48:58.531] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[12:49:28.423] INFO: Resuming triggers.
[12:49:39.280] INFO: run duration 64 seconds, buffer almost full (81%), pausing triggers.
[12:50:08.725] INFO: Resuming triggers.
[12:50:19.583] INFO: run duration 75 seconds, buffer almost full (81%), pausing triggers.
[12:50:49.807] INFO: Resuming triggers.
[12:51:00.661] INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[12:51:30.964] INFO: Resuming triggers.
[12:51:41.817] INFO: run duration 97 seconds, buffer almost full (81%), pausing triggers.
[12:52:11.835] INFO: Resuming triggers.
[12:52:14.474] INFO: data taking finished, elapsed time: 100 seconds.
[12:52:21.991] INFO: PixTest:: pg_setup set to default.
[12:52:21.995] INFO: PixTestXray::doPhRun() done
[12:52:22.132] INFO: enter test to run
[12:54:34.925] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[12:54:34.925] INFO: running: xray
[12:54:34.926] INFO: ----------------------------------------------------------------------
[12:54:34.926] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:54:34.926] INFO: ----------------------------------------------------------------------
[12:54:35.889] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:54:42.052] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[12:55:12.243] INFO: Resuming triggers.
[12:55:18.405] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[12:55:48.549] INFO: Resuming triggers.
[12:55:54.711] INFO: run duration 18 seconds, buffer almost full (81%), pausing triggers.
[12:56:24.868] INFO: Resuming triggers.
[12:56:31.032] INFO: run duration 24 seconds, buffer almost full (81%), pausing triggers.
[12:57:01.191] INFO: Resuming triggers.
[12:57:07.359] INFO: run duration 30 seconds, buffer almost full (81%), pausing triggers.
[12:57:37.489] INFO: Resuming triggers.
[12:57:43.654] INFO: run duration 36 seconds, buffer almost full (81%), pausing triggers.
[12:58:13.857] INFO: Resuming triggers.
[12:58:20.026] INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[12:58:50.287] INFO: Resuming triggers.
[12:58:56.454] INFO: run duration 49 seconds, buffer almost full (81%), pausing triggers.
[12:59:26.644] INFO: Resuming triggers.
[12:59:32.808] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[13:00:03.059] INFO: Resuming triggers.
[13:00:09.225] INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[13:00:40.163] INFO: Resuming triggers.
[13:00:46.325] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[13:01:16.810] INFO: Resuming triggers.
[13:01:22.971] INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[13:01:54.556] INFO: Resuming triggers.
[13:02:00.716] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[13:02:32.371] INFO: Resuming triggers.
[13:02:38.533] INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[13:03:09.148] INFO: Resuming triggers.
[13:03:15.312] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[13:03:45.475] INFO: Resuming triggers.
[13:03:51.633] INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[13:04:21.840] INFO: Resuming triggers.
[13:04:23.563] INFO: data taking finished, elapsed time: 100 seconds.
[13:04:32.311] INFO: PixTest:: pg_setup set to default.
[13:04:32.314] INFO: PixTestXray::doPhRun() done
[13:04:32.462] INFO: enter test to run
[13:05:29.320] INFO: test: HighRate no parameter change
[13:05:29.320] INFO: running: highrate
[13:05:29.321] INFO: ----------------------------------------------------------------------
[13:05:29.321] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[13:05:29.321] INFO: ----------------------------------------------------------------------
[13:05:29.463] INFO: Expecting 768 events.
[13:05:30.597] INFO: 768 events read in total (418ms).
[13:05:30.598] INFO: Test took 1269ms.
[13:05:31.401] INFO: Expecting 41600 events.
[13:05:34.606] INFO: 41600 events read in total (2678ms).
[13:05:34.608] INFO: Test took 4004ms.
[13:05:34.652] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:05:35.360] INFO: Expecting 41600 events.
[13:05:38.652] INFO: 41600 events read in total (2765ms).
[13:05:38.653] INFO: Test took 3982ms.
[13:05:38.691] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:05:39.406] INFO: Expecting 41600 events.
[13:05:42.678] INFO: 41600 events read in total (2745ms).
[13:05:42.679] INFO: Test took 3970ms.
[13:05:42.717] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:05:43.436] INFO: Expecting 41600 events.
[13:05:46.729] INFO: 41600 events read in total (2766ms).
[13:05:46.730] INFO: Test took 3994ms.
[13:05:46.768] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:05:47.482] INFO: Expecting 41600 events.
[13:05:50.785] INFO: 41600 events read in total (2776ms).
[13:05:50.786] INFO: Test took 4000ms.
[13:05:50.823] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:05:51.539] INFO: Expecting 41600 events.
[13:05:54.833] INFO: 41600 events read in total (2767ms).
[13:05:54.834] INFO: Test took 3991ms.
[13:05:54.871] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:05:55.589] INFO: Expecting 41600 events.
[13:05:58.895] INFO: 41600 events read in total (2779ms).
[13:05:58.896] INFO: Test took 4004ms.
[13:05:58.934] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:05:59.646] INFO: Expecting 41600 events.
[13:06:02.954] INFO: 41600 events read in total (2782ms).
[13:06:02.955] INFO: Test took 4001ms.
[13:06:02.993] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:06:03.710] INFO: Expecting 41600 events.
[13:06:07.011] INFO: 41600 events read in total (2774ms).
[13:06:07.012] INFO: Test took 3999ms.
[13:06:07.050] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:06:07.766] INFO: Expecting 41600 events.
[13:06:11.058] INFO: 41600 events read in total (2765ms).
[13:06:11.059] INFO: Test took 3991ms.
[13:06:11.097] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:06:11.816] INFO: Expecting 41600 events.
[13:06:15.112] INFO: 41600 events read in total (2769ms).
[13:06:15.113] INFO: Test took 3997ms.
[13:06:15.151] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:06:15.869] INFO: Expecting 41600 events.
[13:06:19.169] INFO: 41600 events read in total (2773ms).
[13:06:19.170] INFO: Test took 3999ms.
[13:06:19.207] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:06:19.926] INFO: Expecting 41600 events.
[13:06:23.214] INFO: 41600 events read in total (2761ms).
[13:06:23.215] INFO: Test took 3989ms.
[13:06:23.253] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:06:23.972] INFO: Expecting 41600 events.
[13:06:27.278] INFO: 41600 events read in total (2779ms).
[13:06:27.279] INFO: Test took 4006ms.
[13:06:27.316] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:06:28.034] INFO: Expecting 41600 events.
[13:06:31.344] INFO: 41600 events read in total (2783ms).
[13:06:31.345] INFO: Test took 4010ms.
[13:06:31.383] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:06:32.096] INFO: Expecting 41600 events.
[13:06:35.393] INFO: 41600 events read in total (2770ms).
[13:06:35.394] INFO: Test took 3993ms.
[13:06:35.432] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:06:36.153] INFO: Expecting 41600 events.
[13:06:39.444] INFO: 41600 events read in total (2764ms).
[13:06:39.445] INFO: Test took 3994ms.
[13:06:39.483] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:06:40.197] INFO: Expecting 41600 events.
[13:06:43.489] INFO: 41600 events read in total (2765ms).
[13:06:43.490] INFO: Test took 3988ms.
[13:06:43.527] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:06:44.243] INFO: Expecting 41600 events.
[13:06:47.521] INFO: 41600 events read in total (2751ms).
[13:06:47.522] INFO: Test took 3976ms.
[13:06:47.560] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:06:48.276] INFO: Expecting 41600 events.
[13:06:51.370] INFO: 41600 events read in total (2567ms).
[13:06:51.371] INFO: Test took 3791ms.
[13:06:51.408] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:06:51.766] INFO: enter test to run
[13:07:14.199] INFO: test: HighRate no parameter change
[13:07:14.199] INFO: running: highrate
[13:07:14.200] INFO: ----------------------------------------------------------------------
[13:07:14.200] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:07:14.200] INFO: ----------------------------------------------------------------------
[13:07:14.817] INFO: Expecting 208000 events.
[13:07:26.946] INFO: 208000 events read in total (11602ms).
[13:07:26.950] INFO: Test took 12740ms.
[13:07:27.114] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:07:27.374] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[13:07:27.374] INFO: number of red-efficiency pixels: 155 63 98 143 190 197 186 135 102 132 127 120 105 48 29 25
[13:07:27.374] INFO: number of X-ray hits detected: 75721 50979 78834 123759 129782 131640 128063 95007 86568 110545 111828 97572 100010 57103 24325 26848
[13:07:27.374] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:07:27.374] INFO: number of Vcal hits detected: 207815 207937 207899 207851 207806 207798 207807 207856 207896 207865 207872 207878 207889 207952 207970 207974
[13:07:27.374] INFO: Vcal hit fiducial efficiency (%): 99.9 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
[13:07:27.374] INFO: Vcal hit overall efficiency (%): 99.9 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[13:07:27.374] INFO: X-ray hit rate [MHz/cm2]: 22.2 14.9 23.1 36.3 38.0 38.6 37.5 27.8 25.4 32.4 32.8 28.6 29.3 16.7 7.1 7.9
[13:07:27.374] INFO: PixTestHighRate::doXPixelAlive() done
[13:07:27.422] INFO: PixTest:: pg_setup set to default.
[13:07:27.436] INFO: enter test to run
[13:08:50.062] INFO: test: HighRate no parameter change
[13:08:50.062] INFO: running: highrate
[13:08:50.063] INFO: ----------------------------------------------------------------------
[13:08:50.063] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:08:50.063] INFO: ----------------------------------------------------------------------
[13:08:50.674] INFO: Expecting 208000 events.
[13:09:04.884] INFO: 208000 events read in total (13683ms).
[13:09:04.890] INFO: Test took 14817ms.
[13:09:05.225] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:09:05.538] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[13:09:05.539] INFO: number of red-efficiency pixels: 490 144 273 484 716 777 687 459 339 402 415 431 308 181 58 55
[13:09:05.539] INFO: number of X-ray hits detected: 157561 106449 165600 259118 271294 274762 268174 198543 180732 231948 234026 203163 209710 121401 50514 56314
[13:09:05.539] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:09:05.539] INFO: number of Vcal hits detected: 205155 207849 207699 207473 207183 207115 207219 207483 207650 207553 207555 207542 207673 207806 207942 207945
[13:09:05.539] INFO: Vcal hit fiducial efficiency (%): 98.6 99.9 99.9 99.8 99.6 99.6 99.6 99.8 99.8 99.8 99.8 99.8 99.9 99.9 100.0 100.0
[13:09:05.539] INFO: Vcal hit overall efficiency (%): 98.6 99.9 99.9 99.7 99.6 99.6 99.6 99.8 99.8 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[13:09:05.539] INFO: X-ray hit rate [MHz/cm2]: 46.2 31.2 48.5 75.9 79.5 80.5 78.6 58.2 53.0 68.0 68.6 59.5 61.5 35.6 14.8 16.5
[13:09:05.539] INFO: PixTestHighRate::doXPixelAlive() done
[13:09:05.587] INFO: PixTest:: pg_setup set to default.
[13:09:05.599] INFO: enter test to run
[13:09:57.462] INFO: test: HighRate no parameter change
[13:09:57.462] INFO: running: highrate
[13:09:57.463] INFO: ----------------------------------------------------------------------
[13:09:57.463] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:09:57.463] INFO: ----------------------------------------------------------------------
[13:09:58.075] INFO: Expecting 208000 events.
[13:10:14.435] INFO: 208000 events read in total (15833ms).
[13:10:14.443] INFO: Test took 16972ms.
[13:10:14.943] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:10:15.308] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[13:10:15.308] INFO: number of red-efficiency pixels: 817 264 703 1217 1723 1720 1624 993 748 916 1015 994 764 437 104 99
[13:10:15.308] INFO: number of X-ray hits detected: 235469 158892 246299 386102 402823 408631 398799 297350 271015 345381 349250 305343 314590 181019 76722 84678
[13:10:15.309] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:10:15.309] INFO: number of Vcal hits detected: 201127 207719 207025 206466 205488 205564 205656 206607 207119 206940 206735 206725 207116 207501 207893 207901
[13:10:15.309] INFO: Vcal hit fiducial efficiency (%): 96.6 99.9 99.6 99.3 98.9 98.9 99.0 99.4 99.6 99.5 99.4 99.5 99.6 99.8 99.9 100.0
[13:10:15.309] INFO: Vcal hit overall efficiency (%): 96.7 99.9 99.5 99.3 98.8 98.8 98.9 99.3 99.6 99.5 99.4 99.4 99.6 99.8 99.9 100.0
[13:10:15.309] INFO: X-ray hit rate [MHz/cm2]: 69.0 46.6 72.2 113.2 118.1 119.8 116.9 87.2 79.4 101.2 102.4 89.5 92.2 53.1 22.5 24.8
[13:10:15.309] INFO: PixTestHighRate::doXPixelAlive() done
[13:10:15.356] INFO: PixTest:: pg_setup set to default.
[13:10:15.376] INFO: enter test to run
[13:11:14.509] INFO: test: exit no parameter change
[13:11:14.865] QUIET: Connection to board 33 closed.
[13:11:14.886] INFO: pXar: this is the end, my friend