[09:53:09.318] INFO: *** Welcome to pxar ***
[09:53:09.318] INFO: *** Today: 2016/04/18
[09:53:09.337] INFO: *** Version: v1.9.0-796-gef167-dirty
[09:53:09.337] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-M-4-03_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-M-4-03_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//dacParameters35_C15.dat
[09:53:09.381] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-M-4-03_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-M-4-03_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//tbmParameters_C0b.dat
[09:53:09.381] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-M-4-03_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//defaultMaskFile.dat
[09:53:09.382] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-M-4-03_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-M-4-03_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C15.dat
[09:53:09.507] INFO: clk: 4
[09:53:09.507] INFO: ctr: 4
[09:53:09.507] INFO: sda: 19
[09:53:09.507] INFO: tin: 9
[09:53:09.507] INFO: level: 15
[09:53:09.507] INFO: triggerdelay: 0
[09:53:09.507] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[09:53:09.507] INFO: Log level: INFO
[09:53:09.526] QUIET: Connection to board DTB_WREKRL opened.
[09:53:09.530] 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:
------------------------------------------------------
[09:53:09.533] INFO: RPC call hashes of host and DTB match: 398089610
[09:53:11.061] INFO: DUT info:
[09:53:11.061] INFO: The DUT currently contains the following objects:
[09:53:11.061] INFO: 2 TBM Cores tbm08c (2 ON)
[09:53:11.061] INFO: TBM Core alpha (0): 7 registers set
[09:53:11.061] INFO: TBM Core beta (1): 7 registers set
[09:53:11.061] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[09:53:11.061] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[09:53:11.061] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[09:53:11.061] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[09:53:11.061] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[09:53:11.061] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[09:53:11.062] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[09:53:11.062] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[09:53:11.062] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[09:53:11.062] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[09:53:11.062] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[09:53:11.062] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[09:53:11.062] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[09:53:11.062] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[09:53:11.062] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[09:53:11.062] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[09:53:11.062] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[09:53:11.465] INFO: enter 'restricted' command line mode
[09:53:11.465] INFO: enter test to run
[09:53:16.511] INFO: test: PixelAlive no parameter change
[09:53:16.511] INFO: running: pixelalive
[09:53:16.521] INFO: ----------------------------------------------------------------------
[09:53:16.521] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[09:53:16.521] INFO: ----------------------------------------------------------------------
[09:53:16.844] INFO: Expecting 41600 events.
[09:53:21.162] INFO: 41600 events read in total (3600ms).
[09:53:21.329] INFO: Test took 4806ms.
[09:53:21.343] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:53:21.603] INFO: PixTestAlive::aliveTest() done
[09:53:21.603] INFO: number of dead pixels (per ROC): 0 0 4 0 0 0 0 0 0 0 1 0 0 1 0 0
[09:53:21.638] INFO: enter test to run
[09:53:51.431] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200\<-
[09:53:51.431] INFO: running: highrate
[09:53:51.431] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-M-4-03_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-M-4-03_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[09:53:51.643] INFO: ----------------------------------------------------------------------
[09:53:51.643] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[09:53:51.643] INFO: ----------------------------------------------------------------------
[09:53:51.643] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[09:53:51.643] INFO: edge/corner pixel THR is adjusted
[09:53:51.643] INFO: PixTestHighRate::trimHotPixels: step 0...
[09:53:52.602] INFO: Collecting data for 5 seconds...
[09:53:57.618] INFO: Done with hot pixel readout
[09:54:09.384] INFO: PixTest:: pg_setup set to default.
[09:54:09.385] INFO: 13 hot pixels found in step 0
[09:54:10.378] INFO: Collecting data for 5 seconds...
[09:54:15.395] INFO: Done with hot pixel readout
[09:54:26.860] INFO: PixTest:: pg_setup set to default.
[09:54:26.860] INFO: 11 hot pixels found in step 1
[09:54:27.856] INFO: Collecting data for 5 seconds...
[09:54:32.873] INFO: Done with hot pixel readout
[09:54:44.515] INFO: PixTest:: pg_setup set to default.
[09:54:44.516] INFO: 11 hot pixels found in step 2
[09:54:45.508] INFO: Collecting data for 5 seconds...
[09:54:50.526] INFO: Done with hot pixel readout
[09:55:02.194] INFO: PixTest:: pg_setup set to default.
[09:55:02.195] INFO: 8 hot pixels found in step 3
[09:55:03.188] INFO: Collecting data for 5 seconds...
[09:55:08.205] INFO: Done with hot pixel readout
[09:55:19.858] INFO: PixTest:: pg_setup set to default.
[09:55:19.859] INFO: 9 hot pixels found in step 4
[09:55:20.851] INFO: Collecting data for 5 seconds...
[09:55:25.864] INFO: Done with hot pixel readout
[09:55:36.717] INFO: PixTest:: pg_setup set to default.
[09:55:36.718] INFO: 9 hot pixels found in step 5
[09:55:37.710] INFO: Collecting data for 5 seconds...
[09:55:42.727] INFO: Done with hot pixel readout
[09:55:54.418] INFO: PixTest:: pg_setup set to default.


