[15:57:38.022] INFO: *** Welcome to pxar ***
[15:57:38.022] INFO: *** Today: 2016/06/27
[15:57:38.070] INFO: *** Version: v1.9.0-814-g7497
[15:57:38.070] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Y-E-NJ_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-E-NJ_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//dacParameters35_C15.dat
[15:57:38.125] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Y-E-NJ_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-E-NJ_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//tbmParameters_C0b.dat
[15:57:38.125] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Y-E-NJ_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//defaultMaskFile.dat
[15:57:38.137] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Y-E-NJ_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-E-NJ_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C15.dat
[15:57:38.235] INFO: clk: 4
[15:57:38.235] INFO: ctr: 4
[15:57:38.235] INFO: sda: 19
[15:57:38.235] INFO: tin: 9
[15:57:38.235] INFO: level: 15
[15:57:38.235] INFO: triggerdelay: 0
[15:57:38.235] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[15:57:38.235] INFO: Log level: INFO
[15:57:38.253] QUIET: Connection to board DTB_WREK4U opened.
[15:57:38.256] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 32
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREK4U
MAC address: 40D855118020
Hostname: pixelDTB032
Comment:
------------------------------------------------------
[15:57:38.259] INFO: RPC call hashes of host and DTB match: 398089610
[15:57:39.793] INFO: DUT info:
[15:57:39.794] INFO: The DUT currently contains the following objects:
[15:57:39.794] INFO: 2 TBM Cores tbm08c (2 ON)
[15:57:39.794] INFO: TBM Core alpha (0): 7 registers set
[15:57:39.794] INFO: TBM Core beta (1): 7 registers set
[15:57:39.794] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[15:57:39.794] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[15:57:39.794] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[15:57:39.794] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[15:57:39.794] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[15:57:39.794] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[15:57:39.794] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[15:57:39.794] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[15:57:39.794] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[15:57:39.794] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[15:57:39.794] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[15:57:39.794] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[15:57:39.794] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[15:57:39.794] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[15:57:39.794] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[15:57:39.795] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[15:57:39.795] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[15:57:40.198] INFO: enter 'restricted' command line mode
[15:57:40.198] INFO: enter test to run
[15:57:44.140] INFO: test: PixelAlive no parameter change
[15:57:44.140] INFO: running: pixelalive
[15:57:44.149] INFO: ----------------------------------------------------------------------
[15:57:44.149] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[15:57:44.149] INFO: ----------------------------------------------------------------------
[15:57:44.467] INFO: Expecting 41600 events.
[15:57:48.794] INFO: 41600 events read in total (3609ms).
[15:57:48.962] INFO: Test took 4809ms.
[15:57:48.975] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:57:49.238] INFO: PixTestAlive::aliveTest() done
[15:57:49.238] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:57:49.269] INFO: enter test to run
[15:58:08.564] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[15:58:08.564] INFO: running: highrate
[15:58:08.564] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Y-E-NJ_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-E-NJ_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[15:58:08.774] INFO: ----------------------------------------------------------------------
[15:58:08.774] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[15:58:08.774] INFO: ----------------------------------------------------------------------
[15:58:08.774] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[15:58:08.774] INFO: edge/corner pixel THR is adjusted
[15:58:08.774] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:58:09.734] INFO: Collecting data for 5 seconds...
[15:58:14.751] INFO: Done with hot pixel readout
[15:58:27.735] INFO: PixTest:: pg_setup set to default.



















































[15:58:27.765] INFO: 68 hot pixels found in step 0
[15:58:28.765] INFO: Collecting data for 5 seconds...
[15:58:33.781] INFO: Done with hot pixel readout
[15:58:46.674] INFO: PixTest:: pg_setup set to default.







































[15:58:46.676] INFO: 62 hot pixels found in step 1
[15:58:47.674] INFO: Collecting data for 5 seconds...
[15:58:52.690] INFO: Done with hot pixel readout
[15:59:05.599] INFO: PixTest:: pg_setup set to default.























































[15:59:05.601] INFO: 79 hot pixels found in step 2
[15:59:06.603] INFO: Collecting data for 5 seconds...
[15:59:11.618] INFO: Done with hot pixel readout
[15:59:24.616] INFO: PixTest:: pg_setup set to default.




















































