[11:56:45.867] INFO: *** Welcome to pxar ***
[11:56:45.867] INFO: *** Today: 2016/06/08
[11:56:45.933] INFO: *** Version: v1.9.0-814-g7497
[11:56:45.933] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-K-3-23_FPIXTest-17C-FNAL-160603-1303_2016-06-03_13h03m_1464977020/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-K-3-23_FPIXTest-17C-FNAL-160603-1303_2016-06-03_13h03m_1464977020/000_FPIXTest_p17//dacParameters35_C15.dat
[11:56:45.972] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-K-3-23_FPIXTest-17C-FNAL-160603-1303_2016-06-03_13h03m_1464977020/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-K-3-23_FPIXTest-17C-FNAL-160603-1303_2016-06-03_13h03m_1464977020/000_FPIXTest_p17//tbmParameters_C0b.dat
[11:56:45.972] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-K-3-23_FPIXTest-17C-FNAL-160603-1303_2016-06-03_13h03m_1464977020/000_FPIXTest_p17//defaultMaskFile.dat
[11:56:45.974] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-K-3-23_FPIXTest-17C-FNAL-160603-1303_2016-06-03_13h03m_1464977020/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-K-3-23_FPIXTest-17C-FNAL-160603-1303_2016-06-03_13h03m_1464977020/000_FPIXTest_p17//trimParameters35_C15.dat
[11:56:46.058] INFO: clk: 4
[11:56:46.058] INFO: ctr: 4
[11:56:46.058] INFO: sda: 19
[11:56:46.058] INFO: tin: 9
[11:56:46.058] INFO: level: 15
[11:56:46.058] INFO: triggerdelay: 0
[11:56:46.058] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[11:56:46.058] INFO: Log level: INFO
[11:56:46.075] QUIET: Connection to board DTB_WREKRL opened.
[11:56:46.079] 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:
------------------------------------------------------
[11:56:46.082] INFO: RPC call hashes of host and DTB match: 398089610
[11:56:47.612] INFO: DUT info:
[11:56:47.612] INFO: The DUT currently contains the following objects:
[11:56:47.612] INFO: 2 TBM Cores tbm08c (2 ON)
[11:56:47.612] INFO: TBM Core alpha (0): 7 registers set
[11:56:47.612] INFO: TBM Core beta (1): 7 registers set
[11:56:47.612] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[11:56:47.612] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[11:56:47.612] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[11:56:47.612] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[11:56:47.612] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[11:56:47.612] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[11:56:47.612] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[11:56:47.612] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[11:56:47.612] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[11:56:47.612] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[11:56:47.612] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[11:56:47.613] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[11:56:47.613] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[11:56:47.613] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[11:56:47.613] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[11:56:47.613] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[11:56:47.613] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[11:56:48.016] INFO: enter 'restricted' command line mode
[11:56:48.016] INFO: enter test to run
[11:59:50.350] INFO: test: PixelAlive no parameter change
[11:59:50.350] INFO: running: pixelalive
[11:59:50.359] INFO: ----------------------------------------------------------------------
[11:59:50.359] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[11:59:50.360] INFO: ----------------------------------------------------------------------
[11:59:50.677] INFO: Expecting 41600 events.
[11:59:54.993] INFO: 41600 events read in total (3597ms).
[11:59:55.159] INFO: Test took 4796ms.
[11:59:55.173] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:59:55.449] INFO: PixTestAlive::aliveTest() done
[11:59:55.449] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 1 0 0 0 0 1 0 0 0 0
[11:59:55.510] INFO: enter test to run
[12:00:09.774] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[12:00:09.774] INFO: running: highrate
[12:00:09.774] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-K-3-23_FPIXTest-17C-FNAL-160603-1303_2016-06-03_13h03m_1464977020/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-K-3-23_FPIXTest-17C-FNAL-160603-1303_2016-06-03_13h03m_1464977020/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[12:00:09.983] INFO: ----------------------------------------------------------------------
[12:00:09.983] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[12:00:09.983] INFO: ----------------------------------------------------------------------
[12:00:09.983] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[12:00:09.983] INFO: edge/corner pixel THR is adjusted
[12:00:09.983] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:00:10.942] INFO: Collecting data for 5 seconds...
[12:00:15.957] INFO: Done with hot pixel readout
[12:00:27.569] INFO: PixTest:: pg_setup set to default.


