[14:18:50.877] INFO: *** Welcome to pxar ***
[14:18:50.877] INFO: *** Today: 2016/04/27
[14:18:51.236] INFO: *** Version: v1.9.0-796-gef167-dirty
[14:18:51.236] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-L-2-12_FPIXTest-17C-FNAL-160422-0956_2016-04-22_09h56m_1461337018/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-2-12_FPIXTest-17C-FNAL-160422-0956_2016-04-22_09h56m_1461337018/000_FPIXTest_p17//dacParameters35_C15.dat
[14:18:51.270] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-L-2-12_FPIXTest-17C-FNAL-160422-0956_2016-04-22_09h56m_1461337018/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-L-2-12_FPIXTest-17C-FNAL-160422-0956_2016-04-22_09h56m_1461337018/000_FPIXTest_p17//tbmParameters_C0b.dat
[14:18:51.270] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-L-2-12_FPIXTest-17C-FNAL-160422-0956_2016-04-22_09h56m_1461337018/000_FPIXTest_p17//defaultMaskFile.dat
[14:18:51.275] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-L-2-12_FPIXTest-17C-FNAL-160422-0956_2016-04-22_09h56m_1461337018/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-2-12_FPIXTest-17C-FNAL-160422-0956_2016-04-22_09h56m_1461337018/000_FPIXTest_p17//trimParameters35_C15.dat
[14:18:51.386] INFO: clk: 4
[14:18:51.386] INFO: ctr: 4
[14:18:51.386] INFO: sda: 19
[14:18:51.386] INFO: tin: 9
[14:18:51.386] INFO: level: 15
[14:18:51.386] INFO: triggerdelay: 0
[14:18:51.387] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[14:18:51.387] INFO: Log level: INFO
[14:18:51.404] QUIET: Connection to board DTB_WREKRL opened.
[14:18:51.408] 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:
------------------------------------------------------
[14:18:51.411] INFO: RPC call hashes of host and DTB match: 398089610
[14:18:52.948] INFO: DUT info:
[14:18:52.948] INFO: The DUT currently contains the following objects:
[14:18:52.948] INFO: 2 TBM Cores tbm08c (2 ON)
[14:18:52.948] INFO: TBM Core alpha (0): 7 registers set
[14:18:52.948] INFO: TBM Core beta (1): 7 registers set
[14:18:52.948] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[14:18:52.948] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[14:18:52.948] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[14:18:52.948] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[14:18:52.949] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[14:18:52.949] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[14:18:52.949] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[14:18:52.949] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[14:18:52.949] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[14:18:52.949] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[14:18:52.949] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[14:18:52.949] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[14:18:52.949] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[14:18:52.949] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[14:18:52.949] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[14:18:52.949] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[14:18:52.949] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[14:18:53.374] INFO: enter 'restricted' command line mode
[14:18:53.374] INFO: enter test to run
[14:19:00.901] INFO: test: PixelAlive no parameter change
[14:19:00.901] INFO: running: pixelalive
[14:19:00.910] INFO: ----------------------------------------------------------------------
[14:19:00.910] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[14:19:00.910] INFO: ----------------------------------------------------------------------
[14:19:01.233] INFO: Expecting 41600 events.
[14:19:05.572] INFO: 41600 events read in total (3620ms).
[14:19:05.736] INFO: Test took 4823ms.
[14:19:05.746] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:19:06.031] INFO: PixTestAlive::aliveTest() done
[14:19:06.031] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 1 0 0 0 0 0 0 0 0
[14:19:06.070] INFO: enter test to run
[14:19:34.116] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[14:19:34.116] INFO: running: highrate
[14:19:34.117] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-L-2-12_FPIXTest-17C-FNAL-160422-0956_2016-04-22_09h56m_1461337018/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-2-12_FPIXTest-17C-FNAL-160422-0956_2016-04-22_09h56m_1461337018/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[14:19:34.338] INFO: ----------------------------------------------------------------------
[14:19:34.338] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[14:19:34.338] INFO: ----------------------------------------------------------------------
[14:19:34.338] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[14:19:34.338] INFO: edge/corner pixel THR is adjusted
[14:19:34.338] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:19:35.297] INFO: Collecting data for 5 seconds...
[14:19:40.313] INFO: Done with hot pixel readout
[14:19:52.249] INFO: PixTest:: pg_setup set to default.
[14:19:52.250] INFO: 16 hot pixels found in step 0
[14:19:53.263] INFO: Collecting data for 5 seconds...
[14:19:58.280] INFO: Done with hot pixel readout
[14:20:10.184] INFO: PixTest:: pg_setup set to default.
[14:20:10.184] INFO: 16 hot pixels found in step 1
[14:20:11.173] INFO: Collecting data for 5 seconds...
[14:20:16.190] INFO: Done with hot pixel readout
[14:20:28.090] INFO: PixTest:: pg_setup set to default.
[14:20:28.091] INFO: 15 hot pixels found in step 2
[14:20:29.079] INFO: Collecting data for 5 seconds...
[14:20:34.096] INFO: Done with hot pixel readout
[14:20:46.029] INFO: PixTest:: pg_setup set to default.
[14:20:46.030] INFO: 20 hot pixels found in step 3
[14:20:47.020] INFO: Collecting data for 5 seconds...
[14:20:52.036] INFO: Done with hot pixel readout
[14:21:03.961] INFO: PixTest:: pg_setup set to default.

