[15:09:41.511] INFO: *** Welcome to pxar ***
[15:09:41.511] INFO: *** Today: 2016/04/15
[15:09:41.531] INFO: *** Version: v1.9.0-796-gef167-dirty
[15:09:41.531] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-K-2-11_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-K-2-11_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//dacParameters35_C15.dat
[15:09:41.534] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-K-2-11_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-K-2-11_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//tbmParameters_C0b.dat
[15:09:41.535] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-K-2-11_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//defaultMaskFile.dat
[15:09:41.535] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-K-2-11_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-K-2-11_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C15.dat
[15:09:41.614] INFO: clk: 4
[15:09:41.614] INFO: ctr: 4
[15:09:41.615] INFO: sda: 19
[15:09:41.615] INFO: tin: 9
[15:09:41.615] INFO: level: 15
[15:09:41.615] INFO: triggerdelay: 0
[15:09:41.615] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[15:09:41.615] INFO: Log level: INFO
[15:09:41.633] QUIET: Connection to board DTB_WREKRL opened.
[15:09:41.636] 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:09:41.639] INFO: RPC call hashes of host and DTB match: 398089610
[15:09:43.168] INFO: DUT info:
[15:09:43.168] INFO: The DUT currently contains the following objects:
[15:09:43.168] INFO: 2 TBM Cores tbm08c (2 ON)
[15:09:43.168] INFO: TBM Core alpha (0): 7 registers set
[15:09:43.168] INFO: TBM Core beta (1): 7 registers set
[15:09:43.168] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[15:09:43.169] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[15:09:43.169] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[15:09:43.169] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[15:09:43.169] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[15:09:43.169] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[15:09:43.169] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[15:09:43.169] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[15:09:43.169] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[15:09:43.169] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[15:09:43.169] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[15:09:43.169] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[15:09:43.169] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[15:09:43.169] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[15:09:43.169] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[15:09:43.169] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[15:09:43.169] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[15:09:43.572] INFO: enter 'restricted' command line mode
[15:09:43.572] INFO: enter test to run
[15:10:25.358] INFO: test: PixelAlive no parameter change
[15:10:25.358] INFO: running: pixelalive
[15:10:25.367] INFO: ----------------------------------------------------------------------
[15:10:25.367] 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:10:25.368] INFO: ----------------------------------------------------------------------
[15:10:25.687] INFO: Expecting 41600 events.
[15:10:30.020] INFO: 41600 events read in total (3615ms).
[15:10:30.190] INFO: Test took 4820ms.
[15:10:30.201] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:10:30.461] INFO: PixTestAlive::aliveTest() done
[15:10:30.461] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 3 0 0 0 0 0 0 0
[15:10:30.494] INFO: enter test to run
[15:11:09.574] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[15:11:09.574] INFO: running: highrate
[15:11:09.574] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-K-2-11_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-K-2-11_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[15:11:09.781] INFO: ----------------------------------------------------------------------
[15:11:09.781] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[15:11:09.781] INFO: ----------------------------------------------------------------------
[15:11:09.781] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[15:11:09.781] INFO: edge/corner pixel THR is adjusted
[15:11:09.781] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:11:10.740] INFO: Collecting data for 5 seconds...
[15:11:15.756] INFO: Done with hot pixel readout
[15:11:27.532] INFO: PixTest:: pg_setup set to default.
[15:11:27.533] INFO: 28 hot pixels found in step 0
[15:11:28.525] INFO: Collecting data for 5 seconds...
[15:11:33.541] INFO: Done with hot pixel readout
[15:11:45.264] INFO: PixTest:: pg_setup set to default.
[15:11:45.265] INFO: 30 hot pixels found in step 1
[15:11:46.258] INFO: Collecting data for 5 seconds...
[15:11:51.274] INFO: Done with hot pixel readout
[15:12:03.035] INFO: PixTest:: pg_setup set to default.
[15:12:03.036] INFO: 25 hot pixels found in step 2
[15:12:04.028] INFO: Collecting data for 5 seconds...
[15:12:09.044] INFO: Done with hot pixel readout
[15:12:20.753] INFO: PixTest:: pg_setup set to default.