[09:55:54.419] INFO: 10 hot pixels found in step 6
[09:55:55.411] INFO: Collecting data for 5 seconds...
[09:56:00.429] INFO: Done with hot pixel readout
[09:56:12.225] INFO: PixTest:: pg_setup set to default.


[09:56:12.226] INFO: 10 hot pixels found in step 7
[09:56:13.217] INFO: Collecting data for 5 seconds...
[09:56:18.234] INFO: Done with hot pixel readout
[09:56:29.934] INFO: PixTest:: pg_setup set to default.


[09:56:29.935] INFO: 6 hot pixels found in step 8
[09:56:30.927] INFO: Collecting data for 5 seconds...
[09:56:35.945] INFO: Done with hot pixel readout
[09:56:47.639] INFO: PixTest:: pg_setup set to default.


[09:56:47.641] INFO: 5 hot pixels found in step 9
[09:56:48.633] INFO: Collecting data for 5 seconds...
[09:56:53.650] INFO: Done with hot pixel readout
[09:57:05.260] INFO: PixTest:: pg_setup set to default.


[09:57:05.261] INFO: 4 hot pixels found in step 10
[09:57:06.253] INFO: Collecting data for 5 seconds...
[09:57:11.270] INFO: Done with hot pixel readout
[09:57:22.571] INFO: PixTest:: pg_setup set to default.


