[14:02:21.994] INFO: *** Welcome to pxar ***
[14:02:21.994] INFO: *** Today: 2016/06/29
[14:02:22.712] INFO: *** Version: v1.9.0-814-g7497
[14:02:22.712] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-1-45_FPIXTest-17C-FNAL-160624-1152_2016-06-24_11h54m_1466787271/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-45_FPIXTest-17C-FNAL-160624-1152_2016-06-24_11h54m_1466787271/000_FPIXTest_p17//dacParameters35_C15.dat
[14:02:22.807] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-1-45_FPIXTest-17C-FNAL-160624-1152_2016-06-24_11h54m_1466787271/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-45_FPIXTest-17C-FNAL-160624-1152_2016-06-24_11h54m_1466787271/000_FPIXTest_p17//tbmParameters_C0b.dat
[14:02:22.821] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-1-45_FPIXTest-17C-FNAL-160624-1152_2016-06-24_11h54m_1466787271/000_FPIXTest_p17//defaultMaskFile.dat
[14:02:22.821] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-1-45_FPIXTest-17C-FNAL-160624-1152_2016-06-24_11h54m_1466787271/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-45_FPIXTest-17C-FNAL-160624-1152_2016-06-24_11h54m_1466787271/000_FPIXTest_p17//trimParameters35_C15.dat
[14:02:22.945] INFO: clk: 4
[14:02:22.945] INFO: ctr: 4
[14:02:22.945] INFO: sda: 19
[14:02:22.945] INFO: tin: 9
[14:02:22.945] INFO: level: 15
[14:02:22.945] INFO: triggerdelay: 0
[14:02:22.945] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[14:02:22.945] INFO: Log level: INFO
[14:02:22.964] QUIET: Connection to board DTB_WREKRL opened.
[14:02:22.967] 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:
------------------------------------------------------
[14:02:22.970] INFO: RPC call hashes of host and DTB match: 398089610
[14:02:24.499] INFO: DUT info:
[14:02:24.499] INFO: The DUT currently contains the following objects:
[14:02:24.499] INFO: 2 TBM Cores tbm08c (2 ON)
[14:02:24.512] INFO: TBM Core alpha (0): 7 registers set
[14:02:24.512] INFO: TBM Core beta (1): 7 registers set
[14:02:24.512] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[14:02:24.513] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:24.513] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:24.513] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:24.513] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:24.513] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:24.513] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:24.513] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:24.513] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:24.513] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:24.513] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:24.513] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:24.513] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:24.513] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:24.514] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:24.514] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:24.514] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:24.956] INFO: enter 'restricted' command line mode
[14:02:24.956] INFO: enter test to run
[14:02:26.178] INFO: test: PixelAlive no parameter change
[14:02:26.178] INFO: running: pixelalive
[14:02:26.200] INFO: ----------------------------------------------------------------------
[14:02:26.200] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[14:02:26.200] INFO: ----------------------------------------------------------------------
[14:02:26.516] INFO: Expecting 41600 events.
[14:02:30.855] INFO: 41600 events read in total (3621ms).
[14:02:31.024] INFO: Test took 4820ms.
[14:02:31.036] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:02:31.302] INFO: PixTestAlive::aliveTest() done
[14:02:31.302] INFO: number of dead pixels (per ROC): 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:02:31.331] INFO: enter test to run
[14:03:53.673] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[14:03:53.673] INFO: running: highrate
[14:03:53.674] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-1-45_FPIXTest-17C-FNAL-160624-1152_2016-06-24_11h54m_1466787271/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-45_FPIXTest-17C-FNAL-160624-1152_2016-06-24_11h54m_1466787271/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[14:03:53.977] INFO: ----------------------------------------------------------------------
[14:03:53.977] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[14:03:53.977] INFO: ----------------------------------------------------------------------
[14:03:53.977] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[14:03:53.977] INFO: edge/corner pixel THR is adjusted
[14:03:53.977] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:03:54.958] INFO: Collecting data for 5 seconds...
[14:03:59.975] INFO: Done with hot pixel readout
[14:04:11.333] INFO: PixTest:: pg_setup set to default.
[14:04:11.334] INFO: 13 hot pixels found in step 0
[14:04:12.321] INFO: Collecting data for 5 seconds...
[14:04:17.336] INFO: Done with hot pixel readout
[14:04:28.635] INFO: PixTest:: pg_setup set to default.

