[13:57:50.993] INFO: *** Welcome to pxar ***
[13:57:50.994] INFO: *** Today: 2016/04/12
[13:57:51.036] INFO: *** Version: v1.9.0-796-gef167-dirty
[13:57:51.036] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-L-1-04_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-1-04_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//dacParameters35_C15.dat
[13:57:51.055] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-L-1-04_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-L-1-04_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//tbmParameters_C0b.dat
[13:57:51.055] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-L-1-04_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//defaultMaskFile.dat
[13:57:51.058] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-L-1-04_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-1-04_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C15.dat
[13:57:51.151] INFO: clk: 4
[13:57:51.151] INFO: ctr: 4
[13:57:51.151] INFO: sda: 19
[13:57:51.151] INFO: tin: 9
[13:57:51.151] INFO: level: 15
[13:57:51.151] INFO: triggerdelay: 0
[13:57:51.151] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[13:57:51.151] INFO: Log level: INFO
[13:57:51.170] QUIET: Connection to board DTB_WREKRL opened.
[13:57:51.173] 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:
------------------------------------------------------
[13:57:51.176] INFO: RPC call hashes of host and DTB match: 398089610
[13:57:52.708] INFO: DUT info:
[13:57:52.708] INFO: The DUT currently contains the following objects:
[13:57:52.708] INFO: 2 TBM Cores tbm08c (2 ON)
[13:57:52.708] INFO: TBM Core alpha (0): 7 registers set
[13:57:52.708] INFO: TBM Core beta (1): 7 registers set
[13:57:52.708] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[13:57:52.708] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[13:57:52.708] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[13:57:52.708] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[13:57:52.708] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[13:57:52.708] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[13:57:52.708] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[13:57:52.708] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[13:57:52.708] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[13:57:52.708] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[13:57:52.708] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[13:57:52.708] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[13:57:52.708] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[13:57:52.708] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[13:57:52.708] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[13:57:52.708] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[13:57:52.708] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[13:57:53.112] INFO: enter 'restricted' command line mode
[13:57:53.112] INFO: enter test to run
[13:58:01.424] INFO: test: PixelAlive no parameter change
[13:58:01.424] INFO: running: pixelalive
[13:58:01.433] INFO: ----------------------------------------------------------------------
[13:58:01.433] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[13:58:01.433] INFO: ----------------------------------------------------------------------
[13:58:01.757] INFO: Expecting 41600 events.
[13:58:06.108] INFO: 41600 events read in total (3633ms).
[13:58:06.267] INFO: Test took 4831ms.
[13:58:06.279] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:58:06.540] INFO: PixTestAlive::aliveTest() done
[13:58:06.541] INFO: number of dead pixels (per ROC): 0 2 3 0 0 0 0 0 0 0 0 0 0 0 0 0
[13:58:06.570] INFO: enter test to run
[13:58:41.512] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[13:58:41.512] INFO: running: highrate
[13:58:41.512] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-L-1-04_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-1-04_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[13:58:41.715] INFO: ----------------------------------------------------------------------
[13:58:41.715] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[13:58:41.715] INFO: ----------------------------------------------------------------------
[13:58:41.715] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[13:58:41.715] INFO: edge/corner pixel THR is adjusted
[13:58:41.715] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:58:42.675] INFO: Collecting data for 5 seconds...
[13:58:47.692] INFO: Done with hot pixel readout
[13:58:59.421] INFO: PixTest:: pg_setup set to default.
[13:58:59.422] INFO: 23 hot pixels found in step 0
[13:59:00.412] INFO: Collecting data for 5 seconds...
[13:59:05.429] INFO: Done with hot pixel readout
[13:59:17.041] INFO: PixTest:: pg_setup set to default.
[13:59:17.042] INFO: 22 hot pixels found in step 1
[13:59:18.037] INFO: Collecting data for 5 seconds...
[13:59:23.053] INFO: Done with hot pixel readout
[13:59:34.664] INFO: PixTest:: pg_setup set to default.
[13:59:34.665] INFO: 22 hot pixels found in step 2
[13:59:35.658] INFO: Collecting data for 5 seconds...
[13:59:40.674] INFO: Done with hot pixel readout
[13:59:52.521] INFO: PixTest:: pg_setup set to default.
[13:59:52.522] INFO: 24 hot pixels found in step 3
[13:59:53.515] INFO: Collecting data for 5 seconds...
[13:59:58.532] INFO: Done with hot pixel readout
[14:00:10.168] INFO: PixTest:: pg_setup set to default.

