[15:55:51.249] INFO: *** Welcome to pxar ***
[15:55:51.249] INFO: *** Today: 2016/04/20
[15:55:51.266] INFO: *** Version: v1.9.0-796-gef167-dirty
[15:55:51.266] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-L-1-43_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-1-43_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//dacParameters35_C15.dat
[15:55:51.270] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-L-1-43_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-L-1-43_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//tbmParameters_C0b.dat
[15:55:51.270] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-L-1-43_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//defaultMaskFile.dat
[15:55:51.270] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-L-1-43_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-1-43_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C15.dat
[15:55:51.391] INFO: clk: 4
[15:55:51.391] INFO: ctr: 4
[15:55:51.391] INFO: sda: 19
[15:55:51.391] INFO: tin: 9
[15:55:51.391] INFO: level: 15
[15:55:51.391] INFO: triggerdelay: 0
[15:55:51.391] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[15:55:51.391] INFO: Log level: INFO
[15:55:51.410] QUIET: Connection to board DTB_WREKRL opened.
[15:55:51.413] 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:
------------------------------------------------------
[15:55:51.416] INFO: RPC call hashes of host and DTB match: 398089610
[15:55:52.947] INFO: DUT info:
[15:55:52.947] INFO: The DUT currently contains the following objects:
[15:55:52.947] INFO: 2 TBM Cores tbm08c (2 ON)
[15:55:52.947] INFO: TBM Core alpha (0): 7 registers set
[15:55:52.947] INFO: TBM Core beta (1): 7 registers set
[15:55:52.948] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[15:55:52.948] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[15:55:52.948] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[15:55:52.948] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[15:55:52.948] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[15:55:52.948] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[15:55:52.948] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[15:55:52.948] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[15:55:52.948] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[15:55:52.948] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[15:55:52.948] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[15:55:52.948] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[15:55:52.948] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[15:55:52.948] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[15:55:52.948] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[15:55:52.948] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[15:55:52.948] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[15:55:53.352] INFO: enter 'restricted' command line mode
[15:55:53.352] INFO: enter test to run
[15:56:03.959] INFO: test: PixelAlive no parameter change
[15:56:03.959] INFO: running: pixelalive
[15:56:03.968] INFO: ----------------------------------------------------------------------
[15:56:03.968] 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:56:03.968] INFO: ----------------------------------------------------------------------
[15:56:04.284] INFO: Expecting 41600 events.
[15:56:08.622] INFO: 41600 events read in total (3620ms).
[15:56:08.790] INFO: Test took 4819ms.
[15:56:08.803] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:56:09.064] INFO: PixTestAlive::aliveTest() done
[15:56:09.064] INFO: number of dead pixels (per ROC): 0 0 9 9 1 0 0 0 3 0 0 2 1 0 0 0
[15:56:09.099] INFO: enter test to run
[15:58:16.910] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[15:58:16.910] INFO: running: highrate
[15:58:16.910] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-L-1-43_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-1-43_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[15:58:17.115] INFO: ----------------------------------------------------------------------
[15:58:17.115] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[15:58:17.115] INFO: ----------------------------------------------------------------------
[15:58:17.115] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[15:58:17.115] INFO: edge/corner pixel THR is adjusted
[15:58:17.115] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:58:18.074] INFO: Collecting data for 5 seconds...
[15:58:23.091] INFO: Done with hot pixel readout
[15:58:34.778] INFO: PixTest:: pg_setup set to default.
[15:58:34.779] INFO: 12 hot pixels found in step 0
[15:58:35.768] INFO: Collecting data for 5 seconds...
[15:58:40.785] INFO: Done with hot pixel readout
[15:58:52.318] INFO: PixTest:: pg_setup set to default.
[15:58:52.319] INFO: 12 hot pixels found in step 1
[15:58:53.313] INFO: Collecting data for 5 seconds...
[15:58:58.330] INFO: Done with hot pixel readout
[15:59:09.864] INFO: PixTest:: pg_setup set to default.
[15:59:09.865] INFO: 9 hot pixels found in step 2
[15:59:10.856] INFO: Collecting data for 5 seconds...
[15:59:15.873] INFO: Done with hot pixel readout
[15:59:27.425] INFO: PixTest:: pg_setup set to default.
[15:59:27.426] INFO: 7 hot pixels found in step 3
[15:59:28.417] INFO: Collecting data for 5 seconds...
[15:59:33.434] INFO: Done with hot pixel readout
[15:59:44.944] INFO: PixTest:: pg_setup set to default.
[15:59:44.945] INFO: 7 hot pixels found in step 4
[15:59:45.937] INFO: Collecting data for 5 seconds...
[15:59:50.953] INFO: Done with hot pixel readout
[16:00:02.430] INFO: PixTest:: pg_setup set to default.