[09:57:22.572] INFO: 2 hot pixels found in step 11
[09:57:22.608] INFO: 2 hot pixels could not be trimmed and have been masked.
[09:57:22.611] INFO: PixTest::trimHotPixels() done
[09:57:22.611] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-03_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C0.dat
[09:57:22.617] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-03_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C1.dat
[09:57:22.624] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-03_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C2.dat
[09:57:22.629] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-03_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C3.dat
[09:57:22.634] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-03_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C4.dat
[09:57:22.640] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-03_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C5.dat
[09:57:22.645] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-03_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C6.dat
[09:57:22.650] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-03_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C7.dat
[09:57:22.655] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-03_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C8.dat
[09:57:22.661] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-03_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C9.dat
[09:57:22.666] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-03_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C10.dat
[09:57:22.671] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-03_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C11.dat
[09:57:22.676] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-03_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C12.dat
[09:57:22.682] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-03_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C13.dat
[09:57:22.687] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-03_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C14.dat
[09:57:22.692] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-03_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C15.dat
[09:57:22.698] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-M-4-03_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//defaultMaskFile.dat
[09:57:22.708] INFO: enter test to run
[09:58:10.261] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[09:58:10.261] INFO: running: highrate
[09:58:10.266] INFO: ----------------------------------------------------------------------
[09:58:10.266] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[09:58:10.266] INFO: ----------------------------------------------------------------------
[09:58:10.266] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[09:58:10.266] INFO: edge/corner pixel THR is adjusted
[09:58:10.266] INFO: PixTestHighRate::trimHotPixels: step 0...
[09:58:11.224] INFO: Collecting data for 1 seconds...
[09:58:12.227] INFO: Done with hot pixel readout
[09:58:16.178] INFO: PixTest:: pg_setup set to default.
[09:58:16.179] INFO: 0 hot pixels found in step 0
[09:58:16.185] INFO: 0 hot pixels could not be trimmed and have been masked.
[09:58:16.277] INFO: PixTest::trimHotPixels() done
[09:58:16.277] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-03_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C0.dat
[09:58:16.289] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-03_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C1.dat
[09:58:16.295] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-03_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C2.dat
[09:58:16.300] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-03_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C3.dat
[09:58:16.305] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-03_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C4.dat
[09:58:16.310] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-03_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C5.dat
[09:58:16.315] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-03_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C6.dat
[09:58:16.321] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-03_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C7.dat
[09:58:16.326] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-03_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C8.dat
[09:58:16.331] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-03_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C9.dat
[09:58:16.336] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-03_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C10.dat
[09:58:16.341] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-03_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C11.dat
[09:58:16.346] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-03_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C12.dat
[09:58:16.351] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-03_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C13.dat
[09:58:16.356] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-03_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C14.dat
[09:58:16.362] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-4-03_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C15.dat
[09:58:16.367] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-M-4-03_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//defaultMaskFile.dat
[09:58:16.377] INFO: enter test to run
[10:02:22.259] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[10:02:22.260] INFO: running: xray
[10:02:22.261] INFO: ----------------------------------------------------------------------
[10:02:22.261] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[10:02:22.261] INFO: ----------------------------------------------------------------------
[10:02:23.225] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[10:02:34.950] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[10:03:04.252] INFO: Resuming triggers.
[10:03:15.974] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[10:03:45.372] INFO: Resuming triggers.
[10:03:57.096] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[10:04:26.284] INFO: Resuming triggers.
[10:04:38.005] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[10:05:07.291] INFO: Resuming triggers.
[10:05:19.010] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[10:05:48.337] INFO: Resuming triggers.
[10:06:00.061] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[10:06:29.293] INFO: Resuming triggers.
[10:06:41.014] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[10:07:10.227] INFO: Resuming triggers.
[10:07:21.948] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[10:07:51.126] INFO: Resuming triggers.
[10:07:57.689] INFO: data taking finished, elapsed time: 100 seconds.
[10:08:14.326] INFO: PixTest:: pg_setup set to default.
[10:08:14.330] INFO: PixTestXray::doPhRun() done
[10:08:14.466] INFO: enter test to run
[10:09:07.768] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[10:09:07.769] INFO: running: xray
[10:09:07.770] INFO: ----------------------------------------------------------------------
[10:09:07.770] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[10:09:07.770] INFO: ----------------------------------------------------------------------
[10:09:08.733] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[10:09:15.426] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[10:09:45.638] INFO: Resuming triggers.
[10:09:52.332] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[10:10:22.384] INFO: Resuming triggers.
[10:10:29.080] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[10:10:59.205] INFO: Resuming triggers.
[10:11:05.901] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[10:11:35.998] INFO: Resuming triggers.
[10:11:42.696] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[10:12:12.825] INFO: Resuming triggers.
[10:12:19.522] INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[10:12:49.653] INFO: Resuming triggers.
[10:12:56.348] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[10:13:26.511] INFO: Resuming triggers.
[10:13:33.207] INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[10:14:03.309] INFO: Resuming triggers.
[10:14:10.005] INFO: run duration 60 seconds, buffer almost full (81%), pausing triggers.
[10:14:40.217] INFO: Resuming triggers.
[10:14:46.913] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[10:15:16.939] INFO: Resuming triggers.
[10:15:23.634] INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[10:15:53.714] INFO: Resuming triggers.
[10:16:00.406] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[10:16:30.467] INFO: Resuming triggers.
[10:16:37.161] INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[10:17:07.218] INFO: Resuming triggers.
[10:17:13.908] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[10:17:44.038] INFO: Resuming triggers.
[10:17:50.653] INFO: data taking finished, elapsed time: 100 seconds.
[10:18:20.610] INFO: PixTest:: pg_setup set to default.
[10:18:20.613] INFO: PixTestXray::doPhRun() done
[10:18:20.761] INFO: enter test to run
[10:18:54.340] INFO: test: HighRate no parameter change
[10:18:54.340] INFO: running: highrate
[10:18:54.341] INFO: ----------------------------------------------------------------------
[10:18:54.341] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[10:18:54.342] INFO: ----------------------------------------------------------------------
[10:18:54.483] INFO: Expecting 768 events.
[10:18:55.615] INFO: 768 events read in total (417ms).
[10:18:55.615] INFO: Test took 1267ms.
[10:18:56.418] INFO: Expecting 41600 events.
[10:18:59.460] INFO: 41600 events read in total (2515ms).
[10:18:59.461] INFO: Test took 3839ms.
[10:18:59.493] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:19:00.226] INFO: Expecting 41600 events.
[10:19:03.383] INFO: 41600 events read in total (2630ms).
[10:19:03.384] INFO: Test took 3875ms.
[10:19:03.417] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:19:04.141] INFO: Expecting 41600 events.
[10:19:07.348] INFO: 41600 events read in total (2680ms).
[10:19:07.349] INFO: Test took 3914ms.
[10:19:07.382] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:19:08.110] INFO: Expecting 41600 events.
[10:19:11.340] INFO: 41600 events read in total (2703ms).
[10:19:11.341] INFO: Test took 3942ms.
[10:19:11.374] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:19:12.097] INFO: Expecting 41600 events.
[10:19:15.313] INFO: 41600 events read in total (2689ms).
[10:19:15.313] INFO: Test took 3922ms.
[10:19:15.347] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:19:16.070] INFO: Expecting 41600 events.
[10:19:19.286] INFO: 41600 events read in total (2689ms).
[10:19:19.286] INFO: Test took 3921ms.
[10:19:19.319] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:19:20.044] INFO: Expecting 41600 events.
[10:19:23.261] INFO: 41600 events read in total (2690ms).
[10:19:23.262] INFO: Test took 3925ms.
[10:19:23.295] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:19:24.023] INFO: Expecting 41600 events.
[10:19:27.253] INFO: 41600 events read in total (2703ms).
[10:19:27.254] INFO: Test took 3942ms.
[10:19:27.287] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:19:28.011] INFO: Expecting 41600 events.
[10:19:31.215] INFO: 41600 events read in total (2677ms).
[10:19:31.216] INFO: Test took 3911ms.
[10:19:31.249] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:19:31.973] INFO: Expecting 41600 events.
[10:19:35.205] INFO: 41600 events read in total (2705ms).
[10:19:35.206] INFO: Test took 3938ms.
[10:19:35.238] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:19:35.966] INFO: Expecting 41600 events.
[10:19:39.138] INFO: 41600 events read in total (2645ms).
[10:19:39.139] INFO: Test took 3883ms.
[10:19:39.172] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:19:39.899] INFO: Expecting 41600 events.
[10:19:43.132] INFO: 41600 events read in total (2706ms).
[10:19:43.133] INFO: Test took 3943ms.
[10:19:43.165] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:19:43.892] INFO: Expecting 41600 events.
[10:19:47.077] INFO: 41600 events read in total (2658ms).
[10:19:47.078] INFO: Test took 3895ms.
[10:19:47.111] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:19:47.834] INFO: Expecting 41600 events.
[10:19:51.075] INFO: 41600 events read in total (2714ms).
[10:19:51.076] INFO: Test took 3946ms.
[10:19:51.110] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:19:51.834] INFO: Expecting 41600 events.
[10:19:55.043] INFO: 41600 events read in total (2682ms).
[10:19:55.044] INFO: Test took 3918ms.
[10:19:55.079] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:19:55.793] INFO: Expecting 41600 events.
[10:19:59.006] INFO: 41600 events read in total (2686ms).
[10:19:59.007] INFO: Test took 3911ms.
[10:19:59.041] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:19:59.767] INFO: Expecting 41600 events.
[10:20:02.993] INFO: 41600 events read in total (2700ms).
[10:20:02.994] INFO: Test took 3935ms.
[10:20:03.026] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:20:03.755] INFO: Expecting 41600 events.
[10:20:06.977] INFO: 41600 events read in total (2695ms).
[10:20:06.978] INFO: Test took 3934ms.
[10:20:07.010] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:20:07.738] INFO: Expecting 41600 events.
[10:20:10.933] INFO: 41600 events read in total (2668ms).
[10:20:10.934] INFO: Test took 3907ms.
[10:20:10.967] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:20:11.694] INFO: Expecting 41600 events.
[10:20:14.758] INFO: 41600 events read in total (2538ms).
[10:20:14.759] INFO: Test took 3774ms.
[10:20:14.791] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:20:15.157] INFO: enter test to run
[10:20:45.323] INFO: test: HighRate no parameter change
[10:20:45.323] INFO: running: highrate
[10:20:45.324] INFO: ----------------------------------------------------------------------
[10:20:45.324] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:20:45.324] INFO: ----------------------------------------------------------------------
[10:20:45.946] INFO: Expecting 208000 events.
[10:20:57.715] INFO: 208000 events read in total (11242ms).
[10:20:57.718] INFO: Test took 12383ms.
[10:20:57.857] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:20:58.107] INFO: number of dead pixels (per ROC): 0 0 4 0 0 0 0 0 0 0 1 0 0 1 0 0
[10:20:58.107] INFO: number of red-efficiency pixels: 70 43 102 157 153 142 141 103 106 106 164 79 105 70 26 44
[10:20:58.107] INFO: number of X-ray hits detected: 61108 41719 65393 105926 107802 108173 107724 78172 74222 87092 91707 78820 82997 49871 21346 25248
[10:20:58.107] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:20:58.107] INFO: number of Vcal hits detected: 207926 207955 207699 207839 207843 207856 207854 207894 207894 207891 207784 207921 207895 207878 207974 207956
[10:20:58.107] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0 99.9 100.0 100.0 100.0 100.0 100.0
[10:20:58.107] 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 100.0 99.9 99.9 100.0 100.0
[10:20:58.107] INFO: X-ray hit rate [MHz/cm2]: 17.9 12.2 19.2 31.0 31.6 31.7 31.6 22.9 21.8 25.5 26.9 23.1 24.3 14.6 6.3 7.4
[10:20:58.107] INFO: PixTestHighRate::doXPixelAlive() done
[10:20:58.153] INFO: PixTest:: pg_setup set to default.
[10:20:58.163] INFO: enter test to run
[10:22:28.987] INFO: test: HighRate no parameter change
[10:22:28.987] INFO: running: highrate
[10:22:28.988] INFO: ----------------------------------------------------------------------
[10:22:28.988] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:22:28.988] INFO: ----------------------------------------------------------------------
[10:22:29.603] INFO: Expecting 208000 events.
[10:22:43.146] INFO: 208000 events read in total (13016ms).
[10:22:43.151] INFO: Test took 14154ms.
[10:22:43.437] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:22:43.737] INFO: number of dead pixels (per ROC): 0 0 4 0 0 0 0 0 0 0 1 0 0 1 0 0
[10:22:43.737] INFO: number of red-efficiency pixels: 203 130 280 544 557 418 464 337 285 354 399 252 324 232 56 89
[10:22:43.737] INFO: number of X-ray hits detected: 130759 90290 140114 225090 229491 231368 230334 167635 158051 187658 195075 168242 176575 106588 45601 54112
[10:22:43.737] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:22:43.737] INFO: number of Vcal hits detected: 207781 207865 207504 207395 207372 207539 207504 207640 207700 207624 207523 207736 207652 207708 207939 207909
[10:22:43.737] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.7 99.7 99.8 99.8 99.8 99.9 99.8 99.8 99.9 99.8 99.9 100.0 100.0
[10:22:43.737] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.7 99.7 99.8 99.8 99.8 99.9 99.8 99.8 99.9 99.8 99.9 100.0 100.0
[10:22:43.737] INFO: X-ray hit rate [MHz/cm2]: 38.3 26.5 41.1 66.0 67.3 67.8 67.5 49.1 46.3 55.0 57.2 49.3 51.8 31.2 13.4 15.9
[10:22:43.737] INFO: PixTestHighRate::doXPixelAlive() done
[10:22:43.787] INFO: PixTest:: pg_setup set to default.
[10:22:43.806] INFO: enter test to run
[10:23:02.907] INFO: test: HighRate no parameter change
[10:23:02.907] INFO: running: highrate
[10:23:02.908] INFO: ----------------------------------------------------------------------
[10:23:02.908] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:23:02.908] INFO: ----------------------------------------------------------------------
[10:23:03.525] INFO: Expecting 208000 events.
[10:23:18.852] INFO: 208000 events read in total (14800ms).
[10:23:18.859] INFO: Test took 15942ms.
[10:23:19.287] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:23:19.630] INFO: number of dead pixels (per ROC): 0 0 4 0 0 0 0 0 0 0 1 0 0 1 0 0
[10:23:19.630] INFO: number of red-efficiency pixels: 407 216 609 1251 1243 865 1039 708 587 832 916 532 772 458 93 119
[10:23:19.630] INFO: number of X-ray hits detected: 195533 134004 209181 338609 341963 345824 345594 251522 237056 280653 292745 252799 265822 160084 68907 81246
[10:23:19.630] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:23:19.630] INFO: number of Vcal hits detected: 207539 207776 207039 206424 206433 206939 206726 207136 207329 207033 206840 207405 207116 207421 207904 207874
[10:23:19.630] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.7 99.3 99.3 99.5 99.4 99.6 99.7 99.6 99.5 99.7 99.6 99.8 100.0 99.9
[10:23:19.630] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.5 99.2 99.2 99.5 99.4 99.6 99.7 99.5 99.4 99.7 99.6 99.7 100.0 99.9
[10:23:19.630] INFO: X-ray hit rate [MHz/cm2]: 57.3 39.3 61.3 99.2 100.2 101.4 101.3 73.7 69.5 82.3 85.8 74.1 77.9 46.9 20.2 23.8
[10:23:19.630] INFO: PixTestHighRate::doXPixelAlive() done
[10:23:19.677] INFO: PixTest:: pg_setup set to default.
[10:23:19.691] INFO: enter test to run
[10:23:53.898] INFO: test: exit no parameter change
[10:23:54.304] QUIET: Connection to board 33 closed.
[10:23:54.305] INFO: pXar: this is the end, my friend