[14:21:03.961] INFO: 15 hot pixels found in step 4
[14:21:04.952] INFO: Collecting data for 5 seconds...
[14:21:09.968] INFO: Done with hot pixel readout
[14:21:21.888] INFO: PixTest:: pg_setup set to default.
[14:21:21.889] INFO: 13 hot pixels found in step 5
[14:21:22.880] INFO: Collecting data for 5 seconds...
[14:21:27.897] INFO: Done with hot pixel readout
[14:21:39.829] INFO: PixTest:: pg_setup set to default.


[14:21:39.830] INFO: 16 hot pixels found in step 6
[14:21:40.820] INFO: Collecting data for 5 seconds...
[14:21:45.837] INFO: Done with hot pixel readout
[14:21:57.746] INFO: PixTest:: pg_setup set to default.


[14:21:57.747] INFO: 10 hot pixels found in step 7
[14:21:58.736] INFO: Collecting data for 5 seconds...
[14:22:03.754] INFO: Done with hot pixel readout
[14:22:15.637] INFO: PixTest:: pg_setup set to default.


[14:22:15.637] INFO: 9 hot pixels found in step 8
[14:22:16.628] INFO: Collecting data for 5 seconds...
[14:22:21.644] INFO: Done with hot pixel readout
[14:22:33.553] INFO: PixTest:: pg_setup set to default.



[14:22:33.555] INFO: 13 hot pixels found in step 9
[14:22:34.545] INFO: Collecting data for 5 seconds...
[14:22:39.561] INFO: Done with hot pixel readout
[14:22:51.458] INFO: PixTest:: pg_setup set to default.




[14:22:51.459] INFO: 9 hot pixels found in step 10
[14:22:52.448] INFO: Collecting data for 5 seconds...
[14:22:57.465] INFO: Done with hot pixel readout
[14:23:09.372] INFO: PixTest:: pg_setup set to default.


[14:23:09.373] INFO: 10 hot pixels found in step 11
[14:23:10.361] INFO: Collecting data for 5 seconds...
[14:23:15.377] INFO: Done with hot pixel readout
[14:23:27.265] INFO: PixTest:: pg_setup set to default.




[14:23:27.266] INFO: 7 hot pixels found in step 12
[14:23:28.257] INFO: Collecting data for 5 seconds...
[14:23:33.274] INFO: Done with hot pixel readout
[14:23:45.237] INFO: PixTest:: pg_setup set to default.



[14:23:45.238] INFO: 8 hot pixels found in step 13
[14:23:46.228] INFO: Collecting data for 5 seconds...
[14:23:51.244] INFO: Done with hot pixel readout
[14:24:03.166] INFO: PixTest:: pg_setup set to default.