[14:00:10.169] INFO: 23 hot pixels found in step 4
[14:00:11.161] INFO: Collecting data for 5 seconds...
[14:00:16.178] INFO: Done with hot pixel readout
[14:00:27.425] INFO: PixTest:: pg_setup set to default.

[14:00:27.427] INFO: 19 hot pixels found in step 5
[14:00:28.421] INFO: Collecting data for 5 seconds...
[14:00:33.438] INFO: Done with hot pixel readout
[14:00:45.014] INFO: PixTest:: pg_setup set to default.


[14:00:45.015] INFO: 20 hot pixels found in step 6
[14:00:46.008] INFO: Collecting data for 5 seconds...
[14:00:51.024] INFO: Done with hot pixel readout
[14:01:02.719] INFO: PixTest:: pg_setup set to default.


[14:01:02.720] INFO: 18 hot pixels found in step 7
[14:01:03.713] INFO: Collecting data for 5 seconds...
[14:01:08.729] INFO: Done with hot pixel readout
[14:01:20.367] INFO: PixTest:: pg_setup set to default.


[14:01:20.368] INFO: 7 hot pixels found in step 8
[14:01:21.361] INFO: Collecting data for 5 seconds...
[14:01:26.378] INFO: Done with hot pixel readout
[14:01:38.128] INFO: PixTest:: pg_setup set to default.




[14:01:38.129] INFO: 5 hot pixels found in step 9
[14:01:39.122] INFO: Collecting data for 5 seconds...
[14:01:44.139] INFO: Done with hot pixel readout
[14:01:55.882] INFO: PixTest:: pg_setup set to default.


[14:01:55.883] INFO: 5 hot pixels found in step 10
[14:01:56.876] INFO: Collecting data for 5 seconds...
[14:02:01.893] INFO: Done with hot pixel readout
[14:02:13.661] INFO: PixTest:: pg_setup set to default.



[14:02:13.662] INFO: 5 hot pixels found in step 11
[14:02:14.655] INFO: Collecting data for 5 seconds...
[14:02:19.672] INFO: Done with hot pixel readout
[14:02:31.402] INFO: PixTest:: pg_setup set to default.



[14:02:31.403] INFO: 5 hot pixels found in step 12
[14:02:32.396] INFO: Collecting data for 5 seconds...
[14:02:37.413] INFO: Done with hot pixel readout
[14:02:47.828] INFO: PixTest:: pg_setup set to default.


[14:02:47.829] INFO: 5 hot pixels found in step 13
[14:02:48.823] INFO: Collecting data for 5 seconds...
[14:02:53.834] INFO: Done with hot pixel readout
[14:03:03.072] INFO: PixTest:: pg_setup set to default.