[12:00:27.569] INFO: 16 hot pixels found in step 0
[12:00:28.587] INFO: Collecting data for 5 seconds...
[12:00:33.603] INFO: Done with hot pixel readout
[12:00:45.366] INFO: PixTest:: pg_setup set to default.

[12:00:45.366] INFO: 9 hot pixels found in step 1
[12:00:46.360] INFO: Collecting data for 5 seconds...
[12:00:51.376] INFO: Done with hot pixel readout
[12:01:03.484] INFO: PixTest:: pg_setup set to default.
[12:01:03.485] INFO: 14 hot pixels found in step 2
[12:01:04.479] INFO: Collecting data for 5 seconds...
[12:01:09.495] INFO: Done with hot pixel readout
[12:01:21.088] INFO: PixTest:: pg_setup set to default.


[12:01:21.088] INFO: 13 hot pixels found in step 3
[12:01:22.082] INFO: Collecting data for 5 seconds...
[12:01:27.099] INFO: Done with hot pixel readout
[12:01:39.191] INFO: PixTest:: pg_setup set to default.
[12:01:39.192] INFO: 12 hot pixels found in step 4
[12:01:40.186] INFO: Collecting data for 5 seconds...
[12:01:45.202] INFO: Done with hot pixel readout
[12:01:57.502] INFO: PixTest:: pg_setup set to default.
[12:01:57.503] INFO: 17 hot pixels found in step 5
[12:01:58.497] INFO: Collecting data for 5 seconds...
[12:02:03.517] INFO: Done with hot pixel readout
[12:02:15.472] INFO: PixTest:: pg_setup set to default.
[12:02:15.473] INFO: 10 hot pixels found in step 6
[12:02:16.466] INFO: Collecting data for 5 seconds...
[12:02:21.484] INFO: Done with hot pixel readout
[12:02:33.202] INFO: PixTest:: pg_setup set to default.

[12:02:33.203] INFO: 13 hot pixels found in step 7
[12:02:34.197] INFO: Collecting data for 5 seconds...
[12:02:39.214] INFO: Done with hot pixel readout
[12:02:51.022] INFO: PixTest:: pg_setup set to default.

[12:02:51.022] INFO: 12 hot pixels found in step 8
[12:02:52.017] INFO: Collecting data for 5 seconds...
[12:02:57.038] INFO: Done with hot pixel readout
[12:03:09.104] INFO: PixTest:: pg_setup set to default.

[12:03:09.105] INFO: 7 hot pixels found in step 9
[12:03:10.100] INFO: Collecting data for 5 seconds...
[12:03:15.117] INFO: Done with hot pixel readout
[12:03:27.169] INFO: PixTest:: pg_setup set to default.

[12:03:27.170] INFO: 11 hot pixels found in step 10
[12:03:28.166] INFO: Collecting data for 5 seconds...
[12:03:33.183] INFO: Done with hot pixel readout
[12:03:45.427] INFO: PixTest:: pg_setup set to default.

[12:03:45.427] INFO: 11 hot pixels found in step 11
[12:03:46.423] INFO: Collecting data for 5 seconds...
[12:03:51.443] INFO: Done with hot pixel readout
[12:04:03.827] INFO: PixTest:: pg_setup set to default.

[12:04:03.828] INFO: 6 hot pixels found in step 12
[12:04:04.824] INFO: Collecting data for 5 seconds...
[12:04:09.843] INFO: Done with hot pixel readout
[12:04:22.034] INFO: PixTest:: pg_setup set to default.