[14:24:03.167] INFO: 6 hot pixels found in step 14
[14:24:03.200] INFO: 6 hot pixels could not be trimmed and have been masked.
[14:24:03.204] INFO: PixTest::trimHotPixels() done
[14:24:03.209] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-12_FPIXTest-17C-FNAL-160422-0956_2016-04-22_09h56m_1461337018/000_FPIXTest_p17//trimParameters35_C0.dat
[14:24:03.215] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-12_FPIXTest-17C-FNAL-160422-0956_2016-04-22_09h56m_1461337018/000_FPIXTest_p17//trimParameters35_C1.dat
[14:24:03.222] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-12_FPIXTest-17C-FNAL-160422-0956_2016-04-22_09h56m_1461337018/000_FPIXTest_p17//trimParameters35_C2.dat
[14:24:03.227] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-12_FPIXTest-17C-FNAL-160422-0956_2016-04-22_09h56m_1461337018/000_FPIXTest_p17//trimParameters35_C3.dat
[14:24:03.232] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-12_FPIXTest-17C-FNAL-160422-0956_2016-04-22_09h56m_1461337018/000_FPIXTest_p17//trimParameters35_C4.dat
[14:24:03.237] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-12_FPIXTest-17C-FNAL-160422-0956_2016-04-22_09h56m_1461337018/000_FPIXTest_p17//trimParameters35_C5.dat
[14:24:03.243] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-12_FPIXTest-17C-FNAL-160422-0956_2016-04-22_09h56m_1461337018/000_FPIXTest_p17//trimParameters35_C6.dat
[14:24:03.248] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-12_FPIXTest-17C-FNAL-160422-0956_2016-04-22_09h56m_1461337018/000_FPIXTest_p17//trimParameters35_C7.dat
[14:24:03.253] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-12_FPIXTest-17C-FNAL-160422-0956_2016-04-22_09h56m_1461337018/000_FPIXTest_p17//trimParameters35_C8.dat
[14:24:03.258] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-12_FPIXTest-17C-FNAL-160422-0956_2016-04-22_09h56m_1461337018/000_FPIXTest_p17//trimParameters35_C9.dat
[14:24:03.263] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-12_FPIXTest-17C-FNAL-160422-0956_2016-04-22_09h56m_1461337018/000_FPIXTest_p17//trimParameters35_C10.dat
[14:24:03.269] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-12_FPIXTest-17C-FNAL-160422-0956_2016-04-22_09h56m_1461337018/000_FPIXTest_p17//trimParameters35_C11.dat
[14:24:03.274] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-12_FPIXTest-17C-FNAL-160422-0956_2016-04-22_09h56m_1461337018/000_FPIXTest_p17//trimParameters35_C12.dat
[14:24:03.279] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-12_FPIXTest-17C-FNAL-160422-0956_2016-04-22_09h56m_1461337018/000_FPIXTest_p17//trimParameters35_C13.dat
[14:24:03.284] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-12_FPIXTest-17C-FNAL-160422-0956_2016-04-22_09h56m_1461337018/000_FPIXTest_p17//trimParameters35_C14.dat
[14:24:03.290] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-12_FPIXTest-17C-FNAL-160422-0956_2016-04-22_09h56m_1461337018/000_FPIXTest_p17//trimParameters35_C15.dat
[14:24:03.295] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-L-2-12_FPIXTest-17C-FNAL-160422-0956_2016-04-22_09h56m_1461337018/000_FPIXTest_p17//defaultMaskFile.dat
[14:24:03.313] INFO: enter test to run
[14:24:31.594] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[14:24:31.594] INFO: running: highrate
[14:24:31.599] INFO: ----------------------------------------------------------------------
[14:24:31.599] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[14:24:31.599] INFO: ----------------------------------------------------------------------
[14:24:31.599] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[14:24:31.599] INFO: edge/corner pixel THR is adjusted
[14:24:31.599] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:24:32.557] INFO: Collecting data for 1 seconds...
[14:24:33.561] INFO: Done with hot pixel readout
[14:24:37.614] INFO: PixTest:: pg_setup set to default.
[14:24:37.615] INFO: 0 hot pixels found in step 0
[14:24:37.620] INFO: 0 hot pixels could not be trimmed and have been masked.
[14:24:37.707] INFO: PixTest::trimHotPixels() done
[14:24:37.707] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-12_FPIXTest-17C-FNAL-160422-0956_2016-04-22_09h56m_1461337018/000_FPIXTest_p17//trimParameters35_C0.dat
[14:24:37.719] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-12_FPIXTest-17C-FNAL-160422-0956_2016-04-22_09h56m_1461337018/000_FPIXTest_p17//trimParameters35_C1.dat
[14:24:37.726] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-12_FPIXTest-17C-FNAL-160422-0956_2016-04-22_09h56m_1461337018/000_FPIXTest_p17//trimParameters35_C2.dat
[14:24:37.731] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-12_FPIXTest-17C-FNAL-160422-0956_2016-04-22_09h56m_1461337018/000_FPIXTest_p17//trimParameters35_C3.dat
[14:24:37.736] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-12_FPIXTest-17C-FNAL-160422-0956_2016-04-22_09h56m_1461337018/000_FPIXTest_p17//trimParameters35_C4.dat
[14:24:37.742] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-12_FPIXTest-17C-FNAL-160422-0956_2016-04-22_09h56m_1461337018/000_FPIXTest_p17//trimParameters35_C5.dat
[14:24:37.747] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-12_FPIXTest-17C-FNAL-160422-0956_2016-04-22_09h56m_1461337018/000_FPIXTest_p17//trimParameters35_C6.dat
[14:24:37.752] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-12_FPIXTest-17C-FNAL-160422-0956_2016-04-22_09h56m_1461337018/000_FPIXTest_p17//trimParameters35_C7.dat
[14:24:37.757] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-12_FPIXTest-17C-FNAL-160422-0956_2016-04-22_09h56m_1461337018/000_FPIXTest_p17//trimParameters35_C8.dat
[14:24:37.763] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-12_FPIXTest-17C-FNAL-160422-0956_2016-04-22_09h56m_1461337018/000_FPIXTest_p17//trimParameters35_C9.dat
[14:24:37.768] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-12_FPIXTest-17C-FNAL-160422-0956_2016-04-22_09h56m_1461337018/000_FPIXTest_p17//trimParameters35_C10.dat
[14:24:37.773] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-12_FPIXTest-17C-FNAL-160422-0956_2016-04-22_09h56m_1461337018/000_FPIXTest_p17//trimParameters35_C11.dat
[14:24:37.778] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-12_FPIXTest-17C-FNAL-160422-0956_2016-04-22_09h56m_1461337018/000_FPIXTest_p17//trimParameters35_C12.dat
[14:24:37.784] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-12_FPIXTest-17C-FNAL-160422-0956_2016-04-22_09h56m_1461337018/000_FPIXTest_p17//trimParameters35_C13.dat
[14:24:37.789] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-12_FPIXTest-17C-FNAL-160422-0956_2016-04-22_09h56m_1461337018/000_FPIXTest_p17//trimParameters35_C14.dat
[14:24:37.794] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-12_FPIXTest-17C-FNAL-160422-0956_2016-04-22_09h56m_1461337018/000_FPIXTest_p17//trimParameters35_C15.dat
[14:24:37.800] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-L-2-12_FPIXTest-17C-FNAL-160422-0956_2016-04-22_09h56m_1461337018/000_FPIXTest_p17//defaultMaskFile.dat
[14:24:37.809] INFO: enter test to run
[14:25:04.562] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[14:25:04.562] INFO: running: xray
[14:25:04.563] INFO: ----------------------------------------------------------------------
[14:25:04.563] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:25:04.563] INFO: ----------------------------------------------------------------------
[14:25:05.526] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:25:17.538] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[14:25:46.804] INFO: Resuming triggers.
[14:25:58.814] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[14:26:28.230] INFO: Resuming triggers.
[14:26:40.238] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[14:27:09.601] INFO: Resuming triggers.
[14:27:21.612] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[14:27:50.870] INFO: Resuming triggers.
[14:28:02.884] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[14:28:32.174] INFO: Resuming triggers.
[14:28:44.181] INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[14:29:11.064] INFO: Resuming triggers.
[14:29:23.073] INFO: run duration 83 seconds, buffer almost full (81%), pausing triggers.
[14:29:52.306] INFO: Resuming triggers.
[14:30:04.319] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[14:30:33.566] INFO: Resuming triggers.
[14:30:37.800] INFO: data taking finished, elapsed time: 100 seconds.
[14:30:48.419] INFO: PixTest:: pg_setup set to default.
[14:30:48.422] INFO: PixTestXray::doPhRun() done
[14:30:48.556] INFO: enter test to run
[14:31:40.015] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[14:31:40.015] INFO: running: xray
[14:31:40.016] INFO: ----------------------------------------------------------------------
[14:31:40.016] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:31:40.016] INFO: ----------------------------------------------------------------------
[14:31:40.980] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:31:47.544] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[14:32:17.703] INFO: Resuming triggers.
[14:32:24.263] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[14:32:54.402] INFO: Resuming triggers.
[14:33:00.969] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[14:33:31.042] INFO: Resuming triggers.
[14:33:37.605] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[14:34:07.798] INFO: Resuming triggers.
[14:34:14.365] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[14:34:44.461] INFO: Resuming triggers.
[14:34:51.024] INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[14:35:21.220] INFO: Resuming triggers.
[14:35:27.781] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[14:35:57.927] INFO: Resuming triggers.
[14:36:04.494] INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[14:36:34.637] INFO: Resuming triggers.
[14:36:41.201] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[14:37:11.371] INFO: Resuming triggers.
[14:37:17.939] INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[14:37:47.982] INFO: Resuming triggers.
[14:37:54.547] INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[14:38:24.676] INFO: Resuming triggers.
[14:38:31.243] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[14:38:58.031] INFO: Resuming triggers.
[14:39:04.595] INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[14:39:34.789] INFO: Resuming triggers.
[14:39:41.355] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[14:40:11.432] INFO: Resuming triggers.
[14:40:17.993] INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[14:40:48.124] INFO: Resuming triggers.
[14:40:49.990] INFO: data taking finished, elapsed time: 100 seconds.
[14:40:58.845] INFO: PixTest:: pg_setup set to default.
[14:40:58.849] INFO: PixTestXray::doPhRun() done
[14:40:58.998] INFO: enter test to run
[14:41:58.858] INFO: test: HighRate no parameter change
[14:41:58.858] INFO: running: highrate
[14:41:58.860] INFO: ----------------------------------------------------------------------
[14:41:58.860] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[14:41:58.860] INFO: ----------------------------------------------------------------------
[14:41:58.000] INFO: Expecting 768 events.
[14:42:00.137] INFO: 768 events read in total (418ms).
[14:42:00.137] INFO: Test took 1271ms.
[14:42:00.941] INFO: Expecting 41600 events.
[14:42:04.076] INFO: 41600 events read in total (2608ms).
[14:42:04.077] INFO: Test took 3932ms.
[14:42:04.110] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:42:04.830] INFO: Expecting 41600 events.
[14:42:08.032] INFO: 41600 events read in total (2675ms).
[14:42:08.033] INFO: Test took 3907ms.
[14:42:08.067] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:42:08.793] INFO: Expecting 41600 events.
[14:42:12.038] INFO: 41600 events read in total (2718ms).
[14:42:12.039] INFO: Test took 3953ms.
[14:42:12.073] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:42:12.795] INFO: Expecting 41600 events.
[14:42:16.024] INFO: 41600 events read in total (2702ms).
[14:42:16.025] INFO: Test took 3935ms.
[14:42:16.058] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:42:16.783] INFO: Expecting 41600 events.
[14:42:20.006] INFO: 41600 events read in total (2696ms).
[14:42:20.007] INFO: Test took 3930ms.
[14:42:20.041] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:42:20.762] INFO: Expecting 41600 events.
[14:42:24.014] INFO: 41600 events read in total (2725ms).
[14:42:24.015] INFO: Test took 3955ms.
[14:42:24.048] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:42:24.771] INFO: Expecting 41600 events.
[14:42:28.022] INFO: 41600 events read in total (2724ms).
[14:42:28.023] INFO: Test took 3956ms.
[14:42:28.057] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:42:28.781] INFO: Expecting 41600 events.
[14:42:31.005] INFO: 41600 events read in total (2697ms).
[14:42:32.006] INFO: Test took 3931ms.
[14:42:32.040] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:42:32.761] INFO: Expecting 41600 events.
[14:42:35.995] INFO: 41600 events read in total (2707ms).
[14:42:35.996] INFO: Test took 3938ms.
[14:42:36.029] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:42:36.755] INFO: Expecting 41600 events.
[14:42:39.000] INFO: 41600 events read in total (2718ms).
[14:42:39.001] INFO: Test took 3953ms.
[14:42:40.034] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:42:40.759] INFO: Expecting 41600 events.
[14:42:43.995] INFO: 41600 events read in total (2709ms).
[14:42:43.996] INFO: Test took 3944ms.
[14:42:44.030] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:42:44.754] INFO: Expecting 41600 events.
[14:42:47.995] INFO: 41600 events read in total (2714ms).
[14:42:47.996] INFO: Test took 3949ms.
[14:42:48.029] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:42:48.757] INFO: Expecting 41600 events.
[14:42:51.999] INFO: 41600 events read in total (2716ms).
[14:42:51.000] INFO: Test took 3952ms.
[14:42:52.033] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:42:52.757] INFO: Expecting 41600 events.
[14:42:55.983] INFO: 41600 events read in total (2699ms).
[14:42:55.984] INFO: Test took 3933ms.
[14:42:56.018] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:42:56.742] INFO: Expecting 41600 events.
[14:42:59.981] INFO: 41600 events read in total (2712ms).
[14:42:59.982] INFO: Test took 3946ms.
[14:43:00.015] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:43:00.741] INFO: Expecting 41600 events.
[14:43:03.986] INFO: 41600 events read in total (2718ms).
[14:43:03.987] INFO: Test took 3953ms.
[14:43:04.020] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:43:04.743] INFO: Expecting 41600 events.
[14:43:07.994] INFO: 41600 events read in total (2724ms).
[14:43:07.995] INFO: Test took 3956ms.
[14:43:08.028] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:43:08.752] INFO: Expecting 41600 events.
[14:43:11.999] INFO: 41600 events read in total (2720ms).
[14:43:11.000] INFO: Test took 3954ms.
[14:43:12.033] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:43:12.751] INFO: Expecting 41600 events.
[14:43:15.975] INFO: 41600 events read in total (2697ms).
[14:43:15.976] INFO: Test took 3924ms.
[14:43:16.010] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:43:16.734] INFO: Expecting 41600 events.
[14:43:19.763] INFO: 41600 events read in total (2502ms).
[14:43:19.764] INFO: Test took 3735ms.
[14:43:19.797] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:43:20.162] INFO: enter test to run
[14:44:18.481] INFO: test: HighRate no parameter change
[14:44:18.481] INFO: running: highrate
[14:44:18.483] INFO: ----------------------------------------------------------------------
[14:44:18.483] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:44:18.483] INFO: ----------------------------------------------------------------------
[14:44:19.094] INFO: Expecting 208000 events.
[14:44:30.964] INFO: 208000 events read in total (11343ms).
[14:44:30.969] INFO: Test took 12476ms.
[14:44:31.115] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:44:31.366] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 1 0 0 0 0 0 0 0 0
[14:44:31.366] INFO: number of red-efficiency pixels: 76 66 90 112 140 146 147 110 83 140 141 114 112 75 29 25
[14:44:31.366] INFO: number of X-ray hits detected: 66861 45024 69262 104160 111017 116214 114504 81709 75163 94246 92102 81734 87665 51457 21880 23890
[14:44:31.366] 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:44:31.366] INFO: number of Vcal hits detected: 207922 207933 207900 207885 207857 207851 207848 207837 207916 207859 207856 207885 207887 207923 207971 207975
[14:44:31.366] 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 99.9 100.0 100.0 100.0 100.0
[14:44:31.366] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 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
[14:44:31.366] INFO: X-ray hit rate [MHz/cm2]: 19.6 13.2 20.3 30.5 32.5 34.1 33.6 23.9 22.0 27.6 27.0 24.0 25.7 15.1 6.4 7.0
[14:44:31.366] INFO: PixTestHighRate::doXPixelAlive() done
[14:44:31.419] INFO: PixTest:: pg_setup set to default.
[14:44:31.435] INFO: enter test to run
[14:46:02.393] INFO: test: HighRate no parameter change
[14:46:02.393] INFO: running: highrate
[14:46:02.394] INFO: ----------------------------------------------------------------------
[14:46:02.394] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:46:02.394] INFO: ----------------------------------------------------------------------
[14:46:03.011] INFO: Expecting 208000 events.
[14:46:16.592] INFO: 208000 events read in total (13054ms).
[14:46:16.598] INFO: Test took 14195ms.
[14:46:16.898] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:46:17.197] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 1 0 0 0 0 0 0 0 0
[14:46:17.197] INFO: number of red-efficiency pixels: 241 160 240 327 517 422 501 373 188 380 379 261 359 223 51 66
[14:46:17.197] INFO: number of X-ray hits detected: 136888 92285 141654 214214 226826 238049 234500 168701 155698 194062 188910 167326 178785 105797 44770 48762
[14:46:17.197] 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:46:17.197] INFO: number of Vcal hits detected: 207740 207829 207741 207650 207436 207544 207449 207539 207800 207604 207596 207722 207622 207761 207947 207932
[14:46:17.197] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.7 99.8 99.8 99.8 99.9 99.8 99.8 99.9 99.8 99.9 100.0 100.0
[14:46:17.197] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.7 99.8 99.7 99.8 99.9 99.8 99.8 99.9 99.8 99.9 100.0 100.0
[14:46:17.197] INFO: X-ray hit rate [MHz/cm2]: 40.1 27.0 41.5 62.8 66.5 69.8 68.7 49.4 45.6 56.9 55.4 49.0 52.4 31.0 13.1 14.3
[14:46:17.197] INFO: PixTestHighRate::doXPixelAlive() done
[14:46:17.248] INFO: PixTest:: pg_setup set to default.
[14:46:17.264] INFO: enter test to run
[14:48:05.848] INFO: test: HighRate no parameter change
[14:48:05.848] INFO: running: highrate
[14:48:05.849] INFO: ----------------------------------------------------------------------
[14:48:05.849] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:48:05.849] INFO: ----------------------------------------------------------------------
[14:48:06.466] INFO: Expecting 208000 events.
[14:48:22.139] INFO: 208000 events read in total (15146ms).
[14:48:22.146] INFO: Test took 16288ms.
[14:48:22.604] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:48:22.957] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 1 0 0 0 0 0 0 0 0
[14:48:22.957] INFO: number of red-efficiency pixels: 585 355 552 823 1343 1142 1310 874 471 950 953 586 833 488 108 105
[14:48:22.957] INFO: number of X-ray hits detected: 216749 145207 224264 339173 358241 375182 373057 265065 245562 305162 297742 264934 284041 167881 71129 77991
[14:48:22.957] 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:48:22.957] INFO: number of Vcal hits detected: 207255 207605 207309 207025 206234 206585 206227 206791 207488 206866 206850 207325 207024 207404 207891 207892
[14:48:22.957] INFO: Vcal hit fiducial efficiency (%): 99.7 99.8 99.7 99.6 99.2 99.4 99.2 99.5 99.8 99.5 99.5 99.7 99.6 99.7 100.0 100.0
[14:48:22.957] INFO: Vcal hit overall efficiency (%): 99.6 99.8 99.7 99.5 99.2 99.3 99.1 99.4 99.8 99.5 99.4 99.7 99.5 99.7 99.9 99.9
[14:48:22.957] INFO: X-ray hit rate [MHz/cm2]: 63.5 42.6 65.7 99.4 105.0 110.0 109.3 77.7 72.0 89.4 87.3 77.7 83.3 49.2 20.8 22.9
[14:48:22.957] INFO: PixTestHighRate::doXPixelAlive() done
[14:48:22.004] INFO: PixTest:: pg_setup set to default.
[14:48:23.017] INFO: enter test to run
[14:48:44.519] INFO: test: exit no parameter change
[14:48:44.860] QUIET: Connection to board 33 closed.
[14:48:44.860] INFO: pXar: this is the end, my friend