[15:59:24.618] INFO: 69 hot pixels found in step 3
[15:59:25.618] INFO: Collecting data for 5 seconds...
[15:59:30.634] INFO: Done with hot pixel readout
[15:59:43.515] INFO: PixTest:: pg_setup set to default.


















































[15:59:43.517] INFO: 66 hot pixels found in step 4
[15:59:44.517] INFO: Collecting data for 5 seconds...
[15:59:49.533] INFO: Done with hot pixel readout
[16:00:02.415] INFO: PixTest:: pg_setup set to default.





















































[16:00:02.417] INFO: 68 hot pixels found in step 5
[16:00:03.416] INFO: Collecting data for 5 seconds...
[16:00:08.432] INFO: Done with hot pixel readout
[16:00:21.388] INFO: PixTest:: pg_setup set to default.




















































[16:00:21.390] INFO: 68 hot pixels found in step 6
[16:00:22.389] INFO: Collecting data for 5 seconds...
[16:00:27.405] INFO: Done with hot pixel readout
[16:00:40.335] INFO: PixTest:: pg_setup set to default.

















































[16:00:40.337] INFO: 76 hot pixels found in step 7
[16:00:41.336] INFO: Collecting data for 5 seconds...
[16:00:46.352] INFO: Done with hot pixel readout
[16:00:59.324] INFO: PixTest:: pg_setup set to default.



















































[16:00:59.325] INFO: 74 hot pixels found in step 8
[16:01:00.326] INFO: Collecting data for 5 seconds...
[16:01:05.341] INFO: Done with hot pixel readout
[16:01:18.376] INFO: PixTest:: pg_setup set to default.

















































[16:01:18.377] INFO: 66 hot pixels found in step 9
[16:01:19.377] INFO: Collecting data for 5 seconds...
[16:01:24.396] INFO: Done with hot pixel readout
[16:01:37.239] INFO: PixTest:: pg_setup set to default.














































[16:01:37.242] INFO: 64 hot pixels found in step 10
[16:01:38.242] INFO: Collecting data for 5 seconds...
[16:01:43.259] INFO: Done with hot pixel readout
[16:01:56.171] INFO: PixTest:: pg_setup set to default.











































[16:01:56.173] INFO: 61 hot pixels found in step 11
[16:01:57.173] INFO: Collecting data for 5 seconds...
[16:02:02.192] INFO: Done with hot pixel readout
[16:02:15.275] INFO: PixTest:: pg_setup set to default.

























































[16:02:15.277] INFO: 74 hot pixels found in step 12
[16:02:16.277] INFO: Collecting data for 5 seconds...
[16:02:21.294] INFO: Done with hot pixel readout
[16:02:34.207] INFO: PixTest:: pg_setup set to default.















































[16:02:34.209] INFO: 64 hot pixels found in step 13
[16:02:35.208] INFO: Collecting data for 5 seconds...
[16:02:40.226] INFO: Done with hot pixel readout
[16:02:53.293] INFO: PixTest:: pg_setup set to default.



















