[15:12:20.754] INFO: 21 hot pixels found in step 3
[15:12:21.747] INFO: Collecting data for 5 seconds...
[15:12:26.762] INFO: Done with hot pixel readout
[15:12:38.518] INFO: PixTest:: pg_setup set to default.
[15:12:38.519] INFO: 24 hot pixels found in step 4
[15:12:39.511] INFO: Collecting data for 5 seconds...
[15:12:44.527] INFO: Done with hot pixel readout
[15:12:56.248] INFO: PixTest:: pg_setup set to default.

[15:12:56.249] INFO: 19 hot pixels found in step 5
[15:12:57.242] INFO: Collecting data for 5 seconds...
[15:13:02.258] INFO: Done with hot pixel readout
[15:13:13.994] INFO: PixTest:: pg_setup set to default.


[15:13:13.994] INFO: 12 hot pixels found in step 6
[15:13:14.987] INFO: Collecting data for 5 seconds...
[15:13:20.004] INFO: Done with hot pixel readout
[15:13:31.621] INFO: PixTest:: pg_setup set to default.


[15:13:31.622] INFO: 12 hot pixels found in step 7
[15:13:32.614] INFO: Collecting data for 5 seconds...
[15:13:37.630] INFO: Done with hot pixel readout
[15:13:49.398] INFO: PixTest:: pg_setup set to default.



[15:13:49.399] INFO: 13 hot pixels found in step 8
[15:13:50.392] INFO: Collecting data for 5 seconds...
[15:13:55.407] INFO: Done with hot pixel readout
[15:14:07.151] INFO: PixTest:: pg_setup set to default.


[15:14:07.152] INFO: 13 hot pixels found in step 9
[15:14:08.144] INFO: Collecting data for 5 seconds...
[15:14:13.161] INFO: Done with hot pixel readout
[15:14:24.935] INFO: PixTest:: pg_setup set to default.


[15:14:24.936] INFO: 8 hot pixels found in step 10
[15:14:25.930] INFO: Collecting data for 5 seconds...
[15:14:30.946] INFO: Done with hot pixel readout
[15:14:42.712] INFO: PixTest:: pg_setup set to default.



[15:14:42.713] INFO: 12 hot pixels found in step 11
[15:14:43.705] INFO: Collecting data for 5 seconds...
[15:14:48.721] INFO: Done with hot pixel readout
[15:15:00.488] INFO: PixTest:: pg_setup set to default.


[15:15:00.489] INFO: 16 hot pixels found in step 12
[15:15:01.481] INFO: Collecting data for 5 seconds...
[15:15:06.496] INFO: Done with hot pixel readout
[15:15:18.286] INFO: PixTest:: pg_setup set to default.


[15:15:18.287] INFO: 10 hot pixels found in step 13
[15:15:19.279] INFO: Collecting data for 5 seconds...
[15:15:24.295] INFO: Done with hot pixel readout
[15:15:36.088] INFO: PixTest:: pg_setup set to default.