[14:04:28.635] INFO: 15 hot pixels found in step 1
[14:04:29.627] INFO: Collecting data for 5 seconds...
[14:04:34.643] INFO: Done with hot pixel readout
[14:04:45.964] INFO: PixTest:: pg_setup set to default.

[14:04:45.965] INFO: 12 hot pixels found in step 2
[14:04:46.955] INFO: Collecting data for 5 seconds...
[14:04:51.972] INFO: Done with hot pixel readout
[14:05:03.294] INFO: PixTest:: pg_setup set to default.

[14:05:03.295] INFO: 15 hot pixels found in step 3
[14:05:04.285] INFO: Collecting data for 5 seconds...
[14:05:09.301] INFO: Done with hot pixel readout
[14:05:20.731] INFO: PixTest:: pg_setup set to default.

[14:05:20.732] INFO: 11 hot pixels found in step 4
[14:05:21.721] INFO: Collecting data for 5 seconds...
[14:05:26.741] INFO: Done with hot pixel readout
[14:05:38.062] INFO: PixTest:: pg_setup set to default.

[14:05:38.063] INFO: 9 hot pixels found in step 5
[14:05:39.053] INFO: Collecting data for 5 seconds...
[14:05:44.072] INFO: Done with hot pixel readout
[14:05:55.470] INFO: PixTest:: pg_setup set to default.


[14:05:55.471] INFO: 9 hot pixels found in step 6
[14:05:56.462] INFO: Collecting data for 5 seconds...
[14:06:01.481] INFO: Done with hot pixel readout
[14:06:12.754] INFO: PixTest:: pg_setup set to default.


[14:06:12.755] INFO: 7 hot pixels found in step 7
[14:06:13.744] INFO: Collecting data for 5 seconds...
[14:06:18.763] INFO: Done with hot pixel readout
[14:06:29.917] INFO: PixTest:: pg_setup set to default.


[14:06:29.918] INFO: 3 hot pixels found in step 8
[14:06:30.908] INFO: Collecting data for 5 seconds...
[14:06:35.926] INFO: Done with hot pixel readout
[14:06:47.155] INFO: PixTest:: pg_setup set to default.

[14:06:47.156] INFO: 2 hot pixels found in step 9
[14:06:48.146] INFO: Collecting data for 5 seconds...
[14:06:53.164] INFO: Done with hot pixel readout
[14:07:04.433] INFO: PixTest:: pg_setup set to default.


[14:07:04.434] INFO: 5 hot pixels found in step 10
[14:07:05.423] INFO: Collecting data for 5 seconds...
[14:07:10.441] INFO: Done with hot pixel readout
[14:07:21.902] INFO: PixTest:: pg_setup set to default.