[16:00:02.431] INFO: 3 hot pixels found in step 5
[16:00:03.421] INFO: Collecting data for 5 seconds...
[16:00:08.439] INFO: Done with hot pixel readout
[16:00:19.801] INFO: PixTest:: pg_setup set to default.
[16:00:19.802] INFO: 1 hot pixels found in step 6
[16:00:20.793] INFO: Collecting data for 5 seconds...
[16:00:25.809] INFO: Done with hot pixel readout
[16:00:37.312] INFO: PixTest:: pg_setup set to default.
[16:00:37.313] INFO: 1 hot pixels found in step 7
[16:00:38.303] INFO: Collecting data for 5 seconds...
[16:00:43.320] INFO: Done with hot pixel readout
[16:00:54.773] INFO: PixTest:: pg_setup set to default.
[16:00:54.774] INFO: 1 hot pixels found in step 8
[16:00:55.766] INFO: Collecting data for 5 seconds...
[16:01:00.782] INFO: Done with hot pixel readout
[16:01:12.337] INFO: PixTest:: pg_setup set to default.
[16:01:12.338] INFO: 1 hot pixels found in step 9
[16:01:13.330] INFO: Collecting data for 5 seconds...
[16:01:18.346] INFO: Done with hot pixel readout
[16:01:29.845] INFO: PixTest:: pg_setup set to default.
[16:01:29.846] INFO: 3 hot pixels found in step 10
[16:01:30.835] INFO: Collecting data for 5 seconds...
[16:01:35.852] INFO: Done with hot pixel readout
[16:01:46.869] INFO: PixTest:: pg_setup set to default.
[16:01:46.870] INFO: 1 hot pixels found in step 11
[16:01:47.860] INFO: Collecting data for 5 seconds...
[16:01:52.870] INFO: Done with hot pixel readout
[16:02:01.576] INFO: PixTest:: pg_setup set to default.
[16:02:01.577] INFO: 1 hot pixels found in step 12
[16:02:02.568] INFO: Collecting data for 5 seconds...
[16:02:07.585] INFO: Done with hot pixel readout
[16:02:19.081] INFO: PixTest:: pg_setup set to default.
[16:02:19.082] INFO: 0 hot pixels found in step 13
[16:02:19.116] INFO: 0 hot pixels could not be trimmed and have been masked.
[16:02:19.120] INFO: PixTest::trimHotPixels() done
[16:02:19.120] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-43_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C0.dat
[16:02:19.126] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-43_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C1.dat
[16:02:19.132] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-43_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C2.dat
[16:02:19.138] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-43_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C3.dat
[16:02:19.143] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-43_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C4.dat
[16:02:19.148] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-43_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C5.dat
[16:02:19.154] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-43_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C6.dat
[16:02:19.159] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-43_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C7.dat
[16:02:19.164] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-43_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C8.dat
[16:02:19.169] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-43_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C9.dat
[16:02:19.175] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-43_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C10.dat
[16:02:19.180] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-43_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C11.dat
[16:02:19.185] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-43_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C12.dat
[16:02:19.191] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-43_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C13.dat
[16:02:19.196] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-43_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C14.dat
[16:02:19.201] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-43_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C15.dat
[16:02:19.206] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-L-1-43_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//defaultMaskFile.dat
[16:02:19.216] INFO: enter test to run
[16:02:44.004] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[16:02:44.004] INFO: running: highrate
[16:02:44.008] INFO: ----------------------------------------------------------------------
[16:02:44.008] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[16:02:44.008] INFO: ----------------------------------------------------------------------
[16:02:44.008] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[16:02:44.008] INFO: edge/corner pixel THR is adjusted
[16:02:44.008] INFO: PixTestHighRate::trimHotPixels: step 0...
[16:02:44.966] INFO: Collecting data for 1 seconds...
[16:02:45.970] INFO: Done with hot pixel readout
[16:02:49.886] INFO: PixTest:: pg_setup set to default.
[16:02:49.886] INFO: 0 hot pixels found in step 0
[16:02:49.892] INFO: 0 hot pixels could not be trimmed and have been masked.
[16:02:49.988] INFO: PixTest::trimHotPixels() done
[16:02:49.988] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-43_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C0.dat
[16:02:49.000] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-43_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C1.dat
[16:02:50.011] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-43_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C2.dat
[16:02:50.016] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-43_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C3.dat
[16:02:50.021] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-43_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C4.dat
[16:02:50.026] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-43_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C5.dat
[16:02:50.032] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-43_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C6.dat
[16:02:50.037] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-43_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C7.dat
[16:02:50.042] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-43_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C8.dat
[16:02:50.047] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-43_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C9.dat
[16:02:50.053] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-43_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C10.dat
[16:02:50.058] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-43_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C11.dat
[16:02:50.063] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-43_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C12.dat
[16:02:50.069] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-43_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C13.dat
[16:02:50.074] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-43_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C14.dat
[16:02:50.079] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-43_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//trimParameters35_C15.dat
[16:02:50.084] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-L-1-43_FPIXTest-17C-FNAL-160415-1126_2016-04-15_11h26m_1460737597/000_FPIXTest_p17//defaultMaskFile.dat
[16:02:50.094] INFO: enter test to run
[16:04:41.635] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[16:04:41.635] INFO: running: xray
[16:04:41.636] INFO: ----------------------------------------------------------------------
[16:04:41.636] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[16:04:41.636] INFO: ----------------------------------------------------------------------
[16:04:42.599] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[16:04:54.455] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[16:05:23.643] INFO: Resuming triggers.
[16:05:35.503] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[16:06:04.747] INFO: Resuming triggers.
[16:06:16.605] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[16:06:45.822] INFO: Resuming triggers.
[16:06:57.677] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[16:07:26.812] INFO: Resuming triggers.
[16:07:38.675] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[16:08:07.969] INFO: Resuming triggers.
[16:08:19.829] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[16:08:49.037] INFO: Resuming triggers.
[16:09:00.897] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[16:09:30.116] INFO: Resuming triggers.
[16:09:41.975] INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[16:10:11.111] INFO: Resuming triggers.
[16:10:16.573] INFO: data taking finished, elapsed time: 100 seconds.
[16:10:30.268] INFO: PixTest:: pg_setup set to default.
[16:10:30.271] INFO: PixTestXray::doPhRun() done
[16:10:30.403] INFO: enter test to run
[16:11:06.352] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[16:11:06.352] INFO: running: xray
[16:11:06.353] INFO: ----------------------------------------------------------------------
[16:11:06.353] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[16:11:06.353] INFO: ----------------------------------------------------------------------
[16:11:07.318] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[16:11:14.294] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[16:11:44.308] INFO: Resuming triggers.
[16:11:51.289] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[16:12:16.149] INFO: Resuming triggers.
[16:12:23.125] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[16:12:53.051] INFO: Resuming triggers.
[16:13:00.030] INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[16:13:30.031] INFO: Resuming triggers.
[16:13:37.015] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[16:14:07.058] INFO: Resuming triggers.
[16:14:14.040] INFO: run duration 41 seconds, buffer almost full (81%), pausing triggers.
[16:14:44.113] INFO: Resuming triggers.
[16:14:51.098] INFO: run duration 48 seconds, buffer almost full (81%), pausing triggers.
[16:15:21.154] INFO: Resuming triggers.
[16:15:28.138] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[16:15:58.120] INFO: Resuming triggers.
[16:16:05.105] INFO: run duration 62 seconds, buffer almost full (81%), pausing triggers.
[16:16:35.151] INFO: Resuming triggers.
[16:16:42.138] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[16:17:12.242] INFO: Resuming triggers.
[16:17:19.225] INFO: run duration 76 seconds, buffer almost full (81%), pausing triggers.
[16:17:49.285] INFO: Resuming triggers.
[16:17:56.270] INFO: run duration 83 seconds, buffer almost full (81%), pausing triggers.
[16:18:26.358] INFO: Resuming triggers.
[16:18:33.344] INFO: run duration 90 seconds, buffer almost full (81%), pausing triggers.
[16:19:03.373] INFO: Resuming triggers.
[16:19:10.362] INFO: run duration 97 seconds, buffer almost full (81%), pausing triggers.
[16:19:40.342] INFO: Resuming triggers.
[16:19:42.910] INFO: data taking finished, elapsed time: 100 seconds.
[16:19:54.179] INFO: PixTest:: pg_setup set to default.
[16:19:54.182] INFO: PixTestXray::doPhRun() done
[16:19:54.331] INFO: enter test to run
[16:20:30.404] INFO: test: HighRate no parameter change
[16:20:30.404] INFO: running: highrate
[16:20:30.405] INFO: ----------------------------------------------------------------------
[16:20:30.405] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[16:20:30.405] INFO: ----------------------------------------------------------------------
[16:20:30.547] INFO: Expecting 768 events.
[16:20:31.681] INFO: 768 events read in total (419ms).
[16:20:31.681] INFO: Test took 1268ms.
[16:20:32.484] INFO: Expecting 41600 events.
[16:20:35.555] INFO: 41600 events read in total (2544ms).
[16:20:35.556] INFO: Test took 3867ms.
[16:20:35.586] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:20:36.322] INFO: Expecting 41600 events.
[16:20:39.493] INFO: 41600 events read in total (2645ms).
[16:20:39.494] INFO: Test took 3891ms.
[16:20:39.525] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:20:40.255] INFO: Expecting 41600 events.
[16:20:43.462] INFO: 41600 events read in total (2680ms).
[16:20:43.463] INFO: Test took 3921ms.
[16:20:43.493] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:20:44.223] INFO: Expecting 41600 events.
[16:20:47.410] INFO: 41600 events read in total (2660ms).
[16:20:47.411] INFO: Test took 3902ms.
[16:20:47.442] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:20:48.171] INFO: Expecting 41600 events.
[16:20:51.364] INFO: 41600 events read in total (2666ms).
[16:20:51.365] INFO: Test took 3907ms.
[16:20:51.395] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:20:52.128] INFO: Expecting 41600 events.
[16:20:55.321] INFO: 41600 events read in total (2666ms).
[16:20:55.322] INFO: Test took 3911ms.
[16:20:55.352] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:20:56.085] INFO: Expecting 41600 events.
[16:20:59.280] INFO: 41600 events read in total (2668ms).
[16:20:59.281] INFO: Test took 3913ms.
[16:20:59.311] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:21:00.042] INFO: Expecting 41600 events.
[16:21:03.242] INFO: 41600 events read in total (2673ms).
[16:21:03.244] INFO: Test took 3915ms.
[16:21:03.275] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:21:03.004] INFO: Expecting 41600 events.
[16:21:07.200] INFO: 41600 events read in total (2669ms).
[16:21:07.201] INFO: Test took 3908ms.
[16:21:07.230] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:21:07.962] INFO: Expecting 41600 events.
[16:21:11.162] INFO: 41600 events read in total (2673ms).
[16:21:11.163] INFO: Test took 3915ms.
[16:21:11.193] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:21:11.927] INFO: Expecting 41600 events.
[16:21:15.133] INFO: 41600 events read in total (2679ms).
[16:21:15.134] INFO: Test took 3924ms.
[16:21:15.165] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:21:15.896] INFO: Expecting 41600 events.
[16:21:19.094] INFO: 41600 events read in total (2671ms).
[16:21:19.094] INFO: Test took 3912ms.
[16:21:19.124] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:21:19.858] INFO: Expecting 41600 events.
[16:21:23.063] INFO: 41600 events read in total (2678ms).
[16:21:23.064] INFO: Test took 3923ms.
[16:21:23.094] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:21:23.825] INFO: Expecting 41600 events.
[16:21:27.026] INFO: 41600 events read in total (2675ms).
[16:21:27.027] INFO: Test took 3915ms.
[16:21:27.057] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:21:27.789] INFO: Expecting 41600 events.
[16:21:30.985] INFO: 41600 events read in total (2669ms).
[16:21:30.986] INFO: Test took 3911ms.
[16:21:31.016] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:21:31.748] INFO: Expecting 41600 events.
[16:21:34.945] INFO: 41600 events read in total (2670ms).
[16:21:34.946] INFO: Test took 3914ms.
[16:21:34.976] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:21:35.707] INFO: Expecting 41600 events.
[16:21:38.893] INFO: 41600 events read in total (2659ms).
[16:21:38.894] INFO: Test took 3902ms.
[16:21:38.924] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:21:39.657] INFO: Expecting 41600 events.
[16:21:42.864] INFO: 41600 events read in total (2680ms).
[16:21:42.865] INFO: Test took 3924ms.
[16:21:42.894] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:21:43.626] INFO: Expecting 41600 events.
[16:21:46.802] INFO: 41600 events read in total (2650ms).
[16:21:46.803] INFO: Test took 3892ms.
[16:21:46.833] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:21:47.567] INFO: Expecting 41600 events.
[16:21:50.612] INFO: 41600 events read in total (2518ms).
[16:21:50.612] INFO: Test took 3762ms.
[16:21:50.642] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:21:51.014] INFO: enter test to run
[16:22:06.099] INFO: test: HighRate no parameter change
[16:22:06.099] INFO: running: highrate
[16:22:06.100] INFO: ----------------------------------------------------------------------
[16:22:06.100] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:22:06.100] INFO: ----------------------------------------------------------------------
[16:22:06.707] INFO: Expecting 208000 events.
[16:22:16.856] INFO: 208000 events read in total (9622ms).
[16:22:16.858] INFO: Test took 10751ms.
[16:22:16.983] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:22:17.228] INFO: number of dead pixels (per ROC): 0 0 8 8 2 0 0 0 3 0 0 2 1 0 0 0
[16:22:17.228] INFO: number of red-efficiency pixels: 70 22 83 110 150 101 117 73 65 123 95 74 106 42 28 12
[16:22:17.228] INFO: number of X-ray hits detected: 52530 34955 52803 83997 97895 100202 101701 70917 63852 87172 84037 73269 80580 47329 19490 17776
[16:22:17.228] 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:22:17.228] INFO: number of Vcal hits detected: 207930 207978 207434 207347 207750 207896 207883 207926 207788 207874 207894 207828 207844 207957 207972 207988
[16:22:17.228] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 99.9 99.9 99.9 100.0 99.9 100.0 100.0 99.9 100.0 100.0 99.9 100.0 100.0 100.0
[16:22:17.228] INFO: Vcal hit overall efficiency (%): 100.0 100.0 99.7 99.7 99.9 100.0 99.9 100.0 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[16:22:17.228] INFO: X-ray hit rate [MHz/cm2]: 15.4 10.2 15.5 24.6 28.7 29.4 29.8 20.8 18.7 25.6 24.6 21.5 23.6 13.9 5.7 5.2
[16:22:17.228] INFO: PixTestHighRate::doXPixelAlive() done
[16:22:17.279] INFO: PixTest:: pg_setup set to default.
[16:22:17.295] INFO: enter test to run
[16:22:40.075] INFO: test: HighRate no parameter change
[16:22:40.075] INFO: running: highrate
[16:22:40.076] INFO: ----------------------------------------------------------------------
[16:22:40.076] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:22:40.076] INFO: ----------------------------------------------------------------------
[16:22:40.693] INFO: Expecting 208000 events.
[16:22:53.972] INFO: 208000 events read in total (12752ms).
[16:22:53.977] INFO: Test took 13892ms.
[16:22:54.247] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:22:54.539] INFO: number of dead pixels (per ROC): 0 0 7 9 2 0 0 0 3 0 0 2 1 0 0 0
[16:22:54.539] INFO: number of red-efficiency pixels: 183 100 242 394 451 465 475 322 185 334 282 273 257 185 70 43
[16:22:54.539] INFO: number of X-ray hits detected: 116249 77876 116741 185884 215547 221611 226053 156471 141482 192343 185814 163388 177597 104652 43609 39853
[16:22:54.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
[16:22:54.539] INFO: number of Vcal hits detected: 207807 207897 207264 207029 207414 207488 207485 207663 207662 207651 207691 207614 207683 207800 207929 207957
[16:22:54.539] INFO: Vcal hit fiducial efficiency (%): 99.9 100.0 99.8 99.8 99.8 99.8 99.8 99.8 99.9 99.8 99.9 99.9 99.9 99.9 100.0 100.0
[16:22:54.539] INFO: Vcal hit overall efficiency (%): 99.9 100.0 99.6 99.5 99.7 99.8 99.8 99.8 99.8 99.8 99.9 99.8 99.8 99.9 100.0 100.0
[16:22:54.539] INFO: X-ray hit rate [MHz/cm2]: 34.1 22.8 34.2 54.5 63.2 65.0 66.3 45.9 41.5 56.4 54.5 47.9 52.1 30.7 12.8 11.7
[16:22:54.539] INFO: PixTestHighRate::doXPixelAlive() done
[16:22:54.586] INFO: PixTest:: pg_setup set to default.
[16:22:54.599] INFO: enter test to run
[16:23:12.723] INFO: test: HighRate no parameter change
[16:23:12.723] INFO: running: highrate
[16:23:12.724] INFO: ----------------------------------------------------------------------
[16:23:12.724] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:23:12.724] INFO: ----------------------------------------------------------------------
[16:23:13.341] INFO: Expecting 208000 events.
[16:23:28.457] INFO: 208000 events read in total (14590ms).
[16:23:28.464] INFO: Test took 15731ms.
[16:23:28.874] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:23:29.213] INFO: number of dead pixels (per ROC): 0 0 8 7 2 0 0 0 3 0 0 2 1 0 0 0
[16:23:29.213] INFO: number of red-efficiency pixels: 387 226 561 890 1162 1125 1242 711 361 857 664 600 608 413 103 69
[16:23:29.213] INFO: number of X-ray hits detected: 179935 120805 180058 287690 333861 342394 347659 243083 220559 298393 288573 252980 276282 163126 67570 61510
[16:23:29.213] 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:23:29.213] INFO: number of Vcal hits detected: 207572 207761 206827 206388 206488 206537 206426 207124 207460 207008 207224 207230 207286 207531 207890 207930
[16:23:29.213] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.7 99.4 99.4 99.4 99.3 99.6 99.8 99.6 99.7 99.7 99.7 99.8 100.0 100.0
[16:23:29.213] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.4 99.2 99.3 99.3 99.2 99.6 99.7 99.5 99.6 99.6 99.7 99.8 99.9 100.0
[16:23:29.213] INFO: X-ray hit rate [MHz/cm2]: 52.7 35.4 52.8 84.3 97.9 100.4 101.9 71.2 64.6 87.5 84.6 74.2 81.0 47.8 19.8 18.0
[16:23:29.213] INFO: PixTestHighRate::doXPixelAlive() done
[16:23:29.260] INFO: PixTest:: pg_setup set to default.
[16:23:29.277] INFO: enter test to run
[16:24:17.026] INFO: test: exit no parameter change
[16:24:17.405] QUIET: Connection to board 33 closed.
[16:24:17.406] INFO: pXar: this is the end, my friend