[14:03:03.073] INFO: 4 hot pixels found in step 14
[14:03:03.110] INFO: 4 hot pixels could not be trimmed and have been masked.
[14:03:03.113] INFO: PixTest::trimHotPixels() done
[14:03:03.113] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-04_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C0.dat
[14:03:03.120] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-04_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C1.dat
[14:03:03.126] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-04_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C2.dat
[14:03:03.131] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-04_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C3.dat
[14:03:03.137] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-04_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C4.dat
[14:03:03.142] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-04_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C5.dat
[14:03:03.147] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-04_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C6.dat
[14:03:03.152] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-04_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C7.dat
[14:03:03.157] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-04_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C8.dat
[14:03:03.163] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-04_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C9.dat
[14:03:03.168] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-04_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C10.dat
[14:03:03.173] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-04_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C11.dat
[14:03:03.178] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-04_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C12.dat
[14:03:03.184] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-04_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C13.dat
[14:03:03.189] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-04_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C14.dat
[14:03:03.194] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-04_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C15.dat
[14:03:03.199] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-L-1-04_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//defaultMaskFile.dat
[14:03:03.213] INFO: enter test to run
[14:03:28.182] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[14:03:28.182] INFO: running: highrate
[14:03:28.186] INFO: ----------------------------------------------------------------------
[14:03:28.186] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[14:03:28.186] INFO: ----------------------------------------------------------------------
[14:03:28.186] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[14:03:28.187] INFO: edge/corner pixel THR is adjusted
[14:03:28.187] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:03:29.144] INFO: Collecting data for 1 seconds...
[14:03:30.148] INFO: Done with hot pixel readout
[14:03:34.202] INFO: PixTest:: pg_setup set to default.
[14:03:34.203] INFO: 0 hot pixels found in step 0
[14:03:34.208] INFO: 0 hot pixels could not be trimmed and have been masked.
[14:03:34.298] INFO: PixTest::trimHotPixels() done
[14:03:34.298] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-04_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C0.dat
[14:03:34.310] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-04_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C1.dat
[14:03:34.317] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-04_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C2.dat
[14:03:34.323] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-04_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C3.dat
[14:03:34.328] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-04_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C4.dat
[14:03:34.333] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-04_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C5.dat
[14:03:34.338] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-04_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C6.dat
[14:03:34.343] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-04_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C7.dat
[14:03:34.348] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-04_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C8.dat
[14:03:34.353] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-04_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C9.dat
[14:03:34.359] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-04_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C10.dat
[14:03:34.364] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-04_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C11.dat
[14:03:34.369] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-04_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C12.dat
[14:03:34.374] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-04_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C13.dat
[14:03:34.379] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-04_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C14.dat
[14:03:34.384] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-1-04_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C15.dat
[14:03:34.389] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-L-1-04_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//defaultMaskFile.dat
[14:03:34.402] INFO: enter test to run
[14:04:17.725] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[14:04:17.725] INFO: running: xray
[14:04:17.727] INFO: ----------------------------------------------------------------------
[14:04:17.727] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:04:17.727] INFO: ----------------------------------------------------------------------
[14:04:18.689] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:04:30.179] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[14:04:59.437] INFO: Resuming triggers.
[14:05:10.933] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[14:05:40.337] INFO: Resuming triggers.
[14:05:51.830] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[14:06:21.213] INFO: Resuming triggers.
[14:06:32.706] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[14:07:02.036] INFO: Resuming triggers.
[14:07:13.528] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[14:07:42.881] INFO: Resuming triggers.
[14:07:54.372] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[14:08:23.691] INFO: Resuming triggers.
[14:08:35.177] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[14:09:04.579] INFO: Resuming triggers.
[14:09:16.068] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[14:09:45.434] INFO: Resuming triggers.
[14:09:53.830] INFO: data taking finished, elapsed time: 100 seconds.
[14:10:15.445] INFO: PixTest:: pg_setup set to default.
[14:10:15.449] INFO: PixTestXray::doPhRun() done
[14:10:15.585] INFO: enter test to run
[14:10:49.122] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[14:10:49.122] INFO: running: xray
[14:10:49.123] INFO: ----------------------------------------------------------------------
[14:10:49.124] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:10:49.124] INFO: ----------------------------------------------------------------------
[14:10:50.091] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:10:56.649] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[14:11:26.731] INFO: Resuming triggers.
[14:11:33.294] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[14:12:03.365] INFO: Resuming triggers.
[14:12:09.928] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[14:12:39.687] INFO: Resuming triggers.
[14:12:46.250] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[14:13:12.735] INFO: Resuming triggers.
[14:13:19.299] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[14:13:49.304] INFO: Resuming triggers.
[14:13:55.869] INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[14:14:25.969] INFO: Resuming triggers.
[14:14:32.535] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[14:15:02.620] INFO: Resuming triggers.
[14:15:09.187] INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[14:15:39.300] INFO: Resuming triggers.
[14:15:45.861] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[14:16:15.901] INFO: Resuming triggers.
[14:16:22.462] INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[14:16:52.561] INFO: Resuming triggers.
[14:16:59.121] INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[14:17:29.256] INFO: Resuming triggers.
[14:17:35.816] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[14:18:05.893] INFO: Resuming triggers.
[14:18:12.452] INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[14:18:42.479] INFO: Resuming triggers.
[14:18:49.036] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[14:19:19.124] INFO: Resuming triggers.
[14:19:25.680] INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[14:19:55.747] INFO: Resuming triggers.
[14:19:57.648] INFO: data taking finished, elapsed time: 100 seconds.
[14:20:06.663] INFO: PixTest:: pg_setup set to default.
[14:20:06.667] INFO: PixTestXray::doPhRun() done
[14:20:06.815] INFO: enter test to run
[14:20:44.662] INFO: test: HighRate no parameter change
[14:20:44.662] INFO: running: highrate
[14:20:44.663] INFO: ----------------------------------------------------------------------
[14:20:44.663] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[14:20:44.663] INFO: ----------------------------------------------------------------------
[14:20:44.806] INFO: Expecting 768 events.
[14:20:45.943] INFO: 768 events read in total (418ms).
[14:20:45.944] INFO: Test took 1273ms.
[14:20:46.747] INFO: Expecting 41600 events.
[14:20:49.823] INFO: 41600 events read in total (2549ms).
[14:20:49.824] INFO: Test took 3873ms.
[14:20:49.858] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:20:50.583] INFO: Expecting 41600 events.
[14:20:53.774] INFO: 41600 events read in total (2665ms).
[14:20:53.775] INFO: Test took 3900ms.
[14:20:53.808] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:20:54.534] INFO: Expecting 41600 events.
[14:20:57.761] INFO: 41600 events read in total (2701ms).
[14:20:57.762] INFO: Test took 3936ms.
[14:20:57.796] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:20:58.522] INFO: Expecting 41600 events.
[14:21:01.746] INFO: 41600 events read in total (2697ms).
[14:21:01.747] INFO: Test took 3932ms.
[14:21:01.781] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:21:02.506] INFO: Expecting 41600 events.
[14:21:05.738] INFO: 41600 events read in total (2705ms).
[14:21:05.739] INFO: Test took 3940ms.
[14:21:05.772] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:21:06.494] INFO: Expecting 41600 events.
[14:21:09.736] INFO: 41600 events read in total (2715ms).
[14:21:09.737] INFO: Test took 3947ms.
[14:21:09.771] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:21:10.494] INFO: Expecting 41600 events.
[14:21:13.722] INFO: 41600 events read in total (2701ms).
[14:21:13.723] INFO: Test took 3934ms.
[14:21:13.757] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:21:14.483] INFO: Expecting 41600 events.
[14:21:17.717] INFO: 41600 events read in total (2707ms).
[14:21:17.718] INFO: Test took 3943ms.
[14:21:17.752] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:21:18.477] INFO: Expecting 41600 events.
[14:21:21.711] INFO: 41600 events read in total (2707ms).
[14:21:21.712] INFO: Test took 3941ms.
[14:21:21.746] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:21:22.470] INFO: Expecting 41600 events.
[14:21:25.707] INFO: 41600 events read in total (2711ms).
[14:21:25.708] INFO: Test took 3943ms.
[14:21:25.741] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:21:26.465] INFO: Expecting 41600 events.
[14:21:29.701] INFO: 41600 events read in total (2709ms).
[14:21:29.702] INFO: Test took 3942ms.
[14:21:29.735] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:21:30.458] INFO: Expecting 41600 events.
[14:21:33.700] INFO: 41600 events read in total (2715ms).
[14:21:33.701] INFO: Test took 3948ms.
[14:21:33.734] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:21:34.459] INFO: Expecting 41600 events.
[14:21:37.695] INFO: 41600 events read in total (2709ms).
[14:21:37.696] INFO: Test took 3943ms.
[14:21:37.730] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:21:38.452] INFO: Expecting 41600 events.
[14:21:41.691] INFO: 41600 events read in total (2712ms).
[14:21:41.692] INFO: Test took 3943ms.
[14:21:41.725] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:21:42.450] INFO: Expecting 41600 events.
[14:21:45.698] INFO: 41600 events read in total (2722ms).
[14:21:45.699] INFO: Test took 3955ms.
[14:21:45.733] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:21:46.456] INFO: Expecting 41600 events.
[14:21:49.706] INFO: 41600 events read in total (2723ms).
[14:21:49.707] INFO: Test took 3955ms.
[14:21:49.740] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:21:50.463] INFO: Expecting 41600 events.
[14:21:53.701] INFO: 41600 events read in total (2711ms).
[14:21:53.702] INFO: Test took 3943ms.
[14:21:53.735] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:21:54.457] INFO: Expecting 41600 events.
[14:21:57.697] INFO: 41600 events read in total (2714ms).
[14:21:57.698] INFO: Test took 3944ms.
[14:21:57.732] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:21:58.454] INFO: Expecting 41600 events.
[14:22:01.693] INFO: 41600 events read in total (2712ms).
[14:22:01.694] INFO: Test took 3943ms.
[14:22:01.728] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:22:02.449] INFO: Expecting 41600 events.
[14:22:05.579] INFO: 41600 events read in total (2603ms).
[14:22:05.580] INFO: Test took 3834ms.
[14:22:05.613] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:22:05.970] INFO: enter test to run
[14:22:21.165] INFO: test: HighRate no parameter change
[14:22:21.165] INFO: running: highrate
[14:22:21.166] INFO: ----------------------------------------------------------------------
[14:22:21.167] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:22:21.167] INFO: ----------------------------------------------------------------------
[14:22:21.787] INFO: Expecting 208000 events.
[14:22:33.592] INFO: 208000 events read in total (11278ms).
[14:22:33.595] INFO: Test took 12419ms.
[14:22:33.739] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:22:33.991] INFO: number of dead pixels (per ROC): 0 2 3 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:22:33.991] INFO: number of red-efficiency pixels: 94 43 76 129 118 145 109 90 94 97 83 91 93 63 31 20
[14:22:33.991] INFO: number of X-ray hits detected: 67551 41851 64203 107909 114929 113292 113621 79131 77041 92716 89860 80734 85672 51511 22696 26395
[14:22:33.991] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:22:33.991] INFO: number of Vcal hits detected: 207904 207859 207775 207868 207877 207852 207889 207909 207905 207902 207915 207909 207907 207934 207968 207980
[14:22:33.991] 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 100.0 100.0 100.0 100.0 100.0 100.0
[14:22:33.991] INFO: Vcal hit overall efficiency (%): 100.0 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0
[14:22:33.991] INFO: X-ray hit rate [MHz/cm2]: 19.8 12.3 18.8 31.6 33.7 33.2 33.3 23.2 22.6 27.2 26.3 23.7 25.1 15.1 6.7 7.7
[14:22:33.991] INFO: PixTestHighRate::doXPixelAlive() done
[14:22:34.044] INFO: PixTest:: pg_setup set to default.
[14:22:34.055] INFO: enter test to run
[14:22:50.077] INFO: test: HighRate no parameter change
[14:22:50.077] INFO: running: highrate
[14:22:50.078] INFO: ----------------------------------------------------------------------
[14:22:50.078] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:22:50.078] INFO: ----------------------------------------------------------------------
[14:22:50.691] INFO: Expecting 208000 events.
[14:23:03.118] INFO: 208000 events read in total (11900ms).
[14:23:03.124] INFO: Test took 13036ms.
[14:23:03.443] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:03.748] INFO: number of dead pixels (per ROC): 0 2 3 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:23:03.748] INFO: number of red-efficiency pixels: 279 144 267 359 413 561 418 264 256 310 265 281 306 203 79 65
[14:23:03.748] INFO: number of X-ray hits detected: 147705 90693 139354 234993 246020 244215 244214 172502 167091 199639 195143 173961 186207 110985 49578 56979
[14:23:03.748] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:23:03.748] INFO: number of Vcal hits detected: 207694 207755 207564 207617 207561 207387 207547 207724 207733 207672 207723 207709 207674 207785 207916 207934
[14:23:03.748] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.7 99.8 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0
[14:23:03.748] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.8 99.8 99.7 99.8 99.9 99.9 99.8 99.9 99.9 99.8 99.9 100.0 100.0
[14:23:03.748] INFO: X-ray hit rate [MHz/cm2]: 43.3 26.6 40.8 68.9 72.1 71.6 71.6 50.6 49.0 58.5 57.2 51.0 54.6 32.5 14.5 16.7
[14:23:03.748] INFO: PixTestHighRate::doXPixelAlive() done
[14:23:03.793] INFO: PixTest:: pg_setup set to default.
[14:23:03.802] INFO: enter test to run
[14:23:20.829] INFO: test: HighRate no parameter change
[14:23:20.829] INFO: running: highrate
[14:23:20.830] INFO: ----------------------------------------------------------------------
[14:23:20.830] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:23:20.830] INFO: ----------------------------------------------------------------------
[14:23:21.447] INFO: Expecting 208000 events.
[14:23:37.124] INFO: 208000 events read in total (15150ms).
[14:23:37.132] INFO: Test took 16292ms.
[14:23:37.595] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:37.948] INFO: number of dead pixels (per ROC): 0 2 3 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:23:37.948] INFO: number of red-efficiency pixels: 624 260 653 956 962 1228 974 553 571 705 586 706 638 464 126 103
[14:23:37.948] INFO: number of X-ray hits detected: 223405 138758 210635 355071 375421 371002 373208 261407 254644 303244 294811 265113 282783 169104 75597 86433
[14:23:37.948] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:23:37.948] INFO: number of Vcal hits detected: 207180 207616 207021 206865 206856 206432 206799 207383 207364 207209 207333 207188 207277 207450 207866 207893
[14:23:37.948] INFO: Vcal hit fiducial efficiency (%): 99.7 99.9 99.6 99.5 99.5 99.3 99.5 99.7 99.7 99.7 99.7 99.6 99.7 99.8 99.9 99.9
[14:23:37.948] INFO: Vcal hit overall efficiency (%): 99.6 99.8 99.5 99.5 99.5 99.2 99.4 99.7 99.7 99.6 99.7 99.6 99.7 99.7 99.9 99.9
[14:23:37.948] INFO: X-ray hit rate [MHz/cm2]: 65.5 40.7 61.7 104.1 110.0 108.7 109.4 76.6 74.6 88.9 86.4 77.7 82.9 49.6 22.2 25.3
[14:23:37.948] INFO: PixTestHighRate::doXPixelAlive() done
[14:23:37.998] INFO: PixTest:: pg_setup set to default.
[14:23:38.014] INFO: enter test to run
[14:23:40.973] INFO: test: exit no parameter change
[14:23:41.248] QUIET: Connection to board 33 closed.
[14:23:41.249] INFO: pXar: this is the end, my friend