[12:04:22.035] INFO: 5 hot pixels found in step 13
[12:04:23.030] INFO: Collecting data for 5 seconds...
[12:04:28.050] INFO: Done with hot pixel readout
[12:04:40.174] INFO: PixTest:: pg_setup set to default.
[12:04:40.175] INFO: 9 hot pixels found in step 14
[12:04:40.214] INFO: 9 hot pixels could not be trimmed and have been masked.
[12:04:40.218] INFO: PixTest::trimHotPixels() done
[12:04:40.218] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-23_FPIXTest-17C-FNAL-160603-1303_2016-06-03_13h03m_1464977020/000_FPIXTest_p17//trimParameters35_C0.dat
[12:04:40.224] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-23_FPIXTest-17C-FNAL-160603-1303_2016-06-03_13h03m_1464977020/000_FPIXTest_p17//trimParameters35_C1.dat
[12:04:40.230] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-23_FPIXTest-17C-FNAL-160603-1303_2016-06-03_13h03m_1464977020/000_FPIXTest_p17//trimParameters35_C2.dat
[12:04:40.236] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-23_FPIXTest-17C-FNAL-160603-1303_2016-06-03_13h03m_1464977020/000_FPIXTest_p17//trimParameters35_C3.dat
[12:04:40.241] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-23_FPIXTest-17C-FNAL-160603-1303_2016-06-03_13h03m_1464977020/000_FPIXTest_p17//trimParameters35_C4.dat
[12:04:40.247] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-23_FPIXTest-17C-FNAL-160603-1303_2016-06-03_13h03m_1464977020/000_FPIXTest_p17//trimParameters35_C5.dat
[12:04:40.252] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-23_FPIXTest-17C-FNAL-160603-1303_2016-06-03_13h03m_1464977020/000_FPIXTest_p17//trimParameters35_C6.dat
[12:04:40.257] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-23_FPIXTest-17C-FNAL-160603-1303_2016-06-03_13h03m_1464977020/000_FPIXTest_p17//trimParameters35_C7.dat
[12:04:40.263] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-23_FPIXTest-17C-FNAL-160603-1303_2016-06-03_13h03m_1464977020/000_FPIXTest_p17//trimParameters35_C8.dat
[12:04:40.268] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-23_FPIXTest-17C-FNAL-160603-1303_2016-06-03_13h03m_1464977020/000_FPIXTest_p17//trimParameters35_C9.dat
[12:04:40.273] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-23_FPIXTest-17C-FNAL-160603-1303_2016-06-03_13h03m_1464977020/000_FPIXTest_p17//trimParameters35_C10.dat
[12:04:40.279] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-23_FPIXTest-17C-FNAL-160603-1303_2016-06-03_13h03m_1464977020/000_FPIXTest_p17//trimParameters35_C11.dat
[12:04:40.284] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-23_FPIXTest-17C-FNAL-160603-1303_2016-06-03_13h03m_1464977020/000_FPIXTest_p17//trimParameters35_C12.dat
[12:04:40.289] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-23_FPIXTest-17C-FNAL-160603-1303_2016-06-03_13h03m_1464977020/000_FPIXTest_p17//trimParameters35_C13.dat
[12:04:40.295] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-23_FPIXTest-17C-FNAL-160603-1303_2016-06-03_13h03m_1464977020/000_FPIXTest_p17//trimParameters35_C14.dat
[12:04:40.300] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-23_FPIXTest-17C-FNAL-160603-1303_2016-06-03_13h03m_1464977020/000_FPIXTest_p17//trimParameters35_C15.dat
[12:04:40.305] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-K-3-23_FPIXTest-17C-FNAL-160603-1303_2016-06-03_13h03m_1464977020/000_FPIXTest_p17//defaultMaskFile.dat
[12:04:40.315] INFO: enter test to run
[12:05:44.907] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[12:05:44.908] INFO: running: highrate
[12:05:44.912] INFO: ----------------------------------------------------------------------
[12:05:44.912] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[12:05:44.912] INFO: ----------------------------------------------------------------------
[12:05:44.912] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[12:05:44.912] INFO: edge/corner pixel THR is adjusted
[12:05:44.912] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:05:45.870] INFO: Collecting data for 1 seconds...
[12:05:46.874] INFO: Done with hot pixel readout
[12:05:50.002] INFO: PixTest:: pg_setup set to default.
[12:05:50.003] INFO: 0 hot pixels found in step 0
[12:05:51.008] INFO: 0 hot pixels could not be trimmed and have been masked.
[12:05:51.094] INFO: PixTest::trimHotPixels() done
[12:05:51.094] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-23_FPIXTest-17C-FNAL-160603-1303_2016-06-03_13h03m_1464977020/000_FPIXTest_p17//trimParameters35_C0.dat
[12:05:51.102] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-23_FPIXTest-17C-FNAL-160603-1303_2016-06-03_13h03m_1464977020/000_FPIXTest_p17//trimParameters35_C1.dat
[12:05:51.109] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-23_FPIXTest-17C-FNAL-160603-1303_2016-06-03_13h03m_1464977020/000_FPIXTest_p17//trimParameters35_C2.dat
[12:05:51.114] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-23_FPIXTest-17C-FNAL-160603-1303_2016-06-03_13h03m_1464977020/000_FPIXTest_p17//trimParameters35_C3.dat
[12:05:51.119] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-23_FPIXTest-17C-FNAL-160603-1303_2016-06-03_13h03m_1464977020/000_FPIXTest_p17//trimParameters35_C4.dat
[12:05:51.125] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-23_FPIXTest-17C-FNAL-160603-1303_2016-06-03_13h03m_1464977020/000_FPIXTest_p17//trimParameters35_C5.dat
[12:05:51.130] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-23_FPIXTest-17C-FNAL-160603-1303_2016-06-03_13h03m_1464977020/000_FPIXTest_p17//trimParameters35_C6.dat
[12:05:51.135] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-23_FPIXTest-17C-FNAL-160603-1303_2016-06-03_13h03m_1464977020/000_FPIXTest_p17//trimParameters35_C7.dat
[12:05:51.140] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-23_FPIXTest-17C-FNAL-160603-1303_2016-06-03_13h03m_1464977020/000_FPIXTest_p17//trimParameters35_C8.dat
[12:05:51.145] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-23_FPIXTest-17C-FNAL-160603-1303_2016-06-03_13h03m_1464977020/000_FPIXTest_p17//trimParameters35_C9.dat
[12:05:51.150] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-23_FPIXTest-17C-FNAL-160603-1303_2016-06-03_13h03m_1464977020/000_FPIXTest_p17//trimParameters35_C10.dat
[12:05:51.156] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-23_FPIXTest-17C-FNAL-160603-1303_2016-06-03_13h03m_1464977020/000_FPIXTest_p17//trimParameters35_C11.dat
[12:05:51.161] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-23_FPIXTest-17C-FNAL-160603-1303_2016-06-03_13h03m_1464977020/000_FPIXTest_p17//trimParameters35_C12.dat
[12:05:51.166] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-23_FPIXTest-17C-FNAL-160603-1303_2016-06-03_13h03m_1464977020/000_FPIXTest_p17//trimParameters35_C13.dat
[12:05:51.171] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-23_FPIXTest-17C-FNAL-160603-1303_2016-06-03_13h03m_1464977020/000_FPIXTest_p17//trimParameters35_C14.dat
[12:05:51.176] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-23_FPIXTest-17C-FNAL-160603-1303_2016-06-03_13h03m_1464977020/000_FPIXTest_p17//trimParameters35_C15.dat
[12:05:51.181] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-K-3-23_FPIXTest-17C-FNAL-160603-1303_2016-06-03_13h03m_1464977020/000_FPIXTest_p17//defaultMaskFile.dat
[12:05:51.191] INFO: enter test to run
[12:06:06.571] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[12:06:06.571] INFO: running: xray
[12:06:06.589] INFO: ----------------------------------------------------------------------
[12:06:06.589] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:06:06.589] INFO: ----------------------------------------------------------------------
[12:06:07.553] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:06:18.490] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[12:06:48.066] INFO: Resuming triggers.
[12:06:59.006] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[12:07:28.526] INFO: Resuming triggers.
[12:07:39.463] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[12:08:09.038] INFO: Resuming triggers.
[12:08:19.972] INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[12:08:49.577] INFO: Resuming triggers.
[12:09:00.514] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[12:09:30.104] INFO: Resuming triggers.
[12:09:41.044] INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[12:10:10.622] INFO: Resuming triggers.
[12:10:21.560] INFO: run duration 76 seconds, buffer almost full (81%), pausing triggers.
[12:10:51.070] INFO: Resuming triggers.
[12:11:02.005] INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[12:11:31.434] INFO: Resuming triggers.
[12:11:42.371] INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[12:12:11.886] INFO: Resuming triggers.
[12:12:13.767] INFO: data taking finished, elapsed time: 100 seconds.
[12:12:19.185] INFO: PixTest:: pg_setup set to default.
[12:12:19.189] INFO: PixTestXray::doPhRun() done
[12:12:19.326] INFO: enter test to run
[12:16:41.223] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[12:16:41.223] INFO: running: xray
[12:16:41.224] INFO: ----------------------------------------------------------------------
[12:16:41.224] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:16:41.224] INFO: ----------------------------------------------------------------------
[12:16:42.205] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:16:48.568] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[12:17:19.132] INFO: Resuming triggers.
[12:17:25.496] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[12:17:55.523] INFO: Resuming triggers.
[12:18:01.885] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[12:18:31.922] INFO: Resuming triggers.
[12:18:38.287] INFO: run duration 25 seconds, buffer almost full (81%), pausing triggers.
[12:19:08.333] INFO: Resuming triggers.
[12:19:14.694] INFO: run duration 31 seconds, buffer almost full (81%), pausing triggers.
[12:19:44.112] INFO: Resuming triggers.
[12:19:50.472] INFO: run duration 38 seconds, buffer almost full (81%), pausing triggers.
[12:20:20.487] INFO: Resuming triggers.
[12:20:26.850] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[12:20:56.897] INFO: Resuming triggers.
[12:21:03.255] INFO: run duration 50 seconds, buffer almost full (81%), pausing triggers.
[12:21:33.255] INFO: Resuming triggers.
[12:21:39.612] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[12:22:09.595] INFO: Resuming triggers.
[12:22:15.953] INFO: run duration 63 seconds, buffer almost full (81%), pausing triggers.
[12:22:45.977] INFO: Resuming triggers.
[12:22:52.335] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[12:23:22.356] INFO: Resuming triggers.
[12:23:28.714] INFO: run duration 76 seconds, buffer almost full (81%), pausing triggers.
[12:23:58.663] INFO: Resuming triggers.
[12:24:05.024] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[12:24:35.007] INFO: Resuming triggers.
[12:24:41.368] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[12:25:12.043] INFO: Resuming triggers.
[12:25:18.407] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[12:25:48.004] INFO: Resuming triggers.
[12:25:53.922] INFO: data taking finished, elapsed time: 100 seconds.
[12:26:17.867] INFO: PixTest:: pg_setup set to default.
[12:26:17.871] INFO: PixTestXray::doPhRun() done
[12:26:18.019] INFO: enter test to run
[12:26:47.162] INFO: test: HighRate no parameter change
[12:26:47.162] INFO: running: highrate
[12:26:47.219] INFO: ----------------------------------------------------------------------
[12:26:47.219] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[12:26:47.219] INFO: ----------------------------------------------------------------------
[12:26:47.383] INFO: Expecting 768 events.
[12:26:48.516] INFO: 768 events read in total (418ms).
[12:26:48.517] INFO: Test took 1268ms.
[12:26:49.320] INFO: Expecting 41600 events.
[12:26:52.420] INFO: 41600 events read in total (2573ms).
[12:26:52.421] INFO: Test took 3898ms.
[12:26:52.458] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:26:53.180] INFO: Expecting 41600 events.
[12:26:56.473] INFO: 41600 events read in total (2767ms).
[12:26:56.473] INFO: Test took 3999ms.
[12:26:56.511] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:26:57.221] INFO: Expecting 41600 events.
[12:27:00.491] INFO: 41600 events read in total (2743ms).
[12:27:00.492] INFO: Test took 3963ms.
[12:27:00.531] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:01.248] INFO: Expecting 41600 events.
[12:27:04.532] INFO: 41600 events read in total (2757ms).
[12:27:04.533] INFO: Test took 3983ms.
[12:27:04.571] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:05.286] INFO: Expecting 41600 events.
[12:27:08.619] INFO: 41600 events read in total (2806ms).
[12:27:08.619] INFO: Test took 4030ms.
[12:27:08.660] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:09.367] INFO: Expecting 41600 events.
[12:27:12.775] INFO: 41600 events read in total (2881ms).
[12:27:12.776] INFO: Test took 4095ms.
[12:27:12.824] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:13.511] INFO: Expecting 41600 events.
[12:27:16.834] INFO: 41600 events read in total (2796ms).
[12:27:16.835] INFO: Test took 3984ms.
[12:27:16.872] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:17.590] INFO: Expecting 41600 events.
[12:27:20.954] INFO: 41600 events read in total (2837ms).
[12:27:20.955] INFO: Test took 4064ms.
[12:27:20.992] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:21.711] INFO: Expecting 41600 events.
[12:27:24.974] INFO: 41600 events read in total (2736ms).
[12:27:24.975] INFO: Test took 3964ms.
[12:27:25.012] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:25.732] INFO: Expecting 41600 events.
[12:27:29.068] INFO: 41600 events read in total (2810ms).
[12:27:29.069] INFO: Test took 4039ms.
[12:27:29.106] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:29.817] INFO: Expecting 41600 events.
[12:27:33.167] INFO: 41600 events read in total (2824ms).
[12:27:33.168] INFO: Test took 4044ms.
[12:27:33.205] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:33.923] INFO: Expecting 41600 events.
[12:27:37.222] INFO: 41600 events read in total (2772ms).
[12:27:37.223] INFO: Test took 3999ms.
[12:27:37.261] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:37.973] INFO: Expecting 41600 events.
[12:27:41.263] INFO: 41600 events read in total (2763ms).
[12:27:41.264] INFO: Test took 3985ms.
[12:27:41.302] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:42.016] INFO: Expecting 41600 events.
[12:27:45.365] INFO: 41600 events read in total (2822ms).
[12:27:45.366] INFO: Test took 4046ms.
[12:27:45.404] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:46.111] INFO: Expecting 41600 events.
[12:27:49.431] INFO: 41600 events read in total (2793ms).
[12:27:49.432] INFO: Test took 4010ms.
[12:27:49.469] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:50.179] INFO: Expecting 41600 events.
[12:27:53.449] INFO: 41600 events read in total (2743ms).
[12:27:53.450] INFO: Test took 3962ms.
[12:27:53.487] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:54.207] INFO: Expecting 41600 events.
[12:27:57.570] INFO: 41600 events read in total (2836ms).
[12:27:57.571] INFO: Test took 4064ms.
[12:27:57.608] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:58.320] INFO: Expecting 41600 events.
[12:28:01.585] INFO: 41600 events read in total (2738ms).
[12:28:01.586] INFO: Test took 3960ms.
[12:28:01.624] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:02.342] INFO: Expecting 41600 events.
[12:28:05.650] INFO: 41600 events read in total (2781ms).
[12:28:05.651] INFO: Test took 4008ms.
[12:28:05.688] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:06.408] INFO: Expecting 41600 events.
[12:28:09.581] INFO: 41600 events read in total (2647ms).
[12:28:09.582] INFO: Test took 3875ms.
[12:28:09.619] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:09.969] INFO: enter test to run
[12:28:23.713] INFO: test: HighRate no parameter change
[12:28:23.713] INFO: running: highrate
[12:28:23.715] INFO: ----------------------------------------------------------------------
[12:28:23.715] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:28:23.715] INFO: ----------------------------------------------------------------------
[12:28:24.328] INFO: Expecting 208000 events.
[12:28:36.293] INFO: 208000 events read in total (11438ms).
[12:28:36.296] INFO: Test took 12571ms.
[12:28:36.453] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:36.707] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 1 0 0 0 0 1 0 0 0 0
[12:28:36.707] INFO: number of red-efficiency pixels: 85 62 103 143 152 135 152 121 98 161 167 98 122 76 21 23
[12:28:36.707] INFO: number of X-ray hits detected: 70257 46015 72562 113589 122982 123184 122801 93503 87471 110169 107130 85682 94683 54243 21925 25297
[12:28:36.707] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:28:36.707] INFO: number of Vcal hits detected: 207911 207937 207894 207855 207846 207861 207794 207874 207902 207833 207826 207851 207875 207924 207979 207977
[12:28:36.707] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 100.0 99.9 100.0 100.0 100.0
[12:28:36.707] INFO: Vcal hit overall efficiency (%): 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[12:28:36.707] INFO: X-ray hit rate [MHz/cm2]: 20.6 13.5 21.3 33.3 36.0 36.1 36.0 27.4 25.6 32.3 31.4 25.1 27.8 15.9 6.4 7.4
[12:28:36.707] INFO: PixTestHighRate::doXPixelAlive() done
[12:28:36.762] INFO: PixTest:: pg_setup set to default.
[12:28:36.778] INFO: enter test to run
[12:29:21.545] INFO: test: HighRate no parameter change
[12:29:21.545] INFO: running: highrate
[12:29:21.546] INFO: ----------------------------------------------------------------------
[12:29:21.546] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:29:21.546] INFO: ----------------------------------------------------------------------
[12:29:22.166] INFO: Expecting 208000 events.
[12:29:36.077] INFO: 208000 events read in total (13385ms).
[12:29:36.083] INFO: Test took 14527ms.
[12:29:36.410] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:36.720] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 1 0 0 0 0 1 0 0 0 0
[12:29:36.720] INFO: number of red-efficiency pixels: 281 159 327 426 557 477 504 439 257 597 497 292 299 212 58 70
[12:29:36.720] INFO: number of X-ray hits detected: 145250 95706 149743 237604 256577 255697 255730 194051 183570 229505 222703 179152 196550 111978 45296 53081
[12:29:36.720] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:29:36.720] INFO: number of Vcal hits detected: 207691 207833 207629 207545 207382 207466 207402 207511 207730 207335 207459 207642 207683 207773 207941 207928
[12:29:36.720] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.8 99.8 99.7 99.8 99.8 99.8 99.9 99.7 99.8 99.9 99.9 99.9 100.0 100.0
[12:29:36.720] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.8 99.7 99.7 99.7 99.8 99.9 99.7 99.7 99.8 99.8 99.9 100.0 100.0
[12:29:36.720] INFO: X-ray hit rate [MHz/cm2]: 42.6 28.1 43.9 69.6 75.2 74.9 75.0 56.9 53.8 67.3 65.3 52.5 57.6 32.8 13.3 15.6
[12:29:36.720] INFO: PixTestHighRate::doXPixelAlive() done
[12:29:36.772] INFO: PixTest:: pg_setup set to default.
[12:29:36.783] INFO: enter test to run
[12:29:50.825] INFO: test: HighRate no parameter change
[12:29:50.825] INFO: running: highrate
[12:29:50.826] INFO: ----------------------------------------------------------------------
[12:29:50.826] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:29:50.826] INFO: ----------------------------------------------------------------------
[12:29:51.438] INFO: Expecting 208000 events.
[12:30:07.359] INFO: 208000 events read in total (15394ms).
[12:30:07.367] INFO: Test took 16530ms.
[12:30:07.866] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:30:08.226] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 1 0 0 0 0 1 0 0 0 0
[12:30:08.226] INFO: number of red-efficiency pixels: 570 296 757 974 1356 1083 1142 954 587 1252 1115 614 615 492 103 81
[12:30:08.226] INFO: number of X-ray hits detected: 218372 142325 224659 355920 382235 383586 383760 290009 273616 343250 333565 267750 293889 168067 68617 78938
[12:30:08.226] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:30:08.226] INFO: number of Vcal hits detected: 207264 207681 206958 206817 206188 206667 206489 206729 207347 206360 206570 207246 207294 207380 207897 207916
[12:30:08.226] INFO: Vcal hit fiducial efficiency (%): 99.7 99.9 99.6 99.5 99.2 99.4 99.4 99.5 99.7 99.3 99.4 99.7 99.7 99.7 100.0 100.0
[12:30:08.226] INFO: Vcal hit overall efficiency (%): 99.6 99.8 99.5 99.4 99.1 99.4 99.3 99.4 99.7 99.2 99.3 99.6 99.7 99.7 100.0 100.0
[12:30:08.226] INFO: X-ray hit rate [MHz/cm2]: 64.0 41.7 65.8 104.3 112.0 112.4 112.5 85.0 80.2 100.6 97.8 78.5 86.1 49.3 20.1 23.1
[12:30:08.226] INFO: PixTestHighRate::doXPixelAlive() done
[12:30:08.274] INFO: PixTest:: pg_setup set to default.
[12:30:08.292] INFO: enter test to run
[12:30:22.744] INFO: test: exit no parameter change
[12:30:23.072] QUIET: Connection to board 33 closed.
[12:30:23.074] INFO: pXar: this is the end, my friend