[16:02:53.295] INFO: 66 hot pixels found in step 14
[16:02:53.339] INFO: 66 hot pixels could not be trimmed and have been masked.
[16:02:53.343] INFO: PixTest::trimHotPixels() done
[16:02:53.364] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-E-NJ_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C0.dat
[16:02:53.378] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-E-NJ_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C1.dat
[16:02:53.384] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-E-NJ_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C2.dat
[16:02:53.391] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-E-NJ_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C3.dat
[16:02:53.397] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-E-NJ_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C4.dat
[16:02:53.404] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-E-NJ_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C5.dat
[16:02:53.410] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-E-NJ_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C6.dat
[16:02:53.417] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-E-NJ_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C7.dat
[16:02:53.423] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-E-NJ_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C8.dat
[16:02:53.428] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-E-NJ_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C9.dat
[16:02:53.433] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-E-NJ_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C10.dat
[16:02:53.439] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-E-NJ_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C11.dat
[16:02:53.444] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-E-NJ_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C12.dat
[16:02:53.449] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-E-NJ_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C13.dat
[16:02:53.455] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-E-NJ_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C14.dat
[16:02:53.460] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-E-NJ_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C15.dat
[16:02:53.480] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Y-E-NJ_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//defaultMaskFile.dat
[16:02:53.496] INFO: enter test to run
[16:03:33.834] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[16:03:33.834] INFO: running: highrate
[16:03:33.839] INFO: ----------------------------------------------------------------------
[16:03:33.839] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[16:03:33.839] INFO: ----------------------------------------------------------------------
[16:03:33.839] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[16:03:33.839] INFO: edge/corner pixel THR is adjusted
[16:03:33.839] INFO: PixTestHighRate::trimHotPixels: step 0...
[16:03:34.796] INFO: Collecting data for 1 seconds...
[16:03:35.800] INFO: Done with hot pixel readout
[16:03:40.771] INFO: PixTest:: pg_setup set to default.
[16:03:40.772] INFO: 0 hot pixels found in step 0
[16:03:40.777] INFO: 0 hot pixels could not be trimmed and have been masked.
[16:03:40.828] INFO: PixTest::trimHotPixels() done
[16:03:40.828] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-E-NJ_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C0.dat
[16:03:40.833] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-E-NJ_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C1.dat
[16:03:40.839] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-E-NJ_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C2.dat
[16:03:40.844] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-E-NJ_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C3.dat
[16:03:40.849] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-E-NJ_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C4.dat
[16:03:40.855] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-E-NJ_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C5.dat
[16:03:40.860] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-E-NJ_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C6.dat
[16:03:40.865] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-E-NJ_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C7.dat
[16:03:40.871] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-E-NJ_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C8.dat
[16:03:40.876] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-E-NJ_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C9.dat
[16:03:40.881] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-E-NJ_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C10.dat
[16:03:40.887] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-E-NJ_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C11.dat
[16:03:40.892] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-E-NJ_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C12.dat
[16:03:40.897] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-E-NJ_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C13.dat
[16:03:40.903] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-E-NJ_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C14.dat
[16:03:40.908] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-E-NJ_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C15.dat
[16:03:40.913] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Y-E-NJ_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//defaultMaskFile.dat
[16:03:40.923] INFO: enter test to run
[16:04:04.330] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[16:04:04.330] INFO: running: xray
[16:04:04.331] INFO: ----------------------------------------------------------------------
[16:04:04.331] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[16:04:04.331] INFO: ----------------------------------------------------------------------
[16:04:05.294] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[16:04:15.340] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[16:04:43.943] INFO: Resuming triggers.
[16:04:53.991] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[16:05:23.573] INFO: Resuming triggers.
[16:05:33.621] INFO: run duration 30 seconds, buffer almost full (81%), pausing triggers.
[16:06:02.981] INFO: Resuming triggers.
[16:06:13.032] INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[16:06:42.585] INFO: Resuming triggers.
[16:06:52.636] INFO: run duration 50 seconds, buffer almost full (81%), pausing triggers.
[16:07:21.035] INFO: Resuming triggers.
[16:07:31.082] INFO: run duration 60 seconds, buffer almost full (81%), pausing triggers.
[16:07:59.905] INFO: Resuming triggers.
[16:08:09.955] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[16:08:39.619] INFO: Resuming triggers.
[16:08:49.667] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[16:09:19.222] INFO: Resuming triggers.
[16:09:29.274] INFO: run duration 90 seconds, buffer almost full (81%), pausing triggers.
[16:09:58.594] INFO: Resuming triggers.
[16:10:08.490] INFO: data taking finished, elapsed time: 100 seconds.
[16:10:37.707] INFO: PixTest:: pg_setup set to default.
[16:10:37.710] INFO: PixTestXray::doPhRun() done
[16:10:37.925] INFO: enter test to run
[16:11:03.919] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[16:11:03.919] INFO: running: xray
[16:11:03.920] INFO: ----------------------------------------------------------------------
[16:11:03.920] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[16:11:03.920] INFO: ----------------------------------------------------------------------
[16:11:04.894] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[16:11:10.275] INFO: run duration 5 seconds, buffer almost full (81%), pausing triggers.
[16:11:40.541] INFO: Resuming triggers.
[16:11:45.926] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[16:12:15.997] INFO: Resuming triggers.
[16:12:21.386] INFO: run duration 16 seconds, buffer almost full (81%), pausing triggers.
[16:12:51.643] INFO: Resuming triggers.
[16:12:57.030] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[16:13:27.982] INFO: Resuming triggers.
[16:13:33.366] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[16:14:03.793] INFO: Resuming triggers.
[16:14:09.179] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[16:14:39.842] INFO: Resuming triggers.
[16:14:45.226] INFO: run duration 37 seconds, buffer almost full (81%), pausing triggers.
[16:15:15.696] INFO: Resuming triggers.
[16:15:21.078] INFO: run duration 42 seconds, buffer almost full (81%), pausing triggers.
[16:15:52.530] INFO: Resuming triggers.
[16:15:57.913] INFO: run duration 48 seconds, buffer almost full (81%), pausing triggers.
[16:16:28.983] INFO: Resuming triggers.
[16:16:34.371] INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[16:17:05.435] INFO: Resuming triggers.
[16:17:10.818] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[16:17:42.240] INFO: Resuming triggers.
[16:17:47.626] INFO: run duration 64 seconds, buffer almost full (81%), pausing triggers.
[16:18:17.909] INFO: Resuming triggers.
[16:18:23.298] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[16:18:53.364] INFO: Resuming triggers.
[16:18:58.752] INFO: run duration 75 seconds, buffer almost full (81%), pausing triggers.
[16:19:28.462] INFO: Resuming triggers.
[16:19:33.847] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[16:20:03.971] INFO: Resuming triggers.
[16:20:09.357] INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[16:20:39.674] INFO: Resuming triggers.
[16:20:45.062] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[16:21:15.232] INFO: Resuming triggers.
[16:21:20.618] INFO: run duration 96 seconds, buffer almost full (81%), pausing triggers.
[16:21:50.943] INFO: Resuming triggers.
[16:21:54.349] INFO: data taking finished, elapsed time: 100 seconds.
[16:22:13.692] INFO: PixTest:: pg_setup set to default.
[16:22:13.695] INFO: PixTestXray::doPhRun() done
[16:22:13.843] INFO: enter test to run
[16:22:38.442] INFO: test: HighRate no parameter change
[16:22:38.442] INFO: running: highrate
[16:22:38.459] INFO: ----------------------------------------------------------------------
[16:22:38.459] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[16:22:38.459] INFO: ----------------------------------------------------------------------
[16:22:38.615] INFO: Expecting 768 events.
[16:22:39.749] INFO: 768 events read in total (418ms).
[16:22:39.749] INFO: Test took 1268ms.
[16:22:40.552] INFO: Expecting 41600 events.
[16:22:43.732] INFO: 41600 events read in total (2653ms).
[16:22:43.733] INFO: Test took 3959ms.
[16:22:43.778] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:22:44.484] INFO: Expecting 41600 events.
[16:22:47.768] INFO: 41600 events read in total (2757ms).
[16:22:47.770] INFO: Test took 3971ms.
[16:22:47.819] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:22:48.515] INFO: Expecting 41600 events.
[16:22:51.840] INFO: 41600 events read in total (2799ms).
[16:22:51.842] INFO: Test took 4002ms.
[16:22:51.887] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:22:52.590] INFO: Expecting 41600 events.
[16:22:55.921] INFO: 41600 events read in total (2804ms).
[16:22:55.922] INFO: Test took 4012ms.
[16:22:55.969] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:22:56.673] INFO: Expecting 41600 events.
[16:23:00.014] INFO: 41600 events read in total (2815ms).
[16:23:00.015] INFO: Test took 4023ms.
[16:23:00.063] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:23:00.764] INFO: Expecting 41600 events.
[16:23:04.087] INFO: 41600 events read in total (2796ms).
[16:23:04.088] INFO: Test took 4003ms.
[16:23:04.133] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:23:04.833] INFO: Expecting 41600 events.
[16:23:08.196] INFO: 41600 events read in total (2836ms).
[16:23:08.197] INFO: Test took 4041ms.
[16:23:08.243] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:23:08.946] INFO: Expecting 41600 events.
[16:23:12.302] INFO: 41600 events read in total (2829ms).
[16:23:12.304] INFO: Test took 4038ms.
[16:23:12.353] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:23:13.052] INFO: Expecting 41600 events.
[16:23:16.270] INFO: 41600 events read in total (2691ms).
[16:23:16.271] INFO: Test took 3895ms.
[16:23:16.317] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:23:17.019] INFO: Expecting 41600 events.
[16:23:20.354] INFO: 41600 events read in total (2808ms).
[16:23:20.355] INFO: Test took 4017ms.
[16:23:20.402] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:23:21.105] INFO: Expecting 41600 events.
[16:23:24.463] INFO: 41600 events read in total (2831ms).
[16:23:24.465] INFO: Test took 4040ms.
[16:23:24.510] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:23:25.209] INFO: Expecting 41600 events.
[16:23:28.582] INFO: 41600 events read in total (2846ms).
[16:23:28.583] INFO: Test took 4051ms.
[16:23:28.629] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:23:29.329] INFO: Expecting 41600 events.
[16:23:32.653] INFO: 41600 events read in total (2797ms).
[16:23:32.654] INFO: Test took 4001ms.
[16:23:32.700] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:23:33.401] INFO: Expecting 41600 events.
[16:23:36.731] INFO: 41600 events read in total (2803ms).
[16:23:36.732] INFO: Test took 4010ms.
[16:23:36.778] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:23:37.478] INFO: Expecting 41600 events.
[16:23:40.824] INFO: 41600 events read in total (2819ms).
[16:23:40.825] INFO: Test took 4024ms.
[16:23:40.870] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:23:41.573] INFO: Expecting 41600 events.
[16:23:44.913] INFO: 41600 events read in total (2813ms).
[16:23:44.914] INFO: Test took 4020ms.
[16:23:44.960] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:23:45.661] INFO: Expecting 41600 events.
[16:23:49.028] INFO: 41600 events read in total (2840ms).
[16:23:49.029] INFO: Test took 4046ms.
[16:23:49.075] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:23:49.774] INFO: Expecting 41600 events.
[16:23:53.121] INFO: 41600 events read in total (2820ms).
[16:23:53.123] INFO: Test took 4026ms.
[16:23:53.168] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:23:53.869] INFO: Expecting 41600 events.
[16:23:57.177] INFO: 41600 events read in total (2781ms).
[16:23:57.178] INFO: Test took 3987ms.
[16:23:57.223] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:23:57.922] INFO: Expecting 41600 events.
[16:24:01.134] INFO: 41600 events read in total (2685ms).
[16:24:01.135] INFO: Test took 3889ms.
[16:24:01.181] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:24:01.521] INFO: enter test to run
[16:24:08.729] INFO: test: HighRate no parameter change
[16:24:08.730] INFO: running: highrate
[16:24:08.731] INFO: ----------------------------------------------------------------------
[16:24:08.731] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:24:08.731] INFO: ----------------------------------------------------------------------
[16:24:09.342] INFO: Expecting 208000 events.
[16:24:21.869] INFO: 208000 events read in total (12000ms).
[16:24:21.873] INFO: Test took 13136ms.
[16:24:22.072] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:24:22.344] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[16:24:22.344] INFO: number of red-efficiency pixels: 87 68 122 231 192 262 274 164 151 199 166 156 211 97 25 24
[16:24:22.344] INFO: number of X-ray hits detected: 84592 60089 94389 153183 161545 166136 163585 115298 111084 140632 140759 120237 130693 76289 31752 34225
[16:24:22.344] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[16:24:22.344] INFO: number of Vcal hits detected: 207910 207932 207872 207763 207801 207731 207718 207818 207845 207796 207829 207840 207718 207902 207975 207976
[16:24:22.344] 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
[16:24:22.344] INFO: Vcal hit overall 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
[16:24:22.344] INFO: X-ray hit rate [MHz/cm2]: 24.8 17.6 27.7 44.9 47.4 48.7 47.9 33.8 32.6 41.2 41.3 35.2 38.3 22.4 9.3 10.0
[16:24:22.344] INFO: PixTestHighRate::doXPixelAlive() done
[16:24:22.398] INFO: PixTest:: pg_setup set to default.
[16:24:22.416] INFO: enter test to run
[16:25:35.449] INFO: test: HighRate no parameter change
[16:25:35.449] INFO: running: highrate
[16:25:35.450] INFO: ----------------------------------------------------------------------
[16:25:35.450] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:25:35.450] INFO: ----------------------------------------------------------------------
[16:25:36.072] INFO: Expecting 208000 events.
[16:25:51.144] INFO: 208000 events read in total (14544ms).
[16:25:51.151] INFO: Test took 15690ms.
[16:25:51.567] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:25:51.913] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[16:25:51.913] INFO: number of red-efficiency pixels: 325 169 432 952 768 1106 1065 483 510 757 557 518 487 345 80 77
[16:25:51.913] INFO: number of X-ray hits detected: 169729 120501 190157 308613 324302 331780 328168 231771 225511 283818 282900 243419 261230 153911 63915 69502
[16:25:51.913] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[16:25:51.913] INFO: number of Vcal hits detected: 207641 207819 207513 206859 207121 206617 206657 207406 207431 207124 207394 207429 207467 207602 207915 207922
[16:25:51.913] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.8 99.5 99.6 99.4 99.4 99.7 99.7 99.6 99.7 99.8 99.8 99.8 100.0 100.0
[16:25:51.913] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.8 99.5 99.6 99.3 99.4 99.7 99.7 99.6 99.7 99.7 99.7 99.8 100.0 100.0
[16:25:51.913] INFO: X-ray hit rate [MHz/cm2]: 49.7 35.3 55.7 90.5 95.1 97.2 96.2 67.9 66.1 83.2 82.9 71.3 76.6 45.1 18.7 20.4
[16:25:51.913] INFO: PixTestHighRate::doXPixelAlive() done
[16:25:51.959] INFO: PixTest:: pg_setup set to default.
[16:25:51.976] INFO: enter test to run
[16:27:01.384] INFO: test: HighRate no parameter change
[16:27:01.384] INFO: running: highrate
[16:27:01.386] INFO: ----------------------------------------------------------------------
[16:27:01.386] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:27:01.386] INFO: ----------------------------------------------------------------------
[16:27:02.011] INFO: Expecting 208000 events.
[16:27:20.085] INFO: 208000 events read in total (17547ms).
[16:27:20.095] INFO: Test took 18700ms.
[16:27:20.752] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:27:21.165] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[16:27:21.165] INFO: number of red-efficiency pixels: 733 421 921 2143 1813 2510 2407 1110 1191 1842 1313 1255 1163 791 167 127
[16:27:21.165] INFO: number of X-ray hits detected: 258013 183042 287208 466954 490800 502824 495890 352372 342044 429013 428018 368153 396200 232850 97179 105448
[16:27:21.165] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[16:27:21.165] INFO: number of Vcal hits detected: 207059 207529 206504 204452 205215 203480 203551 206264 206434 205181 206209 206275 206525 206841 207823 207868
[16:27:21.165] INFO: Vcal hit fiducial efficiency (%): 99.6 99.8 99.4 98.5 98.8 98.0 98.1 99.3 99.3 98.8 99.2 99.3 99.4 99.5 99.9 99.9
[16:27:21.165] INFO: Vcal hit overall efficiency (%): 99.5 99.8 99.3 98.3 98.7 97.8 97.9 99.2 99.2 98.6 99.1 99.2 99.3 99.4 99.9 99.9
[16:27:21.165] INFO: X-ray hit rate [MHz/cm2]: 75.6 53.7 84.2 136.9 143.9 147.4 145.3 103.3 100.3 125.7 125.5 107.9 116.1 68.3 28.5 30.9
[16:27:21.165] INFO: PixTestHighRate::doXPixelAlive() done
[16:27:21.210] INFO: PixTest:: pg_setup set to default.
[16:27:21.226] INFO: enter test to run
[16:29:01.311] INFO: test: exit no parameter change
[16:29:01.662] QUIET: Connection to board 32 closed.
[16:29:01.678] INFO: pXar: this is the end, my friend