[14:07:21.903] INFO: 2 hot pixels found in step 11
[14:07:21.938] INFO: 2 hot pixels could not be trimmed and have been masked.
[14:07:21.941] INFO: PixTest::trimHotPixels() done
[14:07:21.941] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-45_FPIXTest-17C-FNAL-160624-1152_2016-06-24_11h54m_1466787271/000_FPIXTest_p17//trimParameters35_C0.dat
[14:07:21.972] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-45_FPIXTest-17C-FNAL-160624-1152_2016-06-24_11h54m_1466787271/000_FPIXTest_p17//trimParameters35_C1.dat
[14:07:21.980] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-45_FPIXTest-17C-FNAL-160624-1152_2016-06-24_11h54m_1466787271/000_FPIXTest_p17//trimParameters35_C2.dat
[14:07:21.987] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-45_FPIXTest-17C-FNAL-160624-1152_2016-06-24_11h54m_1466787271/000_FPIXTest_p17//trimParameters35_C3.dat
[14:07:21.993] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-45_FPIXTest-17C-FNAL-160624-1152_2016-06-24_11h54m_1466787271/000_FPIXTest_p17//trimParameters35_C4.dat
[14:07:21.998] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-45_FPIXTest-17C-FNAL-160624-1152_2016-06-24_11h54m_1466787271/000_FPIXTest_p17//trimParameters35_C5.dat
[14:07:22.004] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-45_FPIXTest-17C-FNAL-160624-1152_2016-06-24_11h54m_1466787271/000_FPIXTest_p17//trimParameters35_C6.dat
[14:07:22.009] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-45_FPIXTest-17C-FNAL-160624-1152_2016-06-24_11h54m_1466787271/000_FPIXTest_p17//trimParameters35_C7.dat
[14:07:22.022] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-45_FPIXTest-17C-FNAL-160624-1152_2016-06-24_11h54m_1466787271/000_FPIXTest_p17//trimParameters35_C8.dat
[14:07:22.027] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-45_FPIXTest-17C-FNAL-160624-1152_2016-06-24_11h54m_1466787271/000_FPIXTest_p17//trimParameters35_C9.dat
[14:07:22.033] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-45_FPIXTest-17C-FNAL-160624-1152_2016-06-24_11h54m_1466787271/000_FPIXTest_p17//trimParameters35_C10.dat
[14:07:22.038] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-45_FPIXTest-17C-FNAL-160624-1152_2016-06-24_11h54m_1466787271/000_FPIXTest_p17//trimParameters35_C11.dat
[14:07:22.043] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-45_FPIXTest-17C-FNAL-160624-1152_2016-06-24_11h54m_1466787271/000_FPIXTest_p17//trimParameters35_C12.dat
[14:07:22.049] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-45_FPIXTest-17C-FNAL-160624-1152_2016-06-24_11h54m_1466787271/000_FPIXTest_p17//trimParameters35_C13.dat
[14:07:22.054] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-45_FPIXTest-17C-FNAL-160624-1152_2016-06-24_11h54m_1466787271/000_FPIXTest_p17//trimParameters35_C14.dat
[14:07:22.060] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-45_FPIXTest-17C-FNAL-160624-1152_2016-06-24_11h54m_1466787271/000_FPIXTest_p17//trimParameters35_C15.dat
[14:07:22.065] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-1-45_FPIXTest-17C-FNAL-160624-1152_2016-06-24_11h54m_1466787271/000_FPIXTest_p17//defaultMaskFile.dat
[14:07:22.077] INFO: enter test to run
[14:07:57.712] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[14:07:57.712] INFO: running: highrate
[14:07:57.717] INFO: ----------------------------------------------------------------------
[14:07:57.717] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[14:07:57.717] INFO: ----------------------------------------------------------------------
[14:07:57.717] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[14:07:57.717] INFO: edge/corner pixel THR is adjusted
[14:07:57.717] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:07:58.674] INFO: Collecting data for 1 seconds...
[14:07:59.678] INFO: Done with hot pixel readout
[14:08:03.459] INFO: PixTest:: pg_setup set to default.
[14:08:03.460] INFO: 0 hot pixels found in step 0
[14:08:03.466] INFO: 0 hot pixels could not be trimmed and have been masked.
[14:08:03.561] INFO: PixTest::trimHotPixels() done
[14:08:03.561] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-45_FPIXTest-17C-FNAL-160624-1152_2016-06-24_11h54m_1466787271/000_FPIXTest_p17//trimParameters35_C0.dat
[14:08:03.568] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-45_FPIXTest-17C-FNAL-160624-1152_2016-06-24_11h54m_1466787271/000_FPIXTest_p17//trimParameters35_C1.dat
[14:08:03.574] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-45_FPIXTest-17C-FNAL-160624-1152_2016-06-24_11h54m_1466787271/000_FPIXTest_p17//trimParameters35_C2.dat
[14:08:03.579] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-45_FPIXTest-17C-FNAL-160624-1152_2016-06-24_11h54m_1466787271/000_FPIXTest_p17//trimParameters35_C3.dat
[14:08:03.584] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-45_FPIXTest-17C-FNAL-160624-1152_2016-06-24_11h54m_1466787271/000_FPIXTest_p17//trimParameters35_C4.dat
[14:08:03.590] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-45_FPIXTest-17C-FNAL-160624-1152_2016-06-24_11h54m_1466787271/000_FPIXTest_p17//trimParameters35_C5.dat
[14:08:03.595] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-45_FPIXTest-17C-FNAL-160624-1152_2016-06-24_11h54m_1466787271/000_FPIXTest_p17//trimParameters35_C6.dat
[14:08:03.600] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-45_FPIXTest-17C-FNAL-160624-1152_2016-06-24_11h54m_1466787271/000_FPIXTest_p17//trimParameters35_C7.dat
[14:08:03.606] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-45_FPIXTest-17C-FNAL-160624-1152_2016-06-24_11h54m_1466787271/000_FPIXTest_p17//trimParameters35_C8.dat
[14:08:03.611] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-45_FPIXTest-17C-FNAL-160624-1152_2016-06-24_11h54m_1466787271/000_FPIXTest_p17//trimParameters35_C9.dat
[14:08:03.617] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-45_FPIXTest-17C-FNAL-160624-1152_2016-06-24_11h54m_1466787271/000_FPIXTest_p17//trimParameters35_C10.dat
[14:08:03.622] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-45_FPIXTest-17C-FNAL-160624-1152_2016-06-24_11h54m_1466787271/000_FPIXTest_p17//trimParameters35_C11.dat
[14:08:03.628] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-45_FPIXTest-17C-FNAL-160624-1152_2016-06-24_11h54m_1466787271/000_FPIXTest_p17//trimParameters35_C12.dat
[14:08:03.633] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-45_FPIXTest-17C-FNAL-160624-1152_2016-06-24_11h54m_1466787271/000_FPIXTest_p17//trimParameters35_C13.dat
[14:08:03.638] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-45_FPIXTest-17C-FNAL-160624-1152_2016-06-24_11h54m_1466787271/000_FPIXTest_p17//trimParameters35_C14.dat
[14:08:03.644] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-45_FPIXTest-17C-FNAL-160624-1152_2016-06-24_11h54m_1466787271/000_FPIXTest_p17//trimParameters35_C15.dat
[14:08:03.649] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-1-45_FPIXTest-17C-FNAL-160624-1152_2016-06-24_11h54m_1466787271/000_FPIXTest_p17//defaultMaskFile.dat
[14:08:03.659] INFO: enter test to run
[14:08:28.312] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[14:08:28.312] INFO: running: xray
[14:08:28.313] INFO: ----------------------------------------------------------------------
[14:08:28.313] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:08:28.313] INFO: ----------------------------------------------------------------------
[14:08:29.275] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:08:41.256] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[14:09:11.551] INFO: Resuming triggers.
[14:09:23.534] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[14:09:52.885] INFO: Resuming triggers.
[14:10:04.868] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[14:10:34.110] INFO: Resuming triggers.
[14:10:46.088] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[14:11:15.177] INFO: Resuming triggers.
[14:11:27.164] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[14:11:56.396] INFO: Resuming triggers.
[14:12:08.381] INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[14:12:37.668] INFO: Resuming triggers.
[14:12:49.648] INFO: run duration 83 seconds, buffer almost full (81%), pausing triggers.
[14:13:18.967] INFO: Resuming triggers.
[14:13:30.955] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[14:14:00.225] INFO: Resuming triggers.
[14:14:04.703] INFO: data taking finished, elapsed time: 100 seconds.
[14:14:15.910] INFO: PixTest:: pg_setup set to default.
[14:14:15.913] INFO: PixTestXray::doPhRun() done
[14:14:16.074] INFO: enter test to run
[14:22:08.946] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[14:22:08.946] INFO: running: xray
[14:22:08.947] INFO: ----------------------------------------------------------------------
[14:22:08.948] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:22:08.948] INFO: ----------------------------------------------------------------------
[14:22:09.911] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:22:17.324] INFO: run duration 7 seconds, buffer almost full (81%), pausing triggers.
[14:22:47.591] INFO: Resuming triggers.
[14:22:55.006] INFO: run duration 14 seconds, buffer almost full (81%), pausing triggers.
[14:23:25.200] INFO: Resuming triggers.
[14:23:32.618] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[14:24:02.944] INFO: Resuming triggers.
[14:24:10.357] INFO: run duration 29 seconds, buffer almost full (81%), pausing triggers.
[14:24:40.724] INFO: Resuming triggers.
[14:24:48.139] INFO: run duration 36 seconds, buffer almost full (81%), pausing triggers.
[14:25:18.365] INFO: Resuming triggers.
[14:25:25.777] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[14:25:56.004] INFO: Resuming triggers.
[14:26:03.417] INFO: run duration 51 seconds, buffer almost full (81%), pausing triggers.
[14:26:33.645] INFO: Resuming triggers.
[14:26:41.060] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[14:27:11.349] INFO: Resuming triggers.
[14:27:18.763] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[14:27:49.073] INFO: Resuming triggers.
[14:27:56.485] INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[14:28:26.641] INFO: Resuming triggers.
[14:28:34.053] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[14:29:04.227] INFO: Resuming triggers.
[14:29:11.643] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[14:29:42.708] INFO: Resuming triggers.
[14:29:50.120] INFO: run duration 96 seconds, buffer almost full (81%), pausing triggers.
[14:30:21.155] INFO: Resuming triggers.
[14:30:25.103] INFO: data taking finished, elapsed time: 100 seconds.
[14:30:41.610] INFO: PixTest:: pg_setup set to default.
[14:30:41.613] INFO: PixTestXray::doPhRun() done
[14:30:41.764] INFO: enter test to run
[14:32:04.318] INFO: test: HighRate no parameter change
[14:32:04.318] INFO: running: highrate
[14:32:04.319] INFO: ----------------------------------------------------------------------
[14:32:04.319] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[14:32:04.319] INFO: ----------------------------------------------------------------------
[14:32:04.459] INFO: Expecting 768 events.
[14:32:05.593] INFO: 768 events read in total (418ms).
[14:32:05.593] INFO: Test took 1268ms.
[14:32:06.396] INFO: Expecting 41600 events.
[14:32:09.546] INFO: 41600 events read in total (2624ms).
[14:32:09.547] INFO: Test took 3947ms.
[14:32:09.577] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:32:10.307] INFO: Expecting 41600 events.
[14:32:13.519] INFO: 41600 events read in total (2685ms).
[14:32:13.519] INFO: Test took 3926ms.
[14:32:13.551] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:32:14.274] INFO: Expecting 41600 events.
[14:32:17.542] INFO: 41600 events read in total (2741ms).
[14:32:17.543] INFO: Test took 3974ms.
[14:32:17.574] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:32:18.300] INFO: Expecting 41600 events.
[14:32:21.525] INFO: 41600 events read in total (2698ms).
[14:32:21.526] INFO: Test took 3936ms.
[14:32:21.558] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:32:22.286] INFO: Expecting 41600 events.
[14:32:25.654] INFO: 41600 events read in total (2841ms).
[14:32:25.655] INFO: Test took 4079ms.
[14:32:25.686] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:32:26.415] INFO: Expecting 41600 events.
[14:32:29.638] INFO: 41600 events read in total (2696ms).
[14:32:29.639] INFO: Test took 3936ms.
[14:32:29.672] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:32:30.398] INFO: Expecting 41600 events.
[14:32:33.644] INFO: 41600 events read in total (2719ms).
[14:32:33.645] INFO: Test took 3955ms.
[14:32:33.677] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:32:34.403] INFO: Expecting 41600 events.
[14:32:37.629] INFO: 41600 events read in total (2699ms).
[14:32:37.630] INFO: Test took 3936ms.
[14:32:37.661] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:32:38.388] INFO: Expecting 41600 events.
[14:32:41.688] INFO: 41600 events read in total (2773ms).
[14:32:41.689] INFO: Test took 4010ms.
[14:32:41.721] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:32:42.447] INFO: Expecting 41600 events.
[14:32:45.811] INFO: 41600 events read in total (2837ms).
[14:32:45.812] INFO: Test took 4074ms.
[14:32:45.843] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:32:46.569] INFO: Expecting 41600 events.
[14:32:49.812] INFO: 41600 events read in total (2717ms).
[14:32:49.813] INFO: Test took 3954ms.
[14:32:49.844] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:32:50.574] INFO: Expecting 41600 events.
[14:32:53.928] INFO: 41600 events read in total (2827ms).
[14:32:53.929] INFO: Test took 4068ms.
[14:32:53.960] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:32:54.690] INFO: Expecting 41600 events.
[14:32:57.910] INFO: 41600 events read in total (2694ms).
[14:32:57.911] INFO: Test took 3934ms.
[14:32:57.942] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:32:58.669] INFO: Expecting 41600 events.
[14:33:01.867] INFO: 41600 events read in total (2671ms).
[14:33:01.867] INFO: Test took 3909ms.
[14:33:01.898] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:33:02.627] INFO: Expecting 41600 events.
[14:33:05.828] INFO: 41600 events read in total (2674ms).
[14:33:05.829] INFO: Test took 3915ms.
[14:33:05.860] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:33:06.591] INFO: Expecting 41600 events.
[14:33:09.791] INFO: 41600 events read in total (2673ms).
[14:33:09.792] INFO: Test took 3915ms.
[14:33:09.823] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:33:10.555] INFO: Expecting 41600 events.
[14:33:13.746] INFO: 41600 events read in total (2664ms).
[14:33:13.747] INFO: Test took 3908ms.
[14:33:13.777] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:33:14.505] INFO: Expecting 41600 events.
[14:33:17.707] INFO: 41600 events read in total (2675ms).
[14:33:17.708] INFO: Test took 3914ms.
[14:33:17.739] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:33:18.466] INFO: Expecting 41600 events.
[14:33:21.647] INFO: 41600 events read in total (2654ms).
[14:33:21.648] INFO: Test took 3891ms.
[14:33:21.678] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:33:22.412] INFO: Expecting 41600 events.
[14:33:25.456] INFO: 41600 events read in total (2517ms).
[14:33:25.457] INFO: Test took 3761ms.
[14:33:25.486] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:33:25.858] INFO: enter test to run
[14:34:26.709] INFO: test: HighRate no parameter change
[14:34:26.709] INFO: running: highrate
[14:34:26.710] INFO: ----------------------------------------------------------------------
[14:34:26.710] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:34:26.710] INFO: ----------------------------------------------------------------------
[14:34:27.321] INFO: Expecting 208000 events.
[14:34:38.978] INFO: 208000 events read in total (11130ms).
[14:34:38.981] INFO: Test took 12262ms.
[14:34:39.108] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:34:39.355] INFO: number of dead pixels (per ROC): 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:34:39.355] INFO: number of red-efficiency pixels: 64 39 58 87 115 108 88 82 65 125 96 87 103 52 20 16
[14:34:39.355] INFO: number of X-ray hits detected: 55292 34307 55422 85018 92736 99733 100389 74015 73167 90078 89126 74845 78433 44931 18258 19776
[14:34:39.355] 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:34:39.355] INFO: number of Vcal hits detected: 207886 207961 207940 207911 207879 207889 207912 207914 207934 207873 207902 207910 207896 207947 207980 207983
[14:34:39.355] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 100.0 99.9 100.0 100.0 100.0 100.0 99.9 100.0 100.0 100.0 100.0 100.0 100.0
[14:34:39.355] INFO: Vcal hit overall efficiency (%): 99.9 100.0 100.0 100.0 99.9 99.9 100.0 100.0 100.0 99.9 100.0 100.0 100.0 100.0 100.0 100.0
[14:34:39.355] INFO: X-ray hit rate [MHz/cm2]: 16.2 10.1 16.2 24.9 27.2 29.2 29.4 21.7 21.4 26.4 26.1 21.9 23.0 13.2 5.4 5.8
[14:34:39.355] INFO: PixTestHighRate::doXPixelAlive() done
[14:34:39.402] INFO: PixTest:: pg_setup set to default.
[14:34:39.414] INFO: enter test to run
[14:38:57.379] INFO: test: HighRate no parameter change
[14:38:57.379] INFO: running: highrate
[14:38:57.381] INFO: ----------------------------------------------------------------------
[14:38:57.381] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:38:57.381] INFO: ----------------------------------------------------------------------
[14:38:58.003] INFO: Expecting 208000 events.
[14:39:11.102] INFO: 208000 events read in total (12572ms).
[14:39:11.107] INFO: Test took 13716ms.
[14:39:11.365] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:39:11.652] INFO: number of dead pixels (per ROC): 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:39:11.652] INFO: number of red-efficiency pixels: 157 85 160 240 343 339 322 274 227 368 252 267 259 144 38 38
[14:39:11.652] INFO: number of X-ray hits detected: 112085 70150 112653 172535 187230 202564 202837 151470 149193 182308 179822 151039 158741 91465 37209 40309
[14:39:11.652] 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:39:11.652] INFO: number of Vcal hits detected: 207786 207914 207822 207741 207642 207643 207658 207709 207765 207606 207725 207720 207730 207848 207962 207962
[14:39:11.652] INFO: Vcal hit fiducial efficiency (%): 99.9 100.0 99.9 99.9 99.8 99.8 99.8 99.9 99.9 99.8 99.9 99.9 99.9 99.9 100.0 100.0
[14:39:11.652] INFO: Vcal hit overall efficiency (%): 99.9 100.0 99.9 99.9 99.8 99.8 99.8 99.9 99.9 99.8 99.9 99.9 99.9 99.9 100.0 100.0
[14:39:11.652] INFO: X-ray hit rate [MHz/cm2]: 32.9 20.6 33.0 50.6 54.9 59.4 59.5 44.4 43.7 53.4 52.7 44.3 46.5 26.8 10.9 11.8
[14:39:11.652] INFO: PixTestHighRate::doXPixelAlive() done
[14:39:11.703] INFO: PixTest:: pg_setup set to default.
[14:39:11.717] INFO: enter test to run
[14:39:38.683] INFO: test: HighRate no parameter change
[14:39:38.683] INFO: running: highrate
[14:39:38.684] INFO: ----------------------------------------------------------------------
[14:39:38.684] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:39:38.684] INFO: ----------------------------------------------------------------------
[14:39:39.305] INFO: Expecting 208000 events.
[14:39:53.973] INFO: 208000 events read in total (14141ms).
[14:39:53.979] INFO: Test took 15283ms.
[14:39:54.354] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:39:54.681] INFO: number of dead pixels (per ROC): 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:39:54.681] INFO: number of red-efficiency pixels: 277 186 344 483 841 687 710 576 392 807 548 541 589 327 59 74
[14:39:54.681] INFO: number of X-ray hits detected: 168904 104642 168835 256613 281096 301591 302434 225471 222775 271403 268230 226397 238570 135699 55891 60355
[14:39:54.682] 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:39:54.682] INFO: number of Vcal hits detected: 207646 207798 207585 207457 207038 207193 207179 207329 207571 207070 207364 207402 207342 207623 207938 207923
[14:39:54.682] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.8 99.8 99.6 99.6 99.6 99.7 99.8 99.6 99.7 99.7 99.7 99.8 100.0 100.0
[14:39:54.682] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.8 99.7 99.5 99.6 99.6 99.7 99.8 99.6 99.7 99.7 99.7 99.8 100.0 100.0
[14:39:54.682] INFO: X-ray hit rate [MHz/cm2]: 49.5 30.7 49.5 75.2 82.4 88.4 88.6 66.1 65.3 79.6 78.6 66.4 69.9 39.8 16.4 17.7
[14:39:54.682] INFO: PixTestHighRate::doXPixelAlive() done
[14:39:54.730] INFO: PixTest:: pg_setup set to default.
[14:39:54.748] INFO: enter test to run
[14:39:58.099] INFO: test: exit no parameter change
[14:39:58.353] QUIET: Connection to board 33 closed.
[14:39:58.354] INFO: pXar: this is the end, my friend