[15:15:36.089] INFO: 10 hot pixels found in step 14
[15:15:36.125] INFO: 10 hot pixels could not be trimmed and have been masked.
[15:15:36.129] INFO: PixTest::trimHotPixels() done
[15:15:36.129] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-11_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C0.dat
[15:15:36.134] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-11_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C1.dat
[15:15:36.140] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-11_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C2.dat
[15:15:36.145] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-11_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C3.dat
[15:15:36.150] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-11_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C4.dat
[15:15:36.156] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-11_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C5.dat
[15:15:36.161] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-11_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C6.dat
[15:15:36.166] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-11_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C7.dat
[15:15:36.171] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-11_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C8.dat
[15:15:36.176] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-11_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C9.dat
[15:15:36.181] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-11_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C10.dat
[15:15:36.187] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-11_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C11.dat
[15:15:36.192] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-11_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C12.dat
[15:15:36.197] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-11_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C13.dat
[15:15:36.202] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-11_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C14.dat
[15:15:36.207] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-11_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C15.dat
[15:15:36.212] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-K-2-11_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//defaultMaskFile.dat
[15:15:36.230] INFO: enter test to run
[15:16:14.140] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[15:16:14.140] INFO: running: highrate
[15:16:14.144] INFO: ----------------------------------------------------------------------
[15:16:14.144] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[15:16:14.144] INFO: ----------------------------------------------------------------------
[15:16:14.144] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[15:16:14.145] INFO: edge/corner pixel THR is adjusted
[15:16:14.145] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:16:15.102] INFO: Collecting data for 1 seconds...
[15:16:16.105] INFO: Done with hot pixel readout
[15:16:20.142] INFO: PixTest:: pg_setup set to default.
[15:16:20.143] INFO: 0 hot pixels found in step 0
[15:16:20.148] INFO: 0 hot pixels could not be trimmed and have been masked.
[15:16:20.239] INFO: PixTest::trimHotPixels() done
[15:16:20.240] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-11_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C0.dat
[15:16:20.249] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-11_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C1.dat
[15:16:20.255] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-11_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C2.dat
[15:16:20.260] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-11_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C3.dat
[15:16:20.265] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-11_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C4.dat
[15:16:20.270] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-11_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C5.dat
[15:16:20.275] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-11_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C6.dat
[15:16:20.280] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-11_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C7.dat
[15:16:20.286] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-11_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C8.dat
[15:16:20.291] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-11_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C9.dat
[15:16:20.296] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-11_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C10.dat
[15:16:20.301] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-11_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C11.dat
[15:16:20.307] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-11_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C12.dat
[15:16:20.312] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-11_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C13.dat
[15:16:20.317] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-11_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C14.dat
[15:16:20.323] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-11_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//trimParameters35_C15.dat
[15:16:20.328] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-K-2-11_FPIXTest-17C-FNAL-160412-1450_2016-04-12_14h50m_1460490629/000_FPIXTest_p17//defaultMaskFile.dat
[15:16:20.338] INFO: enter test to run
[15:16:52.635] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[15:16:52.635] INFO: running: xray
[15:16:52.637] INFO: ----------------------------------------------------------------------
[15:16:52.637] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:16:52.637] INFO: ----------------------------------------------------------------------
[15:16:53.601] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:17:05.123] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[15:17:34.460] INFO: Resuming triggers.
[15:17:45.980] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[15:18:12.280] INFO: Resuming triggers.
[15:18:23.802] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[15:18:53.140] INFO: Resuming triggers.
[15:19:04.665] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[15:19:34.031] INFO: Resuming triggers.
[15:19:45.551] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[15:20:14.870] INFO: Resuming triggers.
[15:20:26.395] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[15:20:55.779] INFO: Resuming triggers.
[15:21:07.299] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[15:21:36.735] INFO: Resuming triggers.
[15:21:48.260] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[15:22:17.657] INFO: Resuming triggers.
[15:22:25.795] INFO: data taking finished, elapsed time: 100 seconds.
[15:22:46.542] INFO: PixTest:: pg_setup set to default.
[15:22:46.546] INFO: PixTestXray::doPhRun() done
[15:22:46.708] INFO: enter test to run
[15:23:26.585] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[15:23:26.585] INFO: running: xray
[15:23:26.586] INFO: ----------------------------------------------------------------------
[15:23:26.586] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:23:26.586] INFO: ----------------------------------------------------------------------
[15:23:27.550] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:23:34.227] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[15:24:04.196] INFO: Resuming triggers.
[15:24:10.877] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[15:24:41.056] INFO: Resuming triggers.
[15:24:47.738] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[15:25:18.002] INFO: Resuming triggers.
[15:25:24.685] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[15:25:54.978] INFO: Resuming triggers.
[15:26:01.659] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[15:26:32.043] INFO: Resuming triggers.
[15:26:38.730] INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[15:27:08.930] INFO: Resuming triggers.
[15:27:15.615] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[15:27:45.741] INFO: Resuming triggers.
[15:27:52.424] INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[15:28:19.789] INFO: Resuming triggers.
[15:28:26.471] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[15:28:56.537] INFO: Resuming triggers.
[15:29:03.219] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[15:29:33.398] INFO: Resuming triggers.
[15:29:40.081] INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[15:30:10.213] INFO: Resuming triggers.
[15:30:16.895] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[15:30:46.946] INFO: Resuming triggers.
[15:30:53.626] INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[15:31:23.798] INFO: Resuming triggers.
[15:31:30.479] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[15:32:00.559] INFO: Resuming triggers.
[15:32:07.240] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[15:32:37.346] INFO: Resuming triggers.
[15:32:37.438] INFO: data taking finished, elapsed time: 100 seconds.
[15:32:38.333] INFO: PixTest:: pg_setup set to default.
[15:32:38.336] INFO: PixTestXray::doPhRun() done
[15:32:38.482] INFO: enter test to run
[15:33:09.428] INFO: test: HighRate no parameter change
[15:33:09.428] INFO: running: highrate
[15:33:09.429] INFO: ----------------------------------------------------------------------
[15:33:09.429] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[15:33:09.429] INFO: ----------------------------------------------------------------------
[15:33:09.571] INFO: Expecting 768 events.
[15:33:10.705] INFO: 768 events read in total (419ms).
[15:33:10.705] INFO: Test took 1269ms.
[15:33:11.508] INFO: Expecting 41600 events.
[15:33:14.579] INFO: 41600 events read in total (2544ms).
[15:33:14.581] INFO: Test took 3868ms.
[15:33:14.613] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:15.340] INFO: Expecting 41600 events.
[15:33:18.492] INFO: 41600 events read in total (2626ms).
[15:33:18.493] INFO: Test took 3863ms.
[15:33:18.526] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:19.252] INFO: Expecting 41600 events.
[15:33:22.482] INFO: 41600 events read in total (2703ms).
[15:33:22.482] INFO: Test took 3938ms.
[15:33:22.515] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:23.244] INFO: Expecting 41600 events.
[15:33:26.465] INFO: 41600 events read in total (2695ms).
[15:33:26.466] INFO: Test took 3933ms.
[15:33:26.499] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:27.228] INFO: Expecting 41600 events.
[15:33:30.458] INFO: 41600 events read in total (2704ms).
[15:33:30.459] INFO: Test took 3943ms.
[15:33:30.492] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:31.214] INFO: Expecting 41600 events.
[15:33:34.440] INFO: 41600 events read in total (2699ms).
[15:33:34.441] INFO: Test took 3931ms.
[15:33:34.474] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:35.197] INFO: Expecting 41600 events.
[15:33:38.428] INFO: 41600 events read in total (2704ms).
[15:33:38.429] INFO: Test took 3938ms.
[15:33:38.462] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:39.189] INFO: Expecting 41600 events.
[15:33:42.423] INFO: 41600 events read in total (2707ms).
[15:33:42.424] INFO: Test took 3944ms.
[15:33:42.456] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:43.185] INFO: Expecting 41600 events.
[15:33:46.419] INFO: 41600 events read in total (2708ms).
[15:33:46.420] INFO: Test took 3946ms.
[15:33:46.453] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:47.178] INFO: Expecting 41600 events.
[15:33:50.415] INFO: 41600 events read in total (2710ms).
[15:33:50.416] INFO: Test took 3946ms.
[15:33:50.449] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:51.177] INFO: Expecting 41600 events.
[15:33:54.411] INFO: 41600 events read in total (2707ms).
[15:33:54.412] INFO: Test took 3945ms.
[15:33:54.445] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:55.171] INFO: Expecting 41600 events.
[15:33:58.393] INFO: 41600 events read in total (2695ms).
[15:33:58.394] INFO: Test took 3931ms.
[15:33:58.427] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:59.152] INFO: Expecting 41600 events.
[15:34:02.389] INFO: 41600 events read in total (2710ms).
[15:34:02.390] INFO: Test took 3945ms.
[15:34:02.422] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:34:03.146] INFO: Expecting 41600 events.
[15:34:06.378] INFO: 41600 events read in total (2705ms).
[15:34:06.379] INFO: Test took 3939ms.
[15:34:06.412] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:34:07.140] INFO: Expecting 41600 events.
[15:34:10.370] INFO: 41600 events read in total (2703ms).
[15:34:10.371] INFO: Test took 3942ms.
[15:34:10.403] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:34:11.128] INFO: Expecting 41600 events.
[15:34:14.365] INFO: 41600 events read in total (2710ms).
[15:34:14.366] INFO: Test took 3946ms.
[15:34:14.398] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:34:15.123] INFO: Expecting 41600 events.
[15:34:18.363] INFO: 41600 events read in total (2713ms).
[15:34:18.364] INFO: Test took 3948ms.
[15:34:18.396] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:34:19.122] INFO: Expecting 41600 events.
[15:34:22.335] INFO: 41600 events read in total (2687ms).
[15:34:22.336] INFO: Test took 3921ms.
[15:34:22.368] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:34:23.094] INFO: Expecting 41600 events.
[15:34:26.291] INFO: 41600 events read in total (2670ms).
[15:34:26.292] INFO: Test took 3905ms.
[15:34:26.324] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:34:27.050] INFO: Expecting 41600 events.
[15:34:30.128] INFO: 41600 events read in total (2551ms).
[15:34:30.129] INFO: Test took 3788ms.
[15:34:30.161] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:34:30.521] INFO: enter test to run
[15:34:51.179] INFO: test: HighRate no parameter change
[15:34:51.180] INFO: running: highrate
[15:34:51.181] INFO: ----------------------------------------------------------------------
[15:34:51.181] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:34:51.181] INFO: ----------------------------------------------------------------------
[15:34:51.801] INFO: Expecting 208000 events.
[15:35:03.574] INFO: 208000 events read in total (11246ms).
[15:35:03.577] INFO: Test took 12387ms.
[15:35:03.720] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:35:03.971] INFO: number of dead pixels (per ROC): 0 0 0 1 0 0 0 0 3 0 0 0 0 0 0 0
[15:35:03.971] INFO: number of red-efficiency pixels: 71 51 90 126 130 0 129 102 120 132 115 120 89 61 25 20
[15:35:03.971] INFO: number of X-ray hits detected: 68946 44329 67614 107425 115475 624 120573 82525 85025 106681 107042 93968 93524 53029 22408 25895
[15:35:03.971] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:35:03.971] INFO: number of Vcal hits detected: 207926 207949 207907 207819 207867 208000 207868 207897 207731 207865 207881 207877 207911 207938 207975 207980
[15:35:03.971] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 100.0 99.9 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0 100.0
[15:35:03.971] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 100.0 99.9 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0 100.0
[15:35:03.971] INFO: X-ray hit rate [MHz/cm2]: 20.2 13.0 19.8 31.5 33.8 0.2 35.3 24.2 24.9 31.3 31.4 27.5 27.4 15.5 6.6 7.6
[15:35:03.971] INFO: PixTestHighRate::doXPixelAlive() done
[15:35:04.021] INFO: PixTest:: pg_setup set to default.
[15:35:04.031] INFO: enter test to run
[15:35:27.267] INFO: test: HighRate no parameter change
[15:35:27.267] INFO: running: highrate
[15:35:27.269] INFO: ----------------------------------------------------------------------
[15:35:27.269] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:35:27.269] INFO: ----------------------------------------------------------------------
[15:35:27.886] INFO: Expecting 208000 events.
[15:35:41.443] INFO: 208000 events read in total (13030ms).
[15:35:41.448] INFO: Test took 14169ms.
[15:35:41.734] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:35:42.033] INFO: number of dead pixels (per ROC): 0 0 0 1 0 0 0 0 3 0 0 0 0 0 0 0
[15:35:42.033] INFO: number of red-efficiency pixels: 226 105 311 418 448 0 468 405 424 463 479 418 310 161 60 73
[15:35:42.033] INFO: number of X-ray hits detected: 146757 95369 145755 231256 246215 1346 257921 177223 183395 227631 229179 200196 199547 113295 47616 55557
[15:35:42.033] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:35:42.033] INFO: number of Vcal hits detected: 207756 207891 207653 207506 207512 208000 207496 207541 207379 207471 207471 207539 207673 207833 207939 207925
[15:35:42.033] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.8 100.0 99.8 99.8 99.8 99.8 99.8 99.8 99.9 99.9 100.0 100.0
[15:35:42.033] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.8 99.8 100.0 99.8 99.8 99.7 99.7 99.7 99.8 99.8 99.9 100.0 100.0
[15:35:42.033] INFO: X-ray hit rate [MHz/cm2]: 43.0 28.0 42.7 67.8 72.2 0.4 75.6 51.9 53.8 66.7 67.2 58.7 58.5 33.2 14.0 16.3
[15:35:42.033] INFO: PixTestHighRate::doXPixelAlive() done
[15:35:42.082] INFO: PixTest:: pg_setup set to default.
[15:35:42.095] INFO: enter test to run
[15:36:03.723] INFO: test: HighRate no parameter change
[15:36:03.723] INFO: running: highrate
[15:36:03.724] INFO: ----------------------------------------------------------------------
[15:36:03.724] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:36:03.724] INFO: ----------------------------------------------------------------------
[15:36:04.344] INFO: Expecting 208000 events.
[15:36:19.859] INFO: 208000 events read in total (14988ms).
[15:36:19.866] INFO: Test took 16133ms.
[15:36:20.299] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:36:20.646] INFO: number of dead pixels (per ROC): 0 0 0 1 0 0 0 0 3 0 0 0 0 0 0 0
[15:36:20.646] INFO: number of red-efficiency pixels: 472 308 725 994 1076 2 1109 909 895 1251 1064 989 741 380 102 128
[15:36:20.646] INFO: number of X-ray hits detected: 224176 144671 220513 350465 376618 2009 391646 269132 278179 345854 346910 304202 303170 172479 72909 84849
[15:36:20.646] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:36:20.646] INFO: number of Vcal hits detected: 207430 207661 207004 206754 206555 207998 206520 206733 206650 206343 206665 206780 207132 207569 207895 207870
[15:36:20.646] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.6 99.5 99.4 100.0 99.4 99.5 99.5 99.3 99.4 99.5 99.6 99.8 100.0 99.9
[15:36:20.646] INFO: Vcal hit overall efficiency (%): 99.7 99.8 99.5 99.4 99.3 100.0 99.3 99.4 99.4 99.2 99.4 99.4 99.6 99.8 99.9 99.9
[15:36:20.646] INFO: X-ray hit rate [MHz/cm2]: 65.7 42.4 64.6 102.7 110.4 0.6 114.8 78.9 81.5 101.4 101.7 89.2 88.9 50.6 21.4 24.9
[15:36:20.646] INFO: PixTestHighRate::doXPixelAlive() done
[15:36:20.695] INFO: PixTest:: pg_setup set to default.
[15:36:20.710] INFO: enter test to run
[15:36:23.483] INFO: test: exit no parameter change
[15:36:23.861] QUIET: Connection to board 33 closed.
[15:36:23.863] INFO: pXar: this